Level |
Waits |
Binds |
1 |
False |
False |
4 |
False |
True |
8 |
True |
False |
12 |
True |
True |
For the same statement
sys@DEX11g> var oname varchar2(200) ;sys@DEX11g> exec :oname := 'PUBLIC' ;PL/SQL procedure successfully completed.sys@DEX11g> oradebug setmypidStatement processed.sys@DEX11g> oradebug event 10046 trace name context forever , level 1;Statement processed.sys@DEX11g> select count(*) from dexter.t where owner=:oname ; COUNT(*)---------- 28027sys@DEX11g> oradebug tracefile_name/u01/app/oracle/diag/rdbms/dex/dex/trace/dex_ora_21099.trcsys@DEX11g> oradebug event 10046 trace name context forever , level 4;Statement processed.sys@DEX11g> select count(*) from dexter.t where owner=:oname ; COUNT(*)---------- 28027sys@DEX11g> oradebug event 10046 trace name context forever , level 8;Statement processed.sys@DEX11g> select count(*) from dexter.t where owner=:oname ; COUNT(*)---------- 28027sys@DEX11g> oradebug event 10046 trace name context forever , level 12;Statement processed.sys@DEX11g> exec :oname := 'SYS' ;PL/SQL procedure successfully completed.sys@DEX11g> select sum(object_id) from dexter.t where owner=:oname ;SUM(OBJECT_ID)-------------- 870461706
Level 1
Only basic SQL statement execution Information
PARSING IN CURSOR #47769055467368 len=49 dep=0 uid=0 oct=3 lid=0 tim=1365214739408233 hv=1571021352 ad='861fc700' sqlid='fk8k4v1fu7sj8'select count(*) from dexter.t where owner=:onameEND OF STMTPARSE #47769055467368:c=1000,e=1475,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1365214739408230EXEC #47769055467368:c=6998,e=6678,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2966233522,tim=1365214739415599*** 2013-04-06 10:19:00.761FETCH #47769055467368:c=354946,e=1345404,p=1033,cr=1035,cu=0,mis=0,r=1,dep=0,og=1,plh=2966233522,tim=1365214740761236STAT #47769055467368 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1035 pr=1033 pw=0 time=1345423 us)'STAT #47769055467368 id=2 cnt=28027 pid=1 pos=1 obj=77141 op='TABLE ACCESS FULL T (cr=1035 pr=1033 pw=0 time=186082 us cost=290 size=14502 card=2417)'FETCH #47769055467368:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2966233522,tim=1365214740762714
Level 4
Includes information about variable binding, but does not wait for event statistics.
*** 2013-04-06 10:19:32.644=====================PARSING IN CURSOR #47769055467368 len=49 dep=0 uid=0 oct=3 lid=0 tim=1365214772644926 hv=1571021352 ad='861fc700' sqlid='fk8k4v1fu7sj8'select count(*) from dexter.t where owner=:onameEND OF STMTPARSE #47769055467368:c=999,e=311,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2966233522,tim=1365214772644923BINDS #47769055467368: Bind#0 oacdty=01 mxl=2000(400) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=01 csi=852 siz=2000 off=0 kxsbbbfp=2b72199594b0 bln=2000 avl=06 flg=05 value="PUBLIC"EXEC #47769055467368:c=1000,e=499,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2966233522,tim=1365214772645705*** 2013-04-06 10:19:32.689FETCH #47769055467368:c=24997,e=43476,p=1033,cr=1035,cu=0,mis=0,r=1,dep=0,og=1,plh=2966233522,tim=1365214772689301STAT #47769055467368 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1035 pr=1033 pw=0 time=43518 us)'STAT #47769055467368 id=2 cnt=28027 pid=1 pos=1 obj=77141 op='TABLE ACCESS FULL T (cr=1035 pr=1033 pw=0 time=15880 us cost=290 size=14502 card=2417)'FETCH #47769055467368:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2966233522,tim=1365214772690621PARSE #47769055501464:c=0,e=240,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1365214772692158BINDS #47769055501464: Bind#0 oacdty=123 mxl=4000(4000) mxlc=00 mal=00 scl=00 pre=00 oacflg=00 fl2=1000000 frm=00 csi=00 siz=4000 off=0toid ptr value=87B716C0 length=16AD26DE2F1F4C7C06E0431E4EE50AB7B3 kxsbbbfp=2b72199588c8 bln=4000 avl=00 flg=15 Bind#1 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=01 fl2=1000000 frm=00 csi=00 siz=24 off=0 kxsbbbfp=2b7219959c68 bln=22 avl=22 flg=05 value=### An invalid number has been seen.Memory contents are :Dump of memory from 0x00002B7219959C68 to 0x00002B7219959C7E2B7219959C60 000010C1 00000000 [........]2B7219959C70 00000000 00000000 00000000 00000000 [................]EXEC #47769055501464:c=2000,e=1550,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1365214772693876
Evel 8
Including wait time information, but not bound variable information
PARSING IN CURSOR #47769055467368 len=49 dep=0 uid=0 oct=3 lid=0 tim=1365214778550346 hv=1571021352 ad='861fc700' sqlid='fk8k4v1fu7sj8'select count(*) from dexter.t where owner=:onameEND OF STMTPARSE #47769055467368:c=0,e=213,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2966233522,tim=1365214778550343EXEC #47769055467368:c=0,e=88,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2966233522,tim=1365214778550849WAIT #47769055467368: nam='SQL*Net message to client' ela= 12 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365214778550986WAIT #47769055467368: nam='direct path read' ela= 144 file number=4 first dba=523 block cnt=13 obj#=77141 tim=1365214778551487WAIT #47769055467368: nam='direct path read' ela= 567 file number=4 first dba=537 block cnt=15 obj#=77141 tim=1365214778552290WAIT #47769055467368: nam='direct path read' ela= 71 file number=4 first dba=553 block cnt=15 obj#=77141 tim=1365214778552590WAIT #47769055467368: nam='direct path read' ela= 75 file number=4 first dba=569 block cnt=15 obj#=77141 tim=1365214778552969WAIT #47769055467368: nam='direct path read' ela= 76 file number=4 first dba=585 block cnt=15 obj#=77141 tim=1365214778553554WAIT #47769055467368: nam='direct path read' ela= 162 file number=4 first dba=601 block cnt=15 obj#=77141 tim=1365214778553924WAIT #47769055467368: nam='direct path read' ela= 89 file number=4 first dba=617 block cnt=15 obj#=77141 tim=1365214778554252WAIT #47769055467368: nam='direct path read' ela= 53 file number=4 first dba=633 block cnt=7 obj#=77141 tim=1365214778555146WAIT #47769055467368: nam='direct path read' ela= 57 file number=4 first dba=8832 block cnt=8 obj#=77141 tim=1365214778555479WAIT #47769055467368: nam='direct path read' ela= 1622 file number=4 first dba=8962 block cnt=62 obj#=77141 tim=1365214778557242WAIT #47769055467368: nam='direct path read' ela= 405 file number=4 first dba=9024 block cnt=64 obj#=77141 tim=1365214778558052WAIT #47769055467368: nam='direct path read' ela= 287 file number=4 first dba=9090 block cnt=62 obj#=77141 tim=1365214778559326WAIT #47769055467368: nam='direct path read' ela= 504 file number=4 first dba=9152 block cnt=64 obj#=77141 tim=1365214778560717WAIT #47769055467368: nam='direct path read' ela= 2238 file number=4 first dba=9218 block cnt=62 obj#=77141 tim=1365214778563809WAIT #47769055467368: nam='direct path read' ela= 116 file number=4 first dba=9280 block cnt=64 obj#=77141 tim=1365214778564291WAIT #47769055467368: nam='direct path read' ela= 104 file number=4 first dba=9346 block cnt=62 obj#=77141 tim=1365214778564767WAIT #47769055467368: nam='direct path read' ela= 88 file number=4 first dba=9408 block cnt=64 obj#=77141 tim=1365214778565239WAIT #47769055467368: nam='direct path read' ela= 123 file number=4 first dba=9474 block cnt=62 obj#=77141 tim=1365214778565588WAIT #47769055467368: nam='direct path read' ela= 85 file number=4 first dba=9536 block cnt=64 obj#=77141 tim=1365214778565908WAIT #47769055467368: nam='direct path read' ela= 111 file number=4 first dba=9602 block cnt=62 obj#=77141 tim=1365214778566363WAIT #47769055467368: nam='direct path read' ela= 84 file number=4 first dba=9664 block cnt=64 obj#=77141 tim=1365214778566672WAIT #47769055467368: nam='direct path read' ela= 105 file number=4 first dba=9730 block cnt=62 obj#=77141 tim=1365214778566982WAIT #47769055467368: nam='direct path read' ela= 86 file number=4 first dba=9792 block cnt=64 obj#=77141 tim=1365214778567389WAIT #47769055467368: nam='direct path read' ela= 48 file number=4 first dba=9858 block cnt=33 obj#=77141 tim=1365214778567664FETCH #47769055467368:c=15997,e=16853,p=1033,cr=1035,cu=0,mis=0,r=1,dep=0,og=1,plh=2966233522,tim=1365214778567899STAT #47769055467368 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1035 pr=1033 pw=0 time=16849 us)'STAT #47769055467368 id=2 cnt=28027 pid=1 pos=1 obj=77141 op='TABLE ACCESS FULL T (cr=1035 pr=1033 pw=0 time=12512 us cost=290 size=14502 card=2417)'WAIT #47769055467368: nam='SQL*Net message from client' ela= 243 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365214778568306FETCH #47769055467368:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2966233522,tim=1365214778568341WAIT #47769055467368: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365214778568361WAIT #47769055467368: nam='SQL*Net message from client' ela= 298 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365214778568672PARSE #47769055501464:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1365214778568752WAIT #47769055501464: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365214778569032EXEC #47769055501464:c=0,e=258,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1365214778569066
Level 12 includes statistics of all wait events and information about variable binding.
PARSING IN CURSOR #47769055380448 len=55 dep=0 uid=0 oct=3 lid=0 tim=1365215140961263 hv=2496234691 ad='843636f8' sqlid='24av8d6acm163'select sum(object_id) from dexter.t where owner=:onameEND OF STMTPARSE #47769055380448:c=2999,e=1855,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1365215140961260BINDS #47769055380448: Bind#0 oacdty=01 mxl=2000(400) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=01 csi=852 siz=2000 off=0 kxsbbbfp=2b72199594b0 bln=2000 avl=03 flg=05 value="SYS"EXEC #47769055380448:c=3000,e=3793,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2966233522,tim=1365215140965285WAIT #47769055380448: nam='SQL*Net message to client' ela= 16 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365215140965453WAIT #47769055380448: nam='asynch descriptor resize' ela= 10 outstanding #aio=0 current aio limit=152 new aio limit=182 obj#=77141 tim=1365215140965882WAIT #47769055380448: nam='direct path read' ela= 227 file number=4 first dba=523 block cnt=13 obj#=77141 tim=1365215140966341WAIT #47769055380448: nam='direct path read' ela= 474 file number=4 first dba=537 block cnt=15 obj#=77141 tim=1365215140967633WAIT #47769055380448: nam='direct path read' ela= 164 file number=4 first dba=553 block cnt=15 obj#=77141 tim=1365215140968680WAIT #47769055380448: nam='direct path read' ela= 508 file number=4 first dba=569 block cnt=15 obj#=77141 tim=1365215140969663WAIT #47769055380448: nam='direct path read' ela= 478 file number=4 first dba=585 block cnt=15 obj#=77141 tim=1365215140970818WAIT #47769055380448: nam='direct path read' ela= 176 file number=4 first dba=601 block cnt=15 obj#=77141 tim=1365215140971762WAIT #47769055380448: nam='direct path read' ela= 75 file number=4 first dba=617 block cnt=15 obj#=77141 tim=1365215140972313WAIT #47769055380448: nam='direct path read' ela= 47 file number=4 first dba=633 block cnt=7 obj#=77141 tim=1365215140973455WAIT #47769055380448: nam='direct path read' ela= 62 file number=4 first dba=8832 block cnt=8 obj#=77141 tim=1365215140974061WAIT #47769055380448: nam='direct path read' ela= 1412 file number=4 first dba=8962 block cnt=62 obj#=77141 tim=1365215140975874WAIT #47769055380448: nam='direct path read' ela= 568 file number=4 first dba=9024 block cnt=64 obj#=77141 tim=1365215140976990WAIT #47769055380448: nam='direct path read' ela= 566 file number=4 first dba=9090 block cnt=62 obj#=77141 tim=1365215140979413WAIT #47769055380448: nam='direct path read' ela= 463 file number=4 first dba=9152 block cnt=64 obj#=77141 tim=1365215140981749WAIT #47769055380448: nam='direct path read' ela= 597 file number=4 first dba=9218 block cnt=62 obj#=77141 tim=1365215140984267WAIT #47769055380448: nam='direct path read' ela= 419 file number=4 first dba=9280 block cnt=64 obj#=77141 tim=1365215140986349WAIT #47769055380448: nam='direct path read' ela= 268 file number=4 first dba=9346 block cnt=62 obj#=77141 tim=1365215140988105WAIT #47769055380448: nam='direct path read' ela= 589 file number=4 first dba=9408 block cnt=64 obj#=77141 tim=1365215140990125WAIT #47769055380448: nam='direct path read' ela= 311 file number=4 first dba=9474 block cnt=62 obj#=77141 tim=1365215140991845WAIT #47769055380448: nam='direct path read' ela= 392 file number=4 first dba=9536 block cnt=64 obj#=77141 tim=1365215140993754WAIT #47769055380448: nam='direct path read' ela= 450 file number=4 first dba=9602 block cnt=62 obj#=77141 tim=1365215140995500WAIT #47769055380448: nam='direct path read' ela= 526 file number=4 first dba=9664 block cnt=64 obj#=77141 tim=1365215140997729WAIT #47769055380448: nam='direct path read' ela= 97 file number=4 first dba=9730 block cnt=62 obj#=77141 tim=1365215140998471WAIT #47769055380448: nam='direct path read' ela= 141 file number=4 first dba=9792 block cnt=64 obj#=77141 tim=1365215140998813WAIT #47769055380448: nam='direct path read' ela= 108 file number=4 first dba=9858 block cnt=33 obj#=77141 tim=1365215140999155FETCH #47769055380448:c=33995,e=33888,p=1033,cr=1035,cu=0,mis=0,r=1,dep=0,og=1,plh=2966233522,tim=1365215140999410STAT #47769055380448 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1035 pr=1033 pw=0 time=33879 us)'STAT #47769055380448 id=2 cnt=31142 pid=1 pos=1 obj=77141 op='TABLE ACCESS FULL T (cr=1035 pr=1033 pw=0 time=84280 us cost=290 size=26587 card=2417)'WAIT #47769055380448: nam='SQL*Net message from client' ela= 289 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365215140999832FETCH #47769055380448:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2966233522,tim=1365215140999873WAIT #47769055380448: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365215140999895WAIT #47769055380448: nam='SQL*Net message from client' ela= 541 driver id=1650815232 #bytes=1 p3=0 obj#=77141 tim=1365215141000449