Re: Recursive SQL in a events 10046 trace file

From: Ron <support_at_dbainfopower.com>
Date: Thu, 19 Feb 2004 02:44:00 -0800
Message-ID: <i-ednbMFWsd1DKndRVn-tw_at_comcast.com>


Hello Oxmart,

  Can you please clarify why do you think recursive depth is not right?

  CURSOR #4 seem to be recursive SQL with the depth of 1.

Regards,

  Ron
  DBA Infopower
  
http://www.dbainfopower.com
  Standard disclaimer:
http://www.dbainfopower.com/dbaip_advice_disclaimer.html

"Oxmard" <shankeyp_at_no-spam.comcast.net> wrote in message news:lvCdnUsdE9Zgwq7dRVn-sw_at_comcast.com...
> Armed with my new O'Reilly book Optimizing Oracle Performance I have been
> trying to get a better understanding of how Oracle works.
>
> The book makes the statement, " A database cal with dep=n + 1 is the
> recursive child of the first subsequent dep=n database call listed in the
> SQL data stream. The book gives a few examples, and in trying it out it
> seemed to work until I tried the following SQL. My question are why does
> this not keep with the model? and how does one then account for this
> situation:
>
> Dump file c:\oracle\admin\to5\udump\to5_ora_296_2004-02-15a.trc
> Sun Feb 15 20:55:22 2004
> ORACLE V9.2.0.4.0 - Production vsnsta=0
> vsnsql=12 vsnxtr=3
> Windows 2000 Version 5.0 Service Pack 4, CPU type 586
> Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
> With the Partitioning, OLAP and Oracle Data Mining options
> JServer Release 9.2.0.4.0 - Production
> Windows 2000 Version 5.0 Service Pack 4, CPU type 586
> Instance name: to5
>
> Redo thread mounted by this instance: 1
>
> Oracle process number: 12
>
> Windows thread id: 296, image: ORACLE.EXE
>
>
> *** 2004-02-15 20:55:22.224
> *** SESSION ID:(14.178) 2004-02-15 20:55:22.124
> APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240
> =====================
> PARSING IN CURSOR #3 len=69 dep=0 uid=60 oct=42 lid=60 tim=43164454230
> hv=2004533713 ad='7157ec60'
> alter session set events '10046 trace name context forever, level 12'
> END OF STMT
> EXEC #3:c=0,e=19923,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=43164321789
> WAIT #3: nam='SQL*Net message to client' ela= 8 p1=1952673792 p2=1 p3=0
> WAIT #3: nam='SQL*Net message from client' ela= 5029 p1=1952673792 p2=1
 p3=0
> =====================
> PARSING IN CURSOR #3 len=238 dep=0 uid=60 oct=3 lid=60 tim=43164556233
> hv=4211298066 ad='7157da00'
> select distinct c.name, s.name, s.salesperson_id
> from customer c join orders on c.cust_nbr = orders.cust_nbr
> join salesperson s on orders.salesperson_id = s.salesperson_id
> where c.name = 'Crimson Medical Inc.'
> order by s.name, c.NAME
> END OF STMT
> PARSE #3:c=0,e=2204,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=43164556217
> BINDS #3:
> EXEC #3:c=10014,e=33290,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=43164688931
> WAIT #3: nam='SQL*Net message to client' ela= 10 p1=1952673792 p2=1 p3=0
> FETCH
> #3:c=70101,e=66839,p=0,cr=2900,cu=0,mis=0,r=1,dep=0,og=4,tim=43164785732
> WAIT #3: nam='SQL*Net message from client' ela= 754 p1=1952673792 p2=1
 p3=0
> WAIT #3: nam='SQL*Net message to client' ela= 7 p1=1952673792 p2=1 p3=0
> FETCH #3:c=0,e=13248,p=0,cr=0,cu=0,mis=0,r=3,dep=0,og=4,tim=43164823392
> WAIT #3: nam='SQL*Net message from client' ela= 3669 p1=1952673792 p2=1
 p3=0
> STAT #3 id=1 cnt=4 pid=0 pos=1 obj=0 op='SORT UNIQUE (cr=2900 r=0 w=0
> time=67115 us)'
> STAT #3 id=2 cnt=48 pid=1 pos=1 obj=0 op='NESTED LOOPS (cr=2900 r=0 w=0
> time=66511 us)'
> STAT #3 id=3 cnt=1440 pid=2 pos=1 obj=0 op='NESTED LOOPS (cr=1458 r=0 w=0
> time=40438 us)'
> =====================
> PARSING IN CURSOR #4 len=116 dep=1 uid=0 oct=3 lid=0 tim=43164909064
> hv=431456802 ad='70797038'
> select
>
 o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.
> flags from obj$ o where o.obj#=:1
> END OF STMT
> PARSE #4:c=0,e=1018,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=43164909048
> BINDS #4:
> bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
> offset=0
> bfp=093dbb5c bln=22 avl=04 flg=05
> value=39030
> EXEC #4:c=0,e=73894,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=43165043688
> FETCH #4:c=0,e=117,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=43165056304
> STAT #3 id=4 cnt=1440 pid=3 pos=1 obj=39030 op='TABLE ACCESS FULL ORDERS
> (cr=16 r=0 w=0 time=5866 us)'
> BINDS #4:
> bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
> offset=0
> bfp=093dbb5c bln=22 avl=04 flg=05
> value=39034
> EXEC #4:c=0,e=50695,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=43165132543
> FETCH #4:c=0,e=116,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=43165145593
> STAT #3 id=5 cnt=1440 pid=3 pos=2 obj=39034 op='TABLE ACCESS BY INDEX
 ROWID
> SALESPERSON (cr=1442 r=0 w=0 time=21449 us)'
> STAT #3 id=6 cnt=1440 pid=5 pos=1 obj=39035 op='INDEX UNIQUE SCAN
> SALESPERSON_PK (cr=2 r=0 w=0 time=7068 us)'
> BINDS #4:
> bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
> offset=0
> bfp=093dbb5c bln=22 avl=04 flg=05
> value=39013
> EXEC #4:c=0,e=53716,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=43165240373
> FETCH #4:c=0,e=119,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=43165253961
> STAT #3 id=7 cnt=48 pid=2 pos=2 obj=39013 op='TABLE ACCESS BY INDEX ROWID
> CUSTOMER (cr=1442 r=0 w=0 time=18732 us)'
> STAT #3 id=8 cnt=1440 pid=7 pos=1 obj=39014 op='INDEX UNIQUE SCAN
> CUSTOMER_PK (cr=2 r=0 w=0 time=7059 us)'
> =====================
> PARSING IN CURSOR #3 len=55 dep=0 uid=60 oct=42 lid=60 tim=43165395660
> hv=4110456808 ad='71571ff0'
> alter session set events '10046 trace name context off'
> END OF STMT
> PARSE #3:c=0,e=520,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=43165395645
> BINDS #3:
> EXEC #3:c=0,e=13838,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=43165477860
>
>
Received on Thu Feb 19 2004 - 11:44:00 CET

Original text of this message