RE: sql trace - recursive relationships
Boris, thanks for sending me your data. The following note pertains only to the excerpt you sent me; I didn't look at the whole trace file. Here's the excerpt you sent: excerpt = PARSING IN CURSOR #1 len=94 dep=0 uid=83 oct=47 lid=83 tim=1614119418158 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=1177,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=0,tim=1614119418146 BINDS #1: bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=01 oacfl2=8001 size=48 offset=0 bfp=83fbc005f2c0 bln=22 avl=01 flg=05 value=0 bind 1: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=01 oacfl2=8001 size=0 offset=24 bfp=83fbc005f2d8 bln=22 avl=00 flg=01 = PARSING IN CURSOR #2 len=68 dep=1 uid=98 oct=3 lid=98 tim=1614119426242 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=676,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=1614119426225 BINDS #2: bind 0: dty=2 mxl=22(21) mal=00 scl=00 pre=00 oacflg=03 oacfl2=1 size=24 offset=0 bfp=83fbc005f6f8 bln=22 avl=01 flg=05 value=0 EXEC #2:c=0,e=1345,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1614119427797 WAIT #2: nam='db file sequential read' ela= 2899 p1=14 p2=119562 p3=1 WAIT #2: nam='db file sequential read' ela= 4290 p1=11 p2=28810 p3=1 FETCH #2:c=0,e=7381,p=2,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1614119435232 WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1413697536 p2=1 p3=0 EXEC #1:c=1,e=17026,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1614119435461 WAIT #1: nam='SQL*Net message from client' ela= 15771 p1=1413697536 p2=1 p3=0 = /excerpt Here's the stuff from the excerpt that is required to do this exercise. The first step that most people mess up is the failure to ignore the PARSING IN CURSOR sections during the mechanical step of determining the recursive SQL relationships: abbreviated-excerpt PARSE #1:c=0,e=1177,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=0,tim=1614119418146 PARSE #2:c=0,e=676,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=1614119426225 EXEC #2:c=0,e=1345,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1614119427797 FETCH #2:c=0,e=7381,p=2,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1614119435232 EXEC #1:c=1,e=17026,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1614119435461 /abbreviated-excerpt I think your tree is as follows (it's late, and my eyes are beginning to blur). I've used indentation to represent the parent-child relationships (the number of tabs on a line equals the call's dep value), and the number represents the sequence in which the line was encountered within the trace file. 1. PARSE #1:e=1177 5. EXEC #1:3=17026 2. PARSE #2:e=676 3. EXEC #2:e=1345 4. FETCH #2:e=7381 When you use this method, it helps to leave a blank line for each level by which the dep value of a call exceeds the prior line's dep value. This leaves enough space into which you can later backpatch when you find the recursive parent. In this case, the tree looked like this right before I parsed line 5 of the abbreviated trace data: 1. PARSE #1:e=1177 2. PARSE #2:e=676 3. EXEC #2:e=1345 4. FETCH #2:e=7381 Then I plugged in the 5. EXEC #1 when I encountered the dep=0 dbcall on line 5 that was the parent of all the outstanding dep=1 children. This is a really convenient notation, by the way. I wish I had thought of it in time for the book. It beats the heck out of trying to find a super-wide sheet of paper and then drawing boxes all over it. I will incorporate this into our PD101 course notes, though, so thanks for the inspiration. At this point, to derive meaning from the relationships we've charted, we need now to pay attention to the PARSING IN CURSOR information. Here, the PARSE, EXEC, and FETCH calls (P/E/F) upon cursor #2 are all recursive children of the EXEC call upon cursor #1. Therefore, the P/E/F operations upon the SELECT...FROM NAV_NODE statement are children of the EXEC of the PL/SQL block. I suspect that Raj and Dan are exactly right, but I don't have the energy tonight to cross-check their notes with what I've said here. Happy Thanksgiving, everyone. Cary Millsap Hotsos Enterprises, Ltd. http://www.hotsos.com Upcoming events: - Performance Diagnosis 101: 12/16 Detroit, 1/27 Atlanta - SQL Optimization 101: 12/8 Dallas, 2/16 Dallas - Hotsos Symposium 2004: March 7-10 Dallas - Visit www.hotsos.com for schedule details... -Original Message- Boris Dali Sent: Wednesday, November 26, 2003 8:30 AM To: Multiple recipients of list ORACLE-L Thanks, Raj. So yes, as I said in my other email - the rule stated in the book seem to apply to EXEC db calls only (in case of SQL fired from PL/SQL). I guess I misinterpreted it the way that it applies to ALL db calls for recursive cursors. Thanks, Boris Dali. --- Jamadagni, Rajendra [EMAIL PROTECTED] wrote: Sorry about the last empty
RE: sql trace - recursive relationships
Thanks a lot, Cary. Indeed the indented notation seems rather convenient. I would be delighted to take your PD101 course, just not sure if people here dealing with the training budget would share the delight with me :-( Doesn't hurt to ask though... Thanks again, 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).
RE: sql trace - recursive relationships
Rajendra dot Jamadagni at nospamespn dot com All Views expressed in this email are strictly personal. QOTD: Any clod can have facts, having an opinion is an art ! -Original Message- Sent: Monday, November 24, 2003 8:10 PM To: Multiple recipients of list ORACLE-L 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 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 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 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). ** This e-mail message is confidential, intended only for the named recipient(s) above and may contain information that is privileged, attorney work product or exempt from disclosure under applicable law. If you have received this message in error, or are not the named recipient(s), please immediately notify corporate MIS at (860) 766-2000 and delete this e-mail message from your computer, Thank you. **5 -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Jamadagni, Rajendra 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).
RE: sql trace - recursive relationships
Sorry about the last empty email ... Cary is right, the EXEC at dep=0 is the database call you should be looking for, why? because until #1 is parsed, db has no way of finding what needs to do. And once it finds that Oh I must run a SQL, the dep increases. So, I'd look for a subsequent EXEC instead of PARSE line. I'll take a stab at this ... lines with -- are mine = PARSING IN CURSOR #1 len=94 dep=0 uid=83 oct=47 lid=83 tim=1617285502494 hv=1138148843 ad='605d0998' -- Anonymous block BEGIN nav_tree_pkg.get_nav_parent_node_id( :p_nodeid, :p_parentnodeid ); END; END OF STMT -- anon block gets parsed, it probably contains a sql. PARSE #1:c=0,e=141,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1617285502483 -- Found the sql, so oracle opened another cursor #1 which is dependent on cursor #1 so dep = 1 PARSING IN CURSOR #2 len=68 dep=1 uid=98 oct=3 lid=98 tim=1617285503241 hv=1778717541 ad='606795e8' -- sql test SELECT PARENT_NAV_NODE_ID FROM NAV_NODE WHERE NAV_NODE_ID = :b1 END OF STMT -- Successful parsing of cursor #2 PARSE #2:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1617285503230 -- Executing 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 cursor #2 FETCH #2:c=0,e=40,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1617285503648 -- Data returned to anon block WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 -- Now the anon block executes. the e time includes the time for all actions of cursor #2 EXEC #1:c=0,e=1037,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1617285503786 WAIT #1: nam='SQL*Net message from client' ela= 2470 p1=1413697536 p2=1 p3=0 Now, I'll just wait for Cary to come along and tell me that I got it all wrong ... Happy Thanksgiving (or Turky Day) Raj Rajendra dot Jamadagni at nospamespn dot com All Views expressed in this email are strictly personal. QOTD: Any clod can have facts, having an opinion is an art ! ** This e-mail message is confidential, intended only for the named recipient(s) above and may contain information that is privileged, attorney work product or exempt from disclosure under applicable law. If you have received this message in error, or are not the named recipient(s), please immediately notify corporate MIS at (860) 766-2000 and delete this e-mail message from your computer, Thank you. **4 -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Jamadagni, Rajendra 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).
Re: sql trace - recursive relationships
But the previous email was a shining example of brevity in action! ;) I'll have to wait for Cary, et.al. as well as my understanding is the exact same as yours. Daniel Jamadagni, Rajendra wrote: Sorry about the last empty email ... Cary is right, the EXEC at dep=0 is the database call you should be looking for, why? because until #1 is parsed, db has no way of finding what needs to do. And once it finds that Oh I must run a SQL, the dep increases. So, I'd look for a subsequent EXEC instead of PARSE line. I'll take a stab at this ... lines with -- are mine = PARSING IN CURSOR #1 len=94 dep=0 uid=83 oct=47 lid=83 tim=1617285502494 hv=1138148843 ad='605d0998' -- Anonymous block BEGIN nav_tree_pkg.get_nav_parent_node_id( :p_nodeid, :p_parentnodeid ); END; END OF STMT -- anon block gets parsed, it probably contains a sql. PARSE #1:c=0,e=141,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1617285502483 -- Found the sql, so oracle opened another cursor #1 which is dependent on cursor #1 so dep = 1 PARSING IN CURSOR #2 len=68 dep=1 uid=98 oct=3 lid=98 tim=1617285503241 hv=1778717541 ad='606795e8' -- sql test SELECT PARENT_NAV_NODE_ID FROM NAV_NODE WHERE NAV_NODE_ID = :b1 END OF STMT -- Successful parsing of cursor #2 PARSE #2:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1617285503230 -- Executing 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 cursor #2 FETCH #2:c=0,e=40,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1617285503648 -- Data returned to anon block WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 -- Now the anon block executes. the e time includes the time for all actions of cursor #2 EXEC #1:c=0,e=1037,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1617285503786 WAIT #1: nam='SQL*Net message from client' ela= 2470 p1=1413697536 p2=1 p3=0 Now, I'll just wait for Cary to come along and tell me that I got it all wrong ... Happy Thanksgiving (or Turky Day) Raj Rajendra dot Jamadagni at nospamespn dot com All Views expressed in this email are strictly personal. QOTD: Any clod can have facts, having an opinion is an art ! ** This e-mail message is confidential, intended only for the named recipient(s) above and may contain information that is privileged, attorney work product or exempt from disclosure under applicable law. If you have received this message in error, or are not the named recipient(s), please immediately notify corporate MIS at (860) 766-2000 and delete this e-mail message from your computer, Thank you. **4 -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Jamadagni, Rajendra 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). -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Daniel Fink 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).
RE: sql trace - recursive relationships
Thanks, Raj. So yes, as I said in my other email - the rule stated in the book seem to apply to EXEC db calls only (in case of SQL fired from PL/SQL). I guess I misinterpreted it the way that it applies to ALL db calls for recursive cursors. Thanks, Boris Dali. --- Jamadagni, Rajendra [EMAIL PROTECTED] wrote: Sorry about the last empty email ... Cary is right, the EXEC at dep=0 is the database call you should be looking for, why? because until #1 is parsed, db has no way of finding what needs to do. And once it finds that Oh I must run a SQL, the dep increases. So, I'd look for a subsequent EXEC instead of PARSE line. I'll take a stab at this ... lines with -- are mine = PARSING IN CURSOR #1 len=94 dep=0 uid=83 oct=47 lid=83 tim=1617285502494 hv=1138148843 ad='605d0998' -- Anonymous block BEGIN nav_tree_pkg.get_nav_parent_node_id( :p_nodeid, :p_parentnodeid ); END; END OF STMT -- anon block gets parsed, it probably contains a sql. PARSE #1:c=0,e=141,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1617285502483 -- Found the sql, so oracle opened another cursor #1 which is dependent on cursor #1 so dep = 1 PARSING IN CURSOR #2 len=68 dep=1 uid=98 oct=3 lid=98 tim=1617285503241 hv=1778717541 ad='606795e8' -- sql test SELECT PARENT_NAV_NODE_ID FROM NAV_NODE WHERE NAV_NODE_ID = :b1 END OF STMT -- Successful parsing of cursor #2 PARSE #2:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1617285503230 -- Executing 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 cursor #2 FETCH #2:c=0,e=40,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=1617285503648 -- Data returned to anon block WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 -- Now the anon block executes. the e time includes the time for all actions of cursor #2 EXEC #1:c=0,e=1037,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim=1617285503786 WAIT #1: nam='SQL*Net message from client' ela= 2470 p1=1413697536 p2=1 p3=0 Now, I'll just wait for Cary to come along and tell me that I got it all wrong ... Happy Thanksgiving (or Turky Day) Raj __ 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).
Re: sql trace - recursive relationships
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=83fbc005ff80 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=83fbc005ff98 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=4001 size=24 offset=0 bfp=83fbc005f660 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). -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Daniel Fink 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).
Re: sql trace - recursive relationships
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=83fbc005ff80 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=83fbc005ff98 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=4001 size=24 offset=0 bfp=83fbc005f660 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).
