X

Insights into Statistics, Query Optimization and the Oracle Optimizer

How do I capture a 10053 trace for a SQL statement called in a PL/SQL package?

Maria Colgan
Master Product Manager

Traditionally if you wanted to capture an Optimizer trace (10053) for a SQL statement you would issue an alter session command to switch on a 10053 trace for that entire session, and then issue the SQL statement you wanted to capture the trace for. Once the statement completed you would exit the session to disable the trace. You would then look in the USER_DUMP_DEST directory for the trace file.



But what if the SQL statement you were interested  in was actually called as part of a PL/SQL package? Oracle Database 11g, introduced a new diagnostic events infrastructure, which greatly simplifies the task of generating a 10053 trace for a specific SQL statement in a PL/SQL package. All you will need to know is the SQL_ID for the statement you are interested in. Instead of turning on the trace event for the entire session you can now switch it on for a specific SQL ID. Oracle will then capture a 10053 trace for the corresponding SQL statement when it is issued in that session. Remember the SQL statement still has to be hard parsed for the 10053 trace to be generated.  Let's begin our example by creating a PL/SQL package called 'cal_total_sales'.



The SQL statement we are interested in is the same as the one in our original example, SELECT SUM(AMOUNT_SOLD) FROM SALES WHERE CUST_ID = :B1. We need to know the SQL_ID of this SQL statement to set up the trace, and we can find in V$SQL.



We now have everything we need to generate the trace.



Finally  you would look in the USER_DUMP_DEST directory for the trace file with the name you specified.


Maria Colgan+

Join the discussion

Comments ( 23 )
  • guest Wednesday, November 16, 2011

    Interresting feature, but the point would be to find the sql_id of a sql which was not hard parsed. In your example how could you find the sql_id in v$sql if the query was not hard parsed ?


  • Maria Colgan Wednesday, November 16, 2011

    Eric, assuming the statement was parsed at some point in the past you could find the SQL_ID in the AWR repository.


  • jimmyb Wednesday, November 16, 2011

    In practice, we should call a script which contains all of those commands. Starting a trace session, executing a package, ending a trace session.

    Otherwise, the time between typing out those three commands will be included in the trace. Giving you inaccurate TIM values in your trace file.


  • Maria Colgan Wednesday, November 16, 2011

    I agree with Jimmy. It is far wiser to create a script to run these commands, especially if you misspell things as often as I do! : )


  • Wolfgang Breitling Thursday, November 17, 2011

    Great post as usual. I have only one question: where is the "new diagnostic events infrastructure" documented, i.e. all the various option of the events 'trace... ' command?

    Of course, by this question I reveal that I haven't read (all) the documentation.


  • Maria Colgan Thursday, November 17, 2011

    Wolfgang, that is a really good question. I found out about the new event infrastructure from one of the developers. I just searched the Oracle doc and there are references to aspects of it in the Performance and Tuning Guide as well as in the Reference Guide. But I can't find a section that clearly discusses the new tracing in detail. However, I suspect support have create a MOS note on this and will try and look for it later today and update the blog with it!


  • dba Thursday, November 17, 2011

    2 questions:

    1) Can I set this at the SYSTEM level? That way any session that does hard parsing for a particular sql_id will generate a 10053 trace. I don't have to run the pl/sql in my own session.

    2) How can I do similar thing for a 10046 trace for a specific sql_id?


  • Maria Colgan Thursday, November 17, 2011

    Yes you can set it at a system level and have it capture the trace for the SQL_ID in any session.


  • dba Friday, November 18, 2011

    If I set it at the system level, then how do I unset it after a while?


  • Maria Colgan Friday, November 18, 2011

    Prashant, you can unset it at the system level using,

    alter system set events 'trace [SQL_Optimizer.*] off';


  • jianhui Friday, November 18, 2011

    Hi Maria,

    Great presentation in NCOUG last week.

    I was trying to find some clue about how CBO breaks tie when there are two index range scan have the same cost in a 10053 trace file? I have heard object_id, or simply the order of possible plans that CBO evaluates, but I have no solid resource to confirm that.

    For instance, from the trace file I cound not figure out the reason why foo_IX1 was picked over foo_UX. It seems both have cost 12.30 (I masked the real index names for privacy as this is from work)

    Thank you!

    Jianhui

    Access Path: index (AllEqGuess)

    Index: foo_IX1

    resc_io: 41.00 resc_cpu: 0

    ix_sel: 0.000016 ix_sel_with_filters: 0.000016

    Cost: 12.30 Resp: 12.30 Degree: 1

    Access Path: index (RangeScan)

    Index: foo_UX

    resc_io: 41.00 resc_cpu: 0

    ix_sel: 0.000000 ix_sel_with_filters: 0.000000

    Cost: 12.30 Resp: 12.30 Degree: 1

    Best:: AccessPath: IndexRange

    Index: foo_IX1

    Cost: 13.00 Degree: 1 Resp: 12.30 Card: 1.57 Bytes:


  • Maria Colgan Friday, November 18, 2011

    Hi Jianhui,

    The Optimizer selected foo_IX1 because the cost was slightly lower than that of foo_UX. Cost for foo_IX1 was 'Cost:12.30' while the cost for foo_UX was actually 'Cost:13.00'.

    But if it had been a true tie then the Optimizer actually begins by picking the index which has the highest number of columns matched with the query predicates. For example, if you have predicates on columns A and B only then we pick the index on (A,B) rather than the index on A,B,C. If there is still a tie, for example the available

    indexes are A,B,C and A,B,D then we favor the index with the highest number of distinct keys (combination of A,B values) and lowest number of leaf blocks.


  • Jianhui Friday, November 18, 2011

    Maria,

    Thank you for the comment on how CBO breaks the tie, is there any further official doc or MOS article# discussing about tie breaking rules? (I was hoping 10053 trace file directly dump out the rule it uses)

    Secondly, I read the trace file differently than what you said, it says foo_UX cost was 12.30, not 13.00. Did i interpret it incorrectly? You can see 12.30 value appears twice in the trace file copy I pasted here.

    But I did get answers about why IX1 was picket if the tie situation is the case, IX1 does have higher matching columns in WHERE clause.

    Thanks,

    Jianhui


  • Martin Berger Saturday, November 19, 2011

    Wolfgang, Maria,

    if you search for the full syntax of this great new feature, just ask Tanel Poder:

    http://blog.tanelpoder.com/2010/06/23/the-full-power-of-oracles-diagnostic-events-part-2-oradebug-doc-and-11g-improvements/

    or ORADEBUG DOC

    happy tracing,

    Martin


  • Lewis Cunningham Monday, November 21, 2011

    Hi Maria.

    I was wondering if anyone with alter session can do this for any SQLID or is it tied to security at all?

    A lot of times I may be logged in with a non-DBA account and want to see the trace for a session running under a different ID.

    I think I'll have to go play with this.

    Thanks,

    LewisC


  • Maria Colgan Monday, November 21, 2011

    Hi Lewis,

    You need the DBA privilege to issue the Alter Session command. Without it you get the following error,

    SQL> alter system set events 'trace[rdbms.SQL_Optimizer.*][sql:a8phhr6w1an53]';

    alter system set events 'trace[rdbms.SQL_Optimizer.*][sql:a8phhr6w1an53]'

    *

    ERROR at line 1:

    ORA-01031: insufficient privileges

    Thanks,

    Maria


  • Kevin Friday, November 25, 2011
  • zebonsoft Friday, November 25, 2011

    An alternativeis to use API dbms_sqldiag.dump_trace


  • harsha Wednesday, November 30, 2011

    Maria,

    Could you please explain where in the below syntax that we are referring that the trace be a 10053 or a 10046 trace event?

    alter session set events 'trace[rdbms.SQL_Optimizer.*][sql:sql_id]';

    Thanks

    Harsha


  • guest Wednesday, July 11, 2012

    Thanks for this Maria.

    When using a statement such as this one:

    alter system set events 'sql_trace[SQL:aua4zfxn0953q] plan_stat=all_executions,wait=true,bind=true';

    ... I found that the trace could not be disabled with this:

    alter system set events 'trace[rdbms.SQL_Execution.*] off';

    Rather, an explicit command for the SQL_ID was required:

    alter system set events 'sql_trace[SQL:aua4zfxn0953q] plan_stat=all_executions,wait=true,bind=true';

    Also, in this case (sql_id tracing) when the trace is enabled, all subsequent SQL statements for the session are traced as well.


  • Jared Wednesday, July 11, 2012

    I had not intended the previous comment to be anonymous, guess I forgot to fill in my name.


  • guest Friday, December 28, 2012

    Hi Maria, Just to note an anomaly I found using the dump_trace.

    There is a bug/feature in 11.2.0.2 using mat views. see note 1326110.1 where a piece of SQL works fine but hangs when using it to create a materialized view.

    why is that relevant here? well read on...

    Run explain on a piece of SQL that will satisfy that bug and you get a plan, lets call it GOOD_PLAN.

    wrap a "create materialized view as <SQL select statement>" and according to the above note the query will hang which it did for me. However, during my troubleshooting I also found the plan had changed during run time to BAD_PLAN by querying v$sql_plan for the sql_id.

    In trying to see why the plan had changed, I ran the DBMS_SQLDIAG.DUMP_TRACE against the sql_id but the resulting trace showed GOOD_PLAN as it only reparsed the SQL itself. It didnt regenerate the BAD_PLAN as there wasnt a "create mat. view" in the reparse.

    Yes this is related to a bug and it shouldn't happen in a normal working day but the behavior should be noted in case any bug/feature causes a run time change of a plan. ie. Believe your eyes and contact support. Hopefully this will save someone some time in future.


  • guest Thursday, March 21, 2013

    Hi Maria,

    Thank you for all these information you share with us. Under what specific circumstances do you believe that your function GET_TOTAL_SALES could raise either NO_DATA_FOUND or TOO_MANY ROWS exception?

    Thanks,

    Marius NITU


Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.Captcha