Thanks for your reply, Daniel. Yes, it makes sense for the EXEC calls, but it doesn't explain the PARSEs, does it?
PARSING IN CURSOR #1 len=94 dep=0... PARSE #1:c=0,e=141,p=0,cr=0,cu=0,mis=0,r=0,dep=0... PARSING IN CURSOR #2 len=68 dep=1... PARSE #2:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1... Here I presume elapsed time of the PL/SQL call is 141-60=81 microsec, but it doesn't follow the same rule of parent db call following the recursive/child one - it is out of sequence. It is even more interesting with FETCHes. I can't seem to find FETCH call for the parent anywhere in the trace file. Maybe it makes sense to omit this call altogether as time tallied against PL/SQL proc call goes to EXEC anyway, but than again it breaks the rule. And no, I don't think it is a trace activation/data collection error as these parent-child cursors appear in the middle of the trace. Thanks again, Boris Dali. --- Daniel Fink <[EMAIL PROTECTED]> wrote: > Boris, > > Cary is correct. It gets a little confusing, > especially with pl/sql > involved. It also helps to remember to differentiate > between database > calls (parse/execute/fetch) and other events > (wait/stat). > > Using your example below, I'll attempt an > explanation inline. > > Daniel Fink > > Boris Dali wrote: > > > Reading Cary's "Optimizing Oracle Performance", > page > > 91 it says: > > "A database call with dep=n+1 is the recursive > child > > of the first SUBSEQUENT (empasis mine) dep=n > database > > call listed in the SQL trace data stream" > > > > Does this apply to the SQL issued from PL/SQL? > > > > I am looking at the simple packaged stored proc: > > > > PACKAGE BODY nav_tree_pkg is > > PROCEDURE GET_NAV_PARENT_NODE_ID > > ( p_NodeId IN NUMBER, > > p_ParentNodeId OUT NUMBER) > > IS > > BEGIN > > SELECT PARENT_NAV_NODE_ID INTO p_ParentNodeId > > FROM NAV_NODE > > WHERE NAV_NODE_ID = p_NodeId; > > EXCEPTION > > WHEN NO_DATA_FOUND THEN > > p_ParentNodeId := -1 ; > > END; -- Procedure > > END; > > > > ... and here's what I see in the trace (sorry the > > lines are probably wrapped): > > > > ===================== > > PARSING IN CURSOR #1 len=94 dep=0 uid=83 oct=47 > lid=83 > > tim=1617285502494 hv=1138148843 ad='605d0998' > > BEGIN nav_tree_pkg.get_nav_parent_node_id( > > :p_nodeid, > > :p_parentnodeid > > ); > > END; > > > > END OF STMT > > PARSE > #1:c=0,e=141,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1617285502483 > > > > BINDS #1: bind 0: dty=2 mxl=22(22) mal=00 scl=00 > pre=00 > > oacflg=01 oacfl2=0 size=48 offset=0 > > bfp=800003fbc005ff80 bln=22 avl=01 flg=05 > > value=0 > > bind 1: dty=2 mxl=22(22) mal=00 scl=00 pre=00 > > oacflg=01 oacfl2=0 size=0 offset=24 > > bfp=800003fbc005ff98 bln=22 avl=00 flg=01 > > ===================== > > Here, the pl/sql block is parsed. The next step in > the statement process > is to execute the statement (parse/execute/fetch). > However, notice that > EXEC #1 is not the next database call. > > > > > PARSING IN CURSOR #2 len=68 dep=1 uid=98 oct=3 > lid=98 > > tim=1617285503241 hv=1778717541 ad='606795e8' > > SELECT PARENT_NAV_NODE_ID FROM NAV_NODE > > WHERE NAV_NODE_ID = :b1 > > END OF STMT > > PARSE > #2:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1617285503230 > > BINDS #2: > > bind 0: dty=2 mxl=22(21) mal=00 scl=00 pre=00 > > oacflg=03 oacfl2=4000000000000001 size=24 offset=0 > > bfp=800003fbc005f660 bln=22 avl=01 flg=05 > > value=0 > > Okay, here we parse the sql statement inside the > block. In the next > couple of db calls, we do the execute/fetch of > Cursor #2. > > > > > EXEC > #2:c=0,e=151,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1617285503563 > > FETCH > > > #2:c=0,e=40,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1617285503648 > > WAIT #1: nam='SQL*Net message to client' ela= 2 > > p1=1413697536 p2=1 p3=0 > > EXEC > #1:c=0,e=1037,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1617285503786 > > Here is the execute database call for the block. It > is the execution of > the block that motivates the parse/execute/fetch of > the inner statement. > > > > > WAIT #1: nam='SQL*Net message from client' ela= > 2470 > > p1=1413697536 p2=1 p3=0 > > ===================== > > ... Totaly different calls > > ===================== > > > > So here it looks like the child CURSOR #2 with > dep=1 > > is emitted AFTER the parent (CURSOR #1, dep=0) > > > > Thanks, > > Boris Dali. ______________________________________________________________________ Post your free ad now! http://personals.yahoo.ca -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Boris Dali INET: [EMAIL PROTECTED] Fat City Network Services -- 858-538-5051 http://www.fatcity.com San Diego, California -- Mailing list and web hosting services --------------------------------------------------------------------- To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
