sql_trace、access path和db_file_mul详解
来源:岁月联盟
时间:2008-01-28
本文的测试环境:Windows xp、oracle9.2.
SQL> create table t as select * from dba_objects;Table created.SQL> select count(*) from t; COUNT(*)---------- 30536SQL> select file_id,block_id,blocks from dba_extents where segment_name=''T''; FILE_ID BLOCK_ID BLOCKS---------- ---------- ---------- 1 50921 8 1 50929 8 1 51233 8 1 51241 8 1 51249 8 1 51257 8 1 51265 8 1 51273 8 1 51281 8 1 51289 8 1 51297 8 FILE_ID BLOCK_ID BLOCKS---------- ---------- ---------- 1 51305 8 1 51313 8 1 51321 8 1 51329 8 1 51337 8 1 51465 128 1 51593 128 1 51721 12819 rows selected.SQL> show parameter db_fileNAME TYPE VALUE------------------------------------ ----------- ------db_file_multiblock_read_count integer 16db_file_name_convert stringdb_files integer 200SQL> alter session set events ''10046 trace name context off''; |
结果如下,采用的是全表扫描,共扫描了5次。
注释:p1是文件号,p2起始块号,p3读取数据块数量
*** 2008-01-21 12:11:20.000=====================PARSING IN CURSOR #1 len=68 dep=0 uid=0 oct=42 lid=0 tim=2925420357 hv=570864185 ad=''668b0b0c''alter session set events ''10046 trace name context forever,level 12''END OF STMTEXEC #1:c=0,e=156,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=2925420341WAIT #1: nam=''SQL*Net message to client'' ela= 10 p1=1111838976 p2=1 p3=0WAIT #1: nam=''SQL*Net message from client'' ela= 6417020 p1=1111838976 p2=1 p3=0=====================PARSING IN CURSOR #1 len=22 dep=0 uid=0 oct=3 lid=0 tim=2931845333 hv=2199322426 ad=''6710b08c''select count(*) from tEND OF STMTPARSE #1:c=0,e=88,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2931845326BINDS #1:EXEC #1:c=0,e=1534,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2931853164WAIT #1: nam=''SQL*Net message to client'' ela= 9 p1=1111838976 p2=1 p3=0WAIT #1: nam=''db file scattered read'' ela= 8813 p1=1 p2=51677 p3=16WAIT #1: nam=''db file scattered read'' ela= 1307 p1=1 p2=51693 p3=16WAIT #1: nam=''db file scattered read'' ela= 5570 p1=1 p2=51709 p3=12WAIT #1: nam=''db file scattered read'' ela= 2616 p1=1 p2=51729 p3=13WAIT #1: nam=''db file scattered read'' ela= 595 p1=1 p2=51749 p3=6FETCH #1:c=15625,e=36032,p=63,cr=421,cu=0,mis=0,r=1,dep=0,og=4,tim=2931890915WAIT #1: nam=''SQL*Net message from client'' ela= 409 p1=1111838976 p2=1 p3=0FETCH #1:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=2931893361WAIT #1: nam=''SQL*Net message to client'' ela= 4 p1=1111838976 p2=1 p3=0*** 2008-01-21 11:49:52.000WAIT #1: nam=''SQL*Net message from client'' ela= 15276041 p1=1111838976 p2=1 p3=0STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op=''SORT AGGREGATE ''STAT #1 id=2 cnt=30536 pid=1 pos=1 obj=31687 op=''TABLE ACCESS FULL T ''=====================PARSING IN CURSOR #1 len=55 dep=0 uid=0 oct=42 lid=0 tim=2947176010 hv=3381932903 ad=''668aba24''alter session set events ''10046 trace name context off''END OF STMTPARSE #1:c=0,e=91,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2947176003BINDS #1:EXEC #1:c=0,e=857,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2947181612 |
重新创建一个表空间,其类型为uniform size为1M,在oracle9.2默认的表空间类型是autoallocate
SQL> create tablespace test datafile ':/oracle/oradata/orcl/test.dbf'' size 100m extent management local uniform size 1m;Tablespace created.SQL> alter table t move tablespace test;Table altered.SQL> select file_id,block_id,blocks from dba_extents where segment_name=''T''; FILE_ID BLOCK_ID BLOCKS---------- ---------- ---------- 15 9 128 15 137 128 15 265 128 15 393 128SQL> show parameter read_coNAME TYPE VALUE------------------------------------ ----------- -----db_file_multiblock_read_count integer 16SQL> alter session set db_file_multiblock_read_count=128;Session altered.SQL> show parameter read_coNAME TYPE VALUE------------------------------------ ----------- -----db_file_multiblock_read_count integer 128SQL> alter session set events ''10046 trace name context forever,level 12'';Session altered.SQL> select count(*) from t; COUNT(*)---------- 30536SQL> alter session set events ''10046 trace name context off'';Session altered.SQL> alter session set events ''10046 trace name context forever,level 12'';Session altered.SQL> select count(object_id) from t;COUNT(OBJECT_ID)---------------- 30536SQL> alter session set events ''10046 trace name context off'';Session altered.*** 2008-01-21 11:57:30.000=====================PARSING IN CURSOR #1 len=68 dep=0 uid=0 oct=42 lid=0 tim=3404883601 hv=570864185 ad=''668b0b0c''alter session set events ''10046 trace name context forever,level 12''END OF STMTEXEC #1:c=0,e=107,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3404883596WAIT #1: nam=''SQL*Net message to client'' ela= 7 p1=1111838976 p2=1 p3=0WAIT #1: nam=''SQL*Net message from client'' ela= 8723581 p1=1111838976 p2=1 p3=0=====================PARSING IN CURSOR #1 len=22 dep=0 uid=0 oct=3 lid=0 tim=3413615443 hv=2199322426 ad=''6710b08c''select count(*) from tEND OF STMTPARSE #1:c=0,e=791,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=3413615434BINDS #1:EXEC #1:c=0,e=962,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3413622098WAIT #1: nam=''SQL*Net message to client'' ela= 6 p1=1111838976 p2=1 p3=0WAIT #1: nam=''db file scattered read'' ela= 26551 p1=15 p2=10 p3=127WAIT #1: nam=''db file scattered read'' ela= 21707 p1=15 p2=137 p3=128WAIT #1: nam=''db file scattered read'' ela= 21034 p1=15 p2=265 p3=128WAIT #1: nam=''db file scattered read'' ela= 6274 p1=15 p2=393 p3=34FETCH #1:c=31250,e=94765,p=417,cr=421,cu=0,mis=0,r=1,dep=0,og=4,tim=3413718512WAIT #1: nam=''SQL*Net message from client'' ela= 405 p1=1111838976 p2=1 p3=0FETCH #1:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=3413721284WAIT #1: nam=''SQL*Net message to client'' ela= 5 p1=1111838976 p2=1 p3=0*** 2008-01-21 11:58:34.000WAIT #1: nam=''SQL*Net message from client'' ela= 55266334 p1=1111838976 p2=1 p3=0STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op=''SORT AGGREGATE ''=====================PARSING IN CURSOR #2 len=116 dep=1 uid=0 oct=3 lid=0 tim=3468993615 hv=189272129 ad=''672eea30''select o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.flags from obj$ o where o.obj#=:1END OF STMTPARSE #2:c=0,e=148,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=3468993604BINDS #2: bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0 bfp=05f4a0cc bln=22 avl=04 flg=05 value=31687EXEC #2:c=0,e=3824,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=3469002280FETCH #2:c=0,e=78,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=3469003223STAT #1 id=2 cnt=30536 pid=1 pos=1 obj=31687 op=''TABLE ACCESS FULL T ''=====================PARSING IN CURSOR #1 len=55 dep=0 uid=0 oct=42 lid=0 tim=3469005223 hv=3381932903 ad=''668aba24''alter session set events ''10046 trace name context off''END OF STMTPARSE #1:c=0,e=86,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3469005215BINDS #1:EXEC #1:c=0,e=806,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3469009599 SQL> alter session set events ''10046 trace name context forever,level 12'';Session altered.SQL> select count(object_id) from t;COUNT(OBJECT_ID)---------------- 30536SQL> alter session set events ''10046 trace name context off'';Session altered.*** 2008-1-21 14:00:39.000=====================PARSING IN CURSOR #1 len=68 dep=0 uid=0 oct=42 lid=0 tim=3146410393 hv=570864185 ad=''668b0b0c''alter session set events ''10046 trace name context forever,level 12''END OF STMTEXEC #1:c=0,e=25200,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3146410376WAIT #1: nam=''SQL*Net message to client'' ela= 13714 p1=1111838976 p2=1 p3=0*** 2008-01-26 14:01:05.000WAIT #1: nam=''SQL*Net message from client'' ela= 25992096 p1=1111838976 p2=1 p3=0=====================PARSING IN CURSOR #1 len=30 dep=0 uid=0 oct=3 lid=0 tim=3172483520 hv=3181685953 ad=''66484f6c''select count(object_id) from tEND OF STMTPARSE #1:c=0,e=19961,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=3172483510BINDS #1:EXEC #1:c=0,e=34883,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3172522525WAIT #1: nam=''SQL*Net message to client'' ela= 8 p1=1111838976 p2=1 p3=0WAIT #1: nam=''db file scattered read'' ela= 221317 p1=15 p2=10 p3=127WAIT #1: nam=''db file scattered read'' ela= 63377 p1=15 p2=137 p3=128WAIT #1: nam=''db file scattered read'' ela= 70986 p1=15 p2=265 p3=128WAIT #1: nam=''db file scattered read'' ela= 4848 p1=15 p2=393 p3=34FETCH #1:c=93750,e=390135,p=417,cr=420,cu=0,mis=0,r=1,dep=0,og=4,tim=3172914415WAIT #1: nam=''SQL*Net message from client'' ela= 18930 p1=1111838976 p2=1 p3=0FETCH #1:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=3172936022WAIT #1: nam=''SQL*Net message to client'' ela= 4 p1=1111838976 p2=1 p3=0WAIT #1: nam=''SQL*Net message from client'' ela= 3671714 p1=1111838976 p2=1 p3=0STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op=''SORT AGGREGATE ''STAT #1 id=2 cnt=30536 pid=1 pos=1 obj=31687 op=''TABLE ACCESS FULL T ''=====================PARSING IN CURSOR #1 len=55 dep=0 uid=0 oct=42 lid=0 tim=3176627539 hv=3381932903 ad=''668aba24''alter session set events ''10046 trace name context off''END OF STMTPARSE #1:c=0,e=107,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3176627528BINDS #1:EXEC #1:c=0,e=889,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3176633060 SQL> create unique index IDX_T_ID on T (object_id);Index created.SQL> alter session set events ''10046 trace name context forever,level 12'';Session altered.SQL> select count(object_id) from t where object_id>0;COUNT(OBJECT_ID)---------------- 30536SQL> alter session set events ''10046 trace name context off'';Session altered. |
此种情况说明使用了不合理的索引,此时索引使用的是index range扫描方式,从另一个方面也阐述了"db file sequential read"的产生原理。
*** 2008-01-21 14:01:55.000=====================PARSING IN CURSOR #1 len=68 dep=0 uid=0 oct=42 lid=0 tim=3222433563 hv=570864185 ad=''668b0b0c''alter session set events ''10046 trace name context forever,level 12''END OF STMTEXEC #1:c=0,e=85,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3222433552WAIT #1: nam=''SQL*Net message to client'' ela= 5 p1=1111838976 p2=1 p3=0*** 2008-01-21 14:02:09.000WAIT #1: nam=''SQL*Net message from client'' ela= 14067572 p1=1111838976 p2=1 p3=0=====================PARSING IN CURSOR #1 len=48 dep=0 uid=0 oct=3 lid=0 tim=3236513737 hv=1107120101 ad=''677ffa8c''select count(object_id) from t where object_id>0END OF STMTPARSE #1:c=0,e=1716,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=3236513728BINDS #1:EXEC #1:c=0,e=944,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3236519497WAIT #1: nam=''SQL*Net message to client'' ela= 7 p1=1111838976 p2=1 p3=0WAIT #1: nam=''db file sequential read'' ela= 12439 p1=1 p2=50923 p3=1WAIT #1: nam=''db file sequential read'' ela= 203 p1=1 p2=50924 p3=1WAIT #1: nam=''db file sequential read'' ela= 158 p1=1 p2=50925 p3=1WAIT #1: nam=''db file sequential read'' ela= 157 p1=1 p2=50926 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=50927 p3=1WAIT #1: nam=''db file sequential read'' ela= 149 p1=1 p2=50928 p3=1WAIT #1: nam=''db file sequential read'' ela= 156 p1=1 p2=50929 p3=1WAIT #1: nam=''db file sequential read'' ela= 150 p1=1 p2=50930 p3=1WAIT #1: nam=''db file sequential read'' ela= 148 p1=1 p2=50931 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=50932 p3=1WAIT #1: nam=''db file sequential read'' ela= 167 p1=1 p2=50933 p3=1WAIT #1: nam=''db file sequential read'' ela= 156 p1=1 p2=50934 p3=1WAIT #1: nam=''db file sequential read'' ela= 147 p1=1 p2=50935 p3=1WAIT #1: nam=''db file sequential read'' ela= 149 p1=1 p2=50936 p3=1WAIT #1: nam=''db file sequential read'' ela= 1330 p1=1 p2=51233 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51234 p3=1WAIT #1: nam=''db file sequential read'' ela= 149 p1=1 p2=51235 p3=1WAIT #1: nam=''db file sequential read'' ela= 142 p1=1 p2=51236 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51237 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51238 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51239 p3=1WAIT #1: nam=''db file sequential read'' ela= 146 p1=1 p2=51240 p3=1WAIT #1: nam=''db file sequential read'' ela= 203 p1=1 p2=51241 p3=1WAIT #1: nam=''db file sequential read'' ela= 158 p1=1 p2=51242 p3=1WAIT #1: nam=''db file sequential read'' ela= 158 p1=1 p2=51243 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51244 p3=1WAIT #1: nam=''db file sequential read'' ela= 158 p1=1 p2=51245 p3=1WAIT #1: nam=''db file sequential read'' ela= 154 p1=1 p2=51246 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51247 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51248 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51249 p3=1WAIT #1: nam=''db file sequential read'' ela= 172 p1=1 p2=51250 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51251 p3=1WAIT #1: nam=''db file sequential read'' ela= 213 p1=1 p2=51252 p3=1WAIT #1: nam=''db file sequential read'' ela= 166 p1=1 p2=51253 p3=1WAIT #1: nam=''db file sequential read'' ela= 156 p1=1 p2=51254 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51255 p3=1WAIT #1: nam=''db file sequential read'' ela= 154 p1=1 p2=51256 p3=1WAIT #1: nam=''db file sequential read'' ela= 156 p1=1 p2=51257 p3=1WAIT #1: nam=''db file sequential read'' ela= 154 p1=1 p2=51258 p3=1WAIT #1: nam=''db file sequential read'' ela= 171 p1=1 p2=51259 p3=1WAIT #1: nam=''db file sequential read'' ela= 156 p1=1 p2=51260 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51261 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=51262 p3=1WAIT #1: nam=''db file sequential read'' ela= 149 p1=1 p2=51263 p3=1WAIT #1: nam=''db file sequential read'' ela= 147 p1=1 p2=51264 p3=1WAIT #1: nam=''db file sequential read'' ela= 150 p1=1 p2=51265 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=51266 p3=1WAIT #1: nam=''db file sequential read'' ela= 140 p1=1 p2=51267 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=51268 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51269 p3=1WAIT #1: nam=''db file sequential read'' ela= 146 p1=1 p2=51270 p3=1WAIT #1: nam=''db file sequential read'' ela= 148 p1=1 p2=51271 p3=1WAIT #1: nam=''db file sequential read'' ela= 199 p1=1 p2=51272 p3=1WAIT #1: nam=''db file sequential read'' ela= 158 p1=1 p2=51273 p3=1WAIT #1: nam=''db file sequential read'' ela= 154 p1=1 p2=51274 p3=1WAIT #1: nam=''db file sequential read'' ela= 154 p1=1 p2=51275 p3=1WAIT #1: nam=''db file sequential read'' ela= 153 p1=1 p2=51276 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=51277 p3=1WAIT #1: nam=''db file sequential read'' ela= 152 p1=1 p2=51278 p3=1WAIT #1: nam=''db file sequential read'' ela= 151 p1=1 p2=51279 p3=1WAIT #1: nam=''db file sequential read'' ela= 150 p1=1 p2=51280 p3=1WAIT #1: nam=''db file sequential read'' ela= 148 p1=1 p2=51281 p3=1FETCH #1:c=15625,e=102159,p=63,cr=64,cu=0,mis=0,r=1,dep=0,og=4,tim=3236628878WAIT #1: nam=''SQL*Net message from client'' ela= 382 p1=1111838976 p2=1 p3=0FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=3236631569WAIT #1: nam=''SQL*Net message to client'' ela= 4 p1=1111838976 p2=1 p3=0WAIT #1: nam=''SQL*Net message from client'' ela= 3303736 p1=1111838976 p2=1 p3=0STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op=''SORT AGGREGATE ''STAT #1 id=2 cnt=30536 pid=1 pos=1 obj=31689 op=''INDEX RANGE SCAN IDX_T_ID ''=====================PARSING IN CURSOR #1 len=55 dep=0 uid=0 oct=42 lid=0 tim=3239940284 hv=3381932903 ad=''668aba24''alter session set events ''10046 trace name context off''END OF STMTPARSE #1:c=0,e=92,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3239940275BINDS #1:EXEC #1:c=0,e=1028,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3239947806 SQL> analyze table t compute statistics;Table analyzed.SQL> alter session set events ''10046 trace name context forever,level 12'';Session altered.SQL> select count(object_id) from t where object_id>0;COUNT(OBJECT_ID)---------------- 30536SQL> alter session set events ''10046 trace name context off'';Session altered. |
此现象说明假如表是被分析过的话,采用的是CBO。
*** 2008-01-21 14:10:18.000=====================PARSING IN CURSOR #1 len=68 dep=0 uid=0 oct=42 lid=0 tim=3724965605 hv=570864185 ad=''668b0b0c''alter session set events ''10046 trace name context forever,level 12''END OF STMTEXEC #1:c=0,e=153,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3724965598WAIT #1: nam=''SQL*Net message to client'' ela= 7 p1=1111838976 p2=1 p3=0*** 2008-01-21 14:10:28.000WAIT #1: nam=''SQL*Net message from client'' ela= 10044728 p1=1111838976 p2=1 p3=0=====================PARSING IN CURSOR #1 len=48 dep=0 uid=0 oct=3 lid=0 tim=3735044065 hv=1107120101 ad=''677ffa8c''select count(object_id) from t where object_id>0END OF STMTPARSE #1:c=0,e=18398,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=3735044052BINDS #1:EXEC #1:c=0,e=908,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3735050327WAIT #1: nam=''SQL*Net message to client'' ela= 5 p1=1111838976 p2=1 p3=0FETCH #1:c=15625,e=16491,p=0,cr=68,cu=0,mis=0,r=1,dep=0,og=4,tim=3735068413WAIT #1: nam=''SQL*Net message from client'' ela= 470 p1=1111838976 p2=1 p3=0FETCH #1:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=3735071416WAIT #1: nam=''SQL*Net message to client'' ela= 6 p1=1111838976 p2=1 p3=0WAIT #1: nam=''SQL*Net message from client'' ela= 3767452 p1=1111838976 p2=1 p3=0STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op=''SORT AGGREGATE ''STAT #1 id=2 cnt=30536 pid=1 pos=1 obj=31690 op=''INDEX FAST FULL SCAN IDX_T_ID ''=====================PARSING IN CURSOR #1 len=55 dep=0 uid=0 oct=42 lid=0 tim=3738845289 hv=3381932903 ad=''668aba24''alter session set events ''10046 trace name context off''END OF STMTPARSE #1:c=0,e=91,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3738845282BINDS #1:EXEC #1:c=0,e=876,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3738850186 |