16
A Roadmap To Query Tuning
=============== =============
For each SQL statement, there are different approaches that could be used to retrieve the required data. Optimization is the process of choosing the most efficient way to retrieve this data based upon the evaluation of a number of different criteria. The CBO bases optimization choices on pre-gathered table and index statistics while the RBO makes it's decisions based on a set of rules and does not rely on any statistical information. CBO's reliance on statistics makes it vastly more flexible than the RBO since as long as up to date statistics are maintained ,it will accurately reflect real data volumes. The RBO is desupported in Oracle10g.
To gather 10046 trace at the session level:
alter session set timed_statistic s = true;
alter session set statistics_leve l=all;
alter session set max_dump_file_s ize = unlimited;
alter session set events '10046 trace name context forever,level 12';
Freatures of DBMS_SUPPORT Package
=============== ===============
In this article I have described undocumented feature within Oracle there is no guarantee that the results
will be exactly as described for all releases .
Installing DBMS Package
-----------------------
[oracle@localhos t admin]$ ls -ltr *supp*
-rw-r----- 1 oracle oracle 1546 Feb 27 2001 dbmssupp.sql
-rw-r----- 1 oracle oracle 1198 Sep 19 2005 prvtsupp.plb
SQL> @$ORACLE_HOME/rdbms/admin/dbmssupp
---------------------------------------------
-- run your select(s) --
SQL> exec DBMS_SUPPORT.ST ART_TRACE;
PL/SQL procedure successfully completed.
SQL> <== Your query
.
.
.
SQL> exec DBMS_SUPPORT.ST OP_TRACE;
PL/SQL procedure successfully completed.
System name: Linux
Node name: localhost.local domain
Release: 2.6.18-53.el5xen
Version: #1 SMP Sat Nov 10 19:46:12 EST 2007
Machine: x86_64
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 16
Unix process pid: 4947, image: oracle@localhos t.localdomain (TNS V1-V3)
*** 2008-01-21 12:00:25.204
*** SERVICE NAME:(SYS$USERS ) 2008-01-21 12:00:25.204
*** SESSION ID:(158.3) 2008-01-21 12:00:25.204
=============== ======
PARSING IN CURSOR #6 len=198 dep=1 uid=0 oct=3 lid=0 tim=11727457277 38352 hv=4125641360 ad='6c2b8cc0'
select obj#,type#,ctim e,mtime,stime,s tatus,dataobj#, flags,oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null
and linkname is null and subname is null
END OF STMT
PARSE #6:c=0,e=620,p= 0,cr=0,cu=0,mis =1,r=0,dep=1,og =4,tim=11727457 27738344
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 40552 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
PARSE #3:c=0,e=587,p= 0,cr=0,cu=0,mis =1,r=0,dep=2,og =3,tim=11727457 27740544
EXEC #3:c=0,e=2148,p =0,cr=0,cu=0,mi s=1,r=0,dep=2,o g=3,tim=1172745 727742876
WAIT #3: nam='db file sequential read' ela= 46 file#=1 block#=1888 blocks=1 obj#=-1 tim=11727457277 43123
FETCH #3:c=0,e=334,p= 1,cr=3,cu=0,mis =0,r=12,dep=2,o g=3,tim=1172745 727743301
STAT #3 id=1 cnt=12 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=3 pr=1 pw=0 time=359 us)'
STAT #3 id=2 cnt=12 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=3 pr=1 pw=0 time=310 us)'
STAT #3 id=3 cnt=1 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=51 us)'
=============== ======
PARSING IN CURSOR #3 len=210 dep=2 uid=0 oct=3 lid=0 tim=11727457277 44437 hv=864012087 ad='6c1e0010'
select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2
, avgcln from hist_head$ where obj#=:1 and intcol#=:2
END OF STMT
PARSE #3:c=0,e=533,p= 0,cr=0,cu=0,mis =1,r=0,dep=2,og =3,tim=11727457 27744429
EXEC #3:c=0,e=935,p= 0,cr=0,cu=0,mis =1,r=0,dep=2,og =3,tim=11727457 27745569
FETCH #3:c=0,e=94,p=0 ,cr=3,cu=0,mis= 0,r=1,dep=2,og= 3,tim=117274572 7745746
STAT #3 id=1 cnt=1 pid=0 pos=1 obj=255 op='TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=3 pr=0 pw=0 time=96 us)'
STAT #3 id=2 cnt=1 pid=1 pos=1 obj=257 op='INDEX RANGE SCAN I_HH_OBJ#_INTCO L# (cr=2 pr=0 pw=0 time=45 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 45997 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=49,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7745991
FETCH #3:c=8000,e=242 ,p=0,cr=3,cu=0, mis=0,r=20,dep= 2,og=3,tim=1172 745727746335
STAT #3 id=1 cnt=32 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=6 pr=1 pw=0 time=570 us)'
STAT #3 id=2 cnt=32 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=6 pr=1 pw=0 time=455 us)'
STAT #3 id=3 cnt=2 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=4 pr=0 pw=0 time=76 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 46666 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=68,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7746659
FETCH #3:c=0,e=124,p= 0,cr=3,cu=0,mis =0,r=9,dep=2,og =3,tim=11727457 27746916
STAT #3 id=1 cnt=41 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=9 pr=1 pw=0 time=718 us)'
STAT #3 id=2 cnt=41 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=9 pr=1 pw=0 time=548 us)'
STAT #3 id=3 cnt=3 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=6 pr=0 pw=0 time=105 us)'
=============== ======
PARSING IN CURSOR #3 len=210 dep=2 uid=0 oct=3 lid=0 tim=11727457277 47246 hv=864012087 ad='6c1e0010'
select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2
, avgcln from hist_head$ where obj#=:1 and intcol#=:2
END OF STMT
EXEC #3:c=0,e=49,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7747240
FETCH #3:c=0,e=50,p=0 ,cr=3,cu=0,mis= 0,r=1,dep=2,og= 3,tim=117274572 7747400
STAT #3 id=1 cnt=2 pid=0 pos=1 obj=255 op='TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=6 pr=0 pw=0 time=148 us)'
STAT #3 id=2 cnt=2 pid=1 pos=1 obj=257 op='INDEX RANGE SCAN I_HH_OBJ#_INTCO L# (cr=4 pr=0 pw=0 time=71 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 47609 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=42,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7747603
WAIT #3: nam='db file sequential read' ela= 47 file#=1 block#=56504 blocks=1 obj#=-1 tim=11727457277 47808
WAIT #3: nam='db file sequential read' ela= 24 file#=1 block#=2006 blocks=1 obj#=-1 tim=11727457277 47900
FETCH #3:c=0,e=348,p= 2,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727748053
STAT #3 id=1 cnt=61 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=13 pr=3 pw=0 time=1132 us)'
STAT #3 id=2 cnt=61 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=13 pr=3 pw=0 time=878 us)'
STAT #3 id=3 cnt=4 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=8 pr=0 pw=0 time=125 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 48297 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=44,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7748291
FETCH #3:c=0,e=156,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727748549
STAT #3 id=1 cnt=81 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=17 pr=3 pw=0 time=1336 us)'
STAT #3 id=2 cnt=81 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=17 pr=3 pw=0 time=1009 us)'
STAT #3 id=3 cnt=5 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=10 pr=0 pw=0 time=147 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 48769 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=39,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7748763
FETCH #3:c=0,e=149,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727749013
STAT #3 id=1 cnt=101 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=21 pr=3 pw=0 time=1550 us)'
STAT #3 id=2 cnt=101 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=21 pr=3 pw=0 time=1158 us)'
STAT #3 id=3 cnt=6 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=12 pr=0 pw=0 time=164 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 49231 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=39,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7749225
FETCH #3:c=0,e=149,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727749475
STAT #3 id=1 cnt=121 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=25 pr=3 pw=0 time=1763 us)'
STAT #3 id=2 cnt=121 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=25 pr=3 pw=0 time=1311 us)'
STAT #3 id=3 cnt=7 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=14 pr=0 pw=0 time=183 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 49693 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=39,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7749687
FETCH #3:c=0,e=150,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727749961
STAT #3 id=1 cnt=141 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=29 pr=3 pw=0 time=1978 us)'
STAT #3 id=2 cnt=141 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=29 pr=3 pw=0 time=1452 us)'
STAT #3 id=3 cnt=8 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=16 pr=0 pw=0 time=202 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 50204 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=50,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7750197
FETCH #3:c=0,e=159,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727750471
STAT #3 id=1 cnt=161 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=33 pr=3 pw=0 time=2206 us)'
STAT #3 id=2 cnt=161 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=33 pr=3 pw=0 time=1604 us)'
STAT #3 id=3 cnt=9 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=18 pr=0 pw=0 time=224 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 50701 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=42,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7750695
FETCH #3:c=0,e=151,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727750945
STAT #3 id=1 cnt=181 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=37 pr=3 pw=0 time=2421 us)'
STAT #3 id=2 cnt=181 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=37 pr=3 pw=0 time=1755 us)'
STAT #3 id=3 cnt=10 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=20 pr=0 pw=0 time=243 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 51162 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=39,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7751156
FETCH #3:c=0,e=150,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727751404
STAT #3 id=1 cnt=201 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=41 pr=3 pw=0 time=2635 us)'
STAT #3 id=2 cnt=201 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=41 pr=3 pw=0 time=1928 us)'
STAT #3 id=3 cnt=11 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=22 pr=0 pw=0 time=261 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 51620 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=38,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7751614
FETCH #3:c=0,e=149,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727751863
STAT #3 id=1 cnt=221 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=45 pr=3 pw=0 time=2848 us)'
STAT #3 id=2 cnt=221 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=45 pr=3 pw=0 time=2106 us)'
STAT #3 id=3 cnt=12 pid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=24 pr=0 pw=0 time=278 us)'
=============== ======
PARSING IN CURSOR #3 len=121 dep=2 uid=0 oct=3 lid=0 tim=11727457277 52081 hv=3150898423 ad='6c1ddee0'
select /*+ rule */ bucket, endpoint, col#, epvalue from histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
END OF STMT
EXEC #3:c=0,e=39,p=0 ,cr=0,cu=0,mis= 0,r=0,dep=2,og= 3,tim=117274572 7752075
FETCH #3:c=0,e=150,p= 0,cr=4,cu=0,mis =0,r=20,dep=2,o g=3,tim=1172745 727752325
STAT #3 id=1 cnt=241 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=49 pr=3 pw=0 time=3064 us)'
STAT #3 id=2 cnt=241 pid=1 pos=1 obj=253 op='TABLE ACCESS CLUSTER HISTGRM$ (cr=49 pr=3 pw=0 time=2270 us)'
STAT #3 id=3 cnt=13 ppid=2 pos=1 obj=252 op='INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=26 pr=0 pw=0 time=296 us)'
=============== ======
--More--(4%)
==------------------------------------------------------------------------------------------------
How to interpret the internal trace output
STAT Lines report explain plan statistics for the numbered <CURSOR>.
PARSE Parse a statement
EXEC Execute a pre-parsed statement.
FETCH Fetch rows from a cursor.
-
-
-
-
-
-
This is a very short brief explanation for Interpreting and investigating quey parsing ,wait events .
Vinod Sadanandan
Oracle DBA
