Re: Need help with tuning SQL statement
- From: "Finn Jorgensen" <finn.oracledba@xxxxxxxxx>
- To: Amir.Hameed@xxxxxxxxx
- Date: Tue, 26 Feb 2008 10:49:47 -0500
Amir,
From what I can tell from what you've posted here it does seem like the
issue is the statement is issued 117k times. The statement is fast, but when
executed this many times it still takes a long time to complete.
Do you have access to the source code to figure out why it's executed so
many times and if the code could be rewritten to maybe a single large
statement executed once rather than a loop type operation that executes the
statement over and over again?
Finn
On 2/26/08, Hameed, Amir <Amir.Hameed@xxxxxxxxx> wrote:
>
> Folks,
> I have a trace file that contains a few statements that are taking a
> long time to complete. I am going to paste TKPROF o/p from one statement
> here (other statements have similar behavior). This is an Oracle
> 11.5.9/10.2.0.2 system running on Sun Solaris9. From what I can tell by
> looking at the "db file sequential read" wait statistics, 700713 I/Os
> were performed in 3130.18 seconds which indicates that the average I/O
> time was ~ 4.46 ms and is quite good. Is the issue here related to the
> fact that the statement was executed too many times (117382)? Would
> using bulk-fetch feature help in reducing the elapsed time here?
>
> Any help will be appreciated.
> Thanks
>
>
> SELECT OKL.CLE_ID LINE_ID, OKL.ID SUBLINE_ID, OKL.START_DATE
> LINE_START_DATE,
> DECODE (ORB.ATTRIBUTE11, 'MO', 1, 'Q', 2, 'BA', 3, 'YR', 4, 99 )
> BILLING_FREQ_ORDER, DECODE (ORB.ATTRIBUTE11, 'MO', ' ', 'Q', 'P',
> 'BA', 'S',
> 'YR', 'A', NVL (SUBSTR (ORB.ATTRIBUTE11, 1, 10), 'N/A') )
> BILLING_FREQ
> FROM
> OKC_K_HEADERS_B OKH, OKC_K_LINES_B OKL, OKC_K_ITEMS OKI,
> OKC_RULE_GROUPS_B
> ORG, OKC_RULES_B ORB, TXRCC0_CS_COUNTERS_MP TCC WHERE OKL.ID =
> OKI.CLE_ID
> AND OKH.ID = OKL.DNZ_CHR_ID AND OKL.CLE_ID = ORG.CLE_ID AND
> OKI.OBJECT1_ID1
> = TO_CHAR (TCC.COUNTER_ID) AND OKI.JTOT_OBJECT1_CODE = 'OKX_COUNTER'
> AND
> OKH.CONTRACT_NUMBER = :B2 AND TCC.INSTANCE_COUNTER_GROUP_ID = :B1 AND
> ORG.ID = ORB.RGP_ID AND ORB.RULE_INFORMATION_CATEGORY = 'QRE' ORDER BY
>
> BILLING_FREQ_ORDER, TCC.PARENT_METER_NUMBER
>
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.00 0.00 0 0 0
> 0
> Execute 117382 15.08 14.67 0 0 0
> 0
> Fetch 117382 377.05 3485.69 700713 5941451 0
> 140578
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 234765 392.13 3500.37 700713 5941451 0
> 140578
>
> Misses in library cache during parse: 1
> Misses in library cache during execute: 2
> Optimizer mode: ALL_ROWS
> Parsing user id: 173 (APPS) (recursive depth: 1)
>
> Rows Row Source Operation
> ------- ---------------------------------------------------
> 4761 SORT ORDER BY (cr=203532 pr=21787 pw=0 time=126450991 us)
> 4761 TABLE ACCESS BY INDEX ROWID OKC_RULES_B (cr=203532 pr=21787
> pw=0 time=126955746 us)
> 13288 NESTED LOOPS (cr=199055 pr=19266 pw=0 time=272743522 us)
> 4761 NESTED LOOPS (cr=184936 pr=18429 pw=0 time=96277230 us)
> 4761 HASH JOIN (cr=166034 pr=15515 pw=0 time=80863467 us)
> 5030 NESTED LOOPS (cr=154719 pr=15467 pw=0 time=76459237 us)
> 5030 NESTED LOOPS (cr=134726 pr=12232 pw=0 time=65209837 us)
> 37844 TABLE ACCESS BY INDEX ROWID TXRCC0_CS_COUNTERS_MP
> (cr=46240 pr=9639 pw=0 time=66473907 us)
> 37844 INDEX RANGE SCAN IXRTC0_COUNTER_GRP_ID_N1 (cr=11421
> pr=1416 pw=0 time=9663661 us)(object id 9849161)
> 5030 TABLE ACCESS BY INDEX ROWID OKC_K_ITEMS (cr=88486
> pr=2593 pw=0 time=13838836 us)
> 5030 INDEX RANGE SCAN OKC_K_ITEMS_N2 (cr=83469 pr=480 pw=0
> time=3066136 us)(object id 114433)
> 5030 TABLE ACCESS BY INDEX ROWID OKC_K_LINES_B (cr=19993
> pr=3235 pw=0 time=10801289 us)
> 5030 INDEX UNIQUE SCAN OKC_K_LINES_B_U1 (cr=14802 pr=1123
> pw=0 time=4495583 us)(object id 85466)
> 3766 TABLE ACCESS BY INDEX ROWID OKC_K_HEADERS_B (cr=11315
> pr=48 pw=0 time=357535 us)
> 3766 INDEX RANGE SCAN OKC_K_HEADERS_B_U2 (cr=7548 pr=2 pw=0
> time=114972 us)(object id 85479)
> 4761 TABLE ACCESS BY INDEX ROWID OKC_RULE_GROUPS_B (cr=18902
> pr=2914 pw=0 time=15269149 us)
> 4761 INDEX RANGE SCAN OKC_RULE_GROUPS_B_N2 (cr=14141 pr=1305
> pw=0 time=6744772 us)(object id 108871)
> 4761 INDEX RANGE SCAN OKC_RULES_B_N4 (cr=14119 pr=837 pw=0
> time=6817338 us)(object id 108857)
>
>
> Rows Execution Plan
> ------- ---------------------------------------------------
> 0 SELECT STATEMENT MODE: ALL_ROWS
> 4761 SORT (ORDER BY)
> 4761 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'OKC_RULES_B' (TABLE)
> 13288 NESTED LOOPS
> 4761 NESTED LOOPS
> 4761 HASH JOIN
> 5030 NESTED LOOPS
> 5030 NESTED LOOPS
> 37844 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'TXRCC0_CS_COUNTERS_MP' (TABLE)
> 37844 INDEX MODE: ANALYZED (RANGE SCAN) OF
> 'IXRTC0_COUNTER_GRP_ID_N1' (INDEX)
> 5030 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'OKC_K_ITEMS' (TABLE)
> 5030 INDEX MODE: ANALYZED (RANGE SCAN) OF
> 'OKC_K_ITEMS_N2' (INDEX)
> 5030 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'OKC_K_LINES_B' (TABLE)
> 5030 INDEX MODE: ANALYZED (UNIQUE SCAN) OF
> 'OKC_K_LINES_B_U1' (INDEX (UNIQUE))
> 3766 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'OKC_K_HEADERS_B' (TABLE)
> 3766 INDEX MODE: ANALYZED (RANGE SCAN) OF
> 'OKC_K_HEADERS_B_U2' (INDEX (UNIQUE))
> 4761 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
> 'OKC_RULE_GROUPS_B' (TABLE)
> 4761 INDEX MODE: ANALYZED (RANGE SCAN) OF
> 'OKC_RULE_GROUPS_B_N2' (INDEX)
> 4761 INDEX MODE: ANALYZED (RANGE SCAN) OF 'OKC_RULES_B_N4'
> (INDEX)
>
>
> Elapsed times include waiting on following events:
> Event waited on Times Max. Wait Total
> Waited
> ---------------------------------------- Waited ----------
> ------------
> db file sequential read 700713 1.46
> 3130.18
> latch: cache buffers chains 11 0.00
> 0.00
> latch: shared pool 2 0.00
> 0.00
> latch free 3 0.02
> 0.02
> latch: row cache objects 1 0.00
> 0.00
> ************************************************************************
> ********
>
> --
> //www.freelists.org/webpage/oracle-l
>
>
>
Other related posts:
