From: "Bob Fazio" Subject: Performance problem with a PeopleSoft Database Date: 2000/06/06 Message-ID: X-Priority: 3 X-MimeOLE: Produced By Microsoft MimeOLE V5.00.2919.6600 X-Complaints-To: abuse@home.net X-Trace: news1.rdc2.pa.home.com 960329902 24.8.218.197 (Tue, 06 Jun 2000 15:18:22 PDT) Organization: @Home Network X-MSMail-Priority: Normal Reply-To: "Bob Fazio" NNTP-Posting-Date: Tue, 06 Jun 2000 15:18:22 PDT Newsgroups: comp.databases.oracle.server I am experiencing a problem with one of my databases that I can't explain. Supposidly, there is not real difference between development/qa/test/production databases, but for some reason the Production is running slower for long running jobs than is Dev and QA. I have considered the additional access of the on-line users, but I don't feel that is the issue. Here are some excerpts of the report.txt (bstat/estat report), that concerned me. This is only a 10 minute snapshot, but longer reports don't really look much different. This is a link to the whole file. http://24.8.218.197/problem/report.txt LIBRARY GETS GETHITRATI PINS PINHITRATI RELOADS INVALIDATI ------------ ---------- ---------- ---------- ---------- ---------- -------- -- BODY 12 .833 12 .75 1 0 CLUSTER 17 .941 25 .92 0 0 INDEX 3 .333 3 .333 0 0 OBJECT 0 1 0 1 0 0 PIPE 0 1 0 1 0 0 SQL AREA 14047 .917 36630 .94 8 0 TABLE/PROCED 3936 .945 7960 .949 4 0 TRIGGER 20 1 20 1 0 0 The above looked fine to me, the area's that didn't look good, where small cases. (index 3) consistent gets 5870256 57551.53 90311.63 9576.27 This concerned me, remember this is only a 10 minute scan. session logical reads 5869211 57541.28 90295.55 9574.57 session pga memory 22543532 221015.02 346823.57 36775.75 session pga memory max 46852708 459340.27 720810.89 76431.82 session uga memory 103079434128 1010582687.5 1585837448.1 168155683.73 session uga memory max 26167636 256545.45 402579.02 42687.82 This is more concerning (session uga memory) cache buffers chai 8987049 29 1 0 0 The processes that were having problems seemed to get hung (1-3 seconds) on this latch, and also db file sequential read's I am really stumped. This is one statement that is an issue. UPDATE PS_BNK_RCN_DISBRSE SET PYMNT_RECONCILE_DT = TO_DATE('2000-06-05', 'YYYY-MM-DD') ,RECON_STATUS = 'REC' ,RECON_TYPE = 'A' ,RECONCILE_OPRID = 'AUTO' ,RECON_CYCLE_NBR = 0000000003 ,STTLMNT_DT_ACTUAL = TO_DATE('2099-08-17','YYYY-MM-DD') WHERE RECON_TYPE = 'U' AND BNK_ID_NBR = '950054313' AND BANK_ACCOUNT_NUM = '612969840' AND (RECON_CYCLE_NBR <> 0000000003 OR RECON_CYCLE_NBR = 0) AND PYMNT_STATUS IN ('P', 'V', 'S') AND PYMNT_ID_REF = ( SELECT PS_BANK_STMT_TBL.RECON_REF_ID FROM PS_BANK_STMT_TBL WHERE PS_BNK_RCN_DISBRSE.PYMNT_ID_REF = PS_BANK_STMT_TBL.RECON_REF_ID AND PS_BNK_RCN_DISBRSE.PYMNT_AMT = PS_BANK_STMT_TBL.RECON_TRAN_AMT AND PS_BNK_RCN_DISBRSE.PYMNT_DT <= PS_BANK_STMT_TBL.RECON_BANK_DT AND PS_BANK_STMT_TBL.RECON_STATUS IN ('UNR') AND PS_BNK_RCN_DISBRSE.BNK_ID_NBR = PS_BANK_STMT_TBL.BNK_ID_NBR AND PS_BNK_RCN_DISBRSE.BANK_ACCOUNT_NUM = PS_BANK_STMT_TBL.BANK_ACCOUNT_NUM AND PS_BANK_STMT_TBL.RECON_CYCLE_NBR = 0000000003 AND PS_BANK_STMT_TBL.RECON_BANK_DT = TO_DATE('2099-08-17', 'YYYY-MM-DD')) call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ------ ---- Parse 1 0.06 0.06 0 0 0 0 Execute 1 4.30 4.30 0 33511 0 0 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ------ ---- total 2 4.36 4.36 0 33511 0 0 The 4 seconds per update is the issue for me, considering I have over 3,000 to do each day. (5+ hours, counting the other issues ) Link to the tkprof file. http://24.8.218.197/problem/problem_tkprof.out And a little more info. See the waits on one block. *** 2000.06.06.14.46.09.000 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=6164 p3=1 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=7350 p3=1 WAIT #1: nam='db file sequential read' ela= 0 p1=64 p2=7345 p3=1 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=32334 p3=1 WAIT #1: nam='db file sequential read' ela= 0 p1=64 p2=32332 p3=1 WAIT #1: nam='db file sequential read' ela= 1 p1=64 p2=32331 p3=1 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=2359 p3=1 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=7349 p3=1 WAIT #1: nam='db file sequential read' ela= 1 p1=64 p2=7356 p3=1 WAIT #1: nam='db file sequential read' ela= 1 p1=64 p2=7355 p3=1 WAIT #1: nam='db file sequential read' ela= 2 p1=64 p2=2362 p3=1 ===================== PARSING IN CURSOR #1 len=3291 dep=0 uid=208 oct=2 lid=208 tim=16101617 hv=2161587976 ad='95dffb24' INSERT INTO PS_EDT_ACCTLN_WRK ( BUSINESS_UNIT, VOUCHER_ID, VOUCHER_LINE_NUM, DISTRIB_LINE_NUM, SUSPENSE_REF_NUM, BUSINESS_UNIT_GL, ACCOUNT, STATISTICS_CODE, FOREIGN_AMOUNT, TXN_CURRENCY_CD, MONETARY_AMOUNT, STATISTIC_AMOUNT, QTY_VCHR, JRNL_LN_REF, OPEN_ITEM_STATUS, DESCR, MERCHANDISE_AMT, CHART_EDIT_STATUS, ACCOUNTING_DT, PROCESS_INSTANCE, ERROR_FLAG, FINAL_REF_IND, REFERENCE_NUMBER, REF_CLOSED, REF_DIST_LINE, REF_LINE_NUMBER, BUSINESS_UNIT_PO, PO_ID, LINE_NBR, SCHED_NBR, PO_DIST_LINE_NUM, BCM_LINE_STATUS, BCM_POST_AMOUNT, BCM_POST_AMT_TOT, BUSINESS_UNIT_PC, ACTIVITY_ID, ANALYSIS_TYPE, RESOURCE_TYPE, RESOURCE_CATEGORY, RESOURCE_SUB_CAT, CUR_RT_TYPE, CUR_RATE_MULT, CUR_RATE_DIV, CURRENCY_CD, ASSET_FLG, BUSINESS_UNIT_AM, ASSET_ID, PROFILE_ID, VAT_TXN_TYPE_CD, FREIGHT_AMT, SALETX_AMT, USETAX_AMT, VAT_INV_AMT, VAT_NONINV_AMT, BUSINESS_UNIT_RECV, RECEIVER_ID, RECV_LN_NBR, RECV_SHIP_SEQ_NBR, RECV_DIST_LINE_NUM, VAT_RECOVERY_PCT, VAT_BASIS_AMT, VAT_CALC_AMT, VAT_RCVRY_AMT, VAT_DSCNT_ADJ, VAT_DSCNT_RCVRY, TAX_CD_VAT, TAX_CD_VAT_PCT, LEDGER_GROUP, DSCNT_AMT, ECTRANSID, ECQUEUEINSTANCE, ECTRANSINOUTSW, DEPTID, PRODUCT, PROJECT_ID, AFFILIATE, WTHD_SW, WTHD_SETID, WTHD_CD, SHIPTO_ID, SUT_BASE_ID, TAX_CD_SUT, TAX_CD_SUT_PCT, SALETX_CALC_AMT, SUT_APPLICABILITY, VAT_REBATE_PCT, VAT_REBATE_AMT, VAT_APPLICABILITY, VAT_USE_ID, VAT_ENTITY, POST_STATUS_AP, BASE_CURRENCY, CUR_RT_SOURCE, DISTRIB_MTHD_FLG ) SELECT A.BUSINESS_UNIT, A.VOUCHER_ID, A.VOUCHER_LINE_NUM, A.DISTRIB_LINE_NUM, A.SUSPENSE_REF_NUM, A.BUSINESS_UNIT_GL, A.ACCOUNT, A.STATISTICS_CODE, A.FOREIGN_AMOUNT, A.TXN_CURRENCY_CD, A.MONETARY_AMOUNT, A.STATISTIC_AMOUNT, A.QTY_VCHR, A.JRNL_LN_REF, A.OPEN_ITEM_STATUS, A.DESCR, A.MERCHANDISE_AMT, 'O', A.ACCOUNTING_DT, 0000011595, 'N', A.FINAL_REF_IND, A.REFERENCE_NUMBER, A.REF_CLOSED, A.REF_DIST_LINE, A.REF_LINE_NUMBER, A.BUSINESS_UNIT_PO, A.PO_ID, A.LINE_NBR, A.SCHED_NBR, A.PO_DIST_LINE_NUM, A.BCM_LINE_STATUS, A.BCM_POST_AMOUNT, A.BCM_POST_AMT_TOT, A.BUSINESS_UNIT_PC, A.ACTIVITY_ID, A.ANALYSIS_TYPE, A.RESOURCE_TYPE, A.RESOURCE_CATEGORY, A.RESOURCE_SUB_CAT, A.CUR_RT_TYPE, A.CUR_RATE_MULT, A.CUR_RATE_DIV, A.CURRENCY_CD, A.ASSET_FLG, A.BUSINESS_UNIT_AM, A.ASSET_ID, A.PROFILE_ID, A.VAT_TXN_TYPE_CD, A.FREIGHT_AMT, A.SALETX_AMT, A.USETAX_AMT, A.VAT_INV_AMT, A.VAT_NONINV_AMT, A.BUSINESS_UNIT_RECV, A.RECEIVER_ID, A.RECV_LN_NBR, A.RECV_SHIP_SEQ_NBR, A.RECV_DIST_LINE_NUM, A.VAT_RECOVERY_PCT, A.VAT_BASIS_AMT, A.VAT_CALC_AMT, A.VAT_RCVRY_AMT, A.VAT_DSCNT_ADJ, A.VAT_DSCNT_RCVRY, A.TAX_CD_VAT, A.TAX_CD_VAT_PCT, A.LEDGER_GROUP, A.DSCNT_AMT, A.ECTRANSID, A.ECQUEUEINSTANCE, A.ECTRANSINOUTSW, A.DEPTID, A.PRODUCT, A.PROJECT_ID, A.AFFILIATE, A.WTHD_SW, A.WTHD_SETID, A.WTHD_CD, A.SHIPTO_ID, A.SUT_BASE_ID, A.TAX_CD_SUT, A.TAX_CD_SUT_PCT, A.SALETX_CALC_AMT, A.SUT_APPLICABILITY, A.VAT_REBATE_PCT, A.VAT_REBATE_AMT, A.VAT_APPLICABILITY, A.VAT_USE_ID, A.VAT_ENTITY, B.POST_STATUS_AP, B.BASE_CURRENCY, B.CUR_RT_SOURCE, C.DISTRIB_MTHD_FLG FROM PS_DISTRIB_LINE A, PS_EDT_VCHRLN_WRK C, PS_EDT_VCHR_WRK B WHERE B.BUSINESS_UNIT = 'ECD01' AND B.IN_PROCESS_FLG = 'Y' AND B.PROCESS_INSTANCE = 0000011595 AND B.BUSINESS_UNIT = A.BUSINESS_UNIT AND B.VOUCHER_ID = A.VOUCHER_ID AND C.BUSINESS_UNIT = A.BUSINESS_UNIT AND C.VOUCHER_ID = A.VOUCHER_ID AND C.VOUCHER_LINE_NUM = A.VOUCHER_LINE_NUM END OF STMT EXEC #1:c=0,e=0,p=56,cr=34707290,cu=68,mis=1,r=90,dep=0,og=4,tim=16101617 WAIT #1: nam='SQL*Net message to client' ela= 0 p1=675562835 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 0 p1=675562835 p2=1 p3=0 XCTEND rlbk=0, rd_only=0 WAIT #0: nam='log file sync' ela= 3 p1=40 p2=0 p3=0 WAIT #0: nam='SQL*Net message to client' ela= 0 p1=675562835 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 5 p1=675562835 p2=1 p3=0 ===================== PARSING IN CURSOR #2 len=128 dep=1 uid=0 oct=3 lid=0 tim=16101629 hv=2554239735 ad='972832ac' select u.name,o.name from obj$ o,user$ u,trigger$ t where t.baseobject=:1 and t.obj#=o.obj# and o.owner#=u.user# order by o.obj# END OF STMT PARSE #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=16101629 BINDS #2: bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 bfp=01094a90 bln=22 avl=04 flg=05 value=122841 EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=16101629 FETCH #2:c=1,e=1,p=0,cr=22,cu=3,mis=0,r=0,dep=1,og=4,tim=16101630 STAT #2 id=1 cnt=0 pid=0 pos=0 obj=0 op='SORT ORDER BY ' STAT #2 id=2 cnt=0 pid=1 pos=1 obj=0 op='HASH JOIN ' STAT #2 id=3 cnt=364 pid=2 pos=1 obj=22 op='TABLE ACCESS FULL USER$ ' STAT #2 id=4 cnt=0 pid=2 pos=2 obj=0 op='NESTED LOOPS ' STAT #2 id=5 cnt=0 pid=4 pos=1 obj=69 op='TABLE ACCESS BY INDEX ROWID TRIGGER$ ' STAT #2 id=6 cnt=1 pid=5 pos=1 obj=109 op='INDEX RANGE SCAN ' STAT #2 id=7 cnt=0 pid=4 pos=2 obj=18 op='TABLE ACCESS BY INDEX ROWID OBJ$ ' STAT #2 id=8 cnt=0 pid=7 pos=1 obj=31 op='INDEX UNIQUE SCAN ' -- Robert Fazio, Oracle DBA rfazio@home.com remove nospam from reply address http://24.8.218.197/