Please see my other blog for Oracle EBusiness Suite Posts - EBMentors

Search This Blog

Note: All the posts are based on practical approach avoiding lengthy theory. All have been tested on some development servers. Please don’t test any post on production servers until you are sure.

Tuesday, September 27, 2011

How To Collect 10046 Trace (SQL_TRACE) Diagnostics for Performance Issues

Event 10046 is the standard method of gathering extended sql_trace information for Oracle sessions.
This is a special EVENT code. It can be used to signal Oracle to perform SQL_TRACE type 
actions. The 10046 trace is the equivalent of setting SQL_TRACE=TRUE.The advantage of using 
the event is that extra details may be output to the trace file depending on the level
specified with the event. 
For Query Performance issues the typical requirement is to record wait and bind variable information for queries. This is achieved using 10046 with level 12.

'sql trace' generates the following statistics for each statement:

        *       parse, execute, and fetch counts 
        *       CPU and elapsed times 
        *       physical reads and logical reads 
        *       number of rows processed 
        *       misses on the library cache 

This information is input to a trace (.trc) file and sql trace can be
enabled/disabled for a session or an instance.

10046 EVENT levels:
        1  - Enable standard SQL_TRACE functionality (Default)
        4  - As Level 1 PLUS trace bind values
        8  - As Level 1 PLUS trace waits
             This is especially useful for spotting latch wait etc. 
             but can also be used to spot full table scans and index scans.
        12 - As Level 1 PLUS both trace bind values and waits
        16 - Added in 11g to generate STAT line dumps for each execution
 Trace Location
11g R1 and above:

With the introduction of the new diagnosability infrastructure introduced in Oracle Database 11g Release 1, traces and core files are placed in a location controlled by the DIAGNOSTIC_DEST initialization parameter.
To show the location of the DIAGNOSTIC_DEST, the following command can be used:
  SQL> show parameter diagnostic_dest
Pre 11g R1:

Event 10046 tracing will produce a trace file in the <> for user processes and <> for background processes.
To show the location of the user_dump_dest, the following command can be used:
  SQL> show parameter user_dump_dest

Note: Some examples include setting a 'tracefile_identifier' to assist with finding the resultant trace output.

Session Tracing

This tracing can be used where the session is accessible to the user prior to the start of the statement(s) to be traced.
To gather 10046 trace at the session level:
alter session set tracefile_identifier='10046'; alter session set timed_statistics = true; alter session set statistics_level=all; alter session set max_dump_file_size = unlimited; alter session set events '10046 trace name context forever,level 12'; -- Execute the queries or operations to be traced here -- select * from dual; exit;
if the session is not exited then the trace can be disabled using:
alter session set events '10046 trace name context off';
Note that if the session is not closed cleanly and tracing is disabled, then important trace information may be missing from the trace file. 
Instance wide tracing
  • Note: Please be cautious when setting system wide, as this will impact performance due to every session being traced.
    This setting will trace every session that is created after the parameter is set. Existing sessions will not be traced. Setting system-wide 10046 tracing can be useful for scenarios where a problem session is known to occur but cannot be identified in advance. In this situation, tracing can be enabled for a short period of time, the problem can then be reproduced and tracing disabled and the resultant traces searched for evidence of the problem. System-wide tracing can be enabled as follows:
    alter system set events '10046 trace name context forever,level 12';
    The setting can be disabled in all sessions by using the following command:
    alter system set events '10046 trace name context off';
  • Initialisation parameter setting This setting will trace every session in the instance when it is restarted.
    event="10046 trace name context forever,level 12"
    The setting can be disabled by removing the parameter and restarting the instance or by using an alter system command as follows:
    alter system set events '10046 trace name context off';
    EXAMPLES: ~~~~~~~~~ Wait Information: nam is what is being waited for ela is the elapsed time for the operation In Oracle7 / 8 this is in units of hundredths of a second In Oracle9i onwards this is in microseconds p1 is the file number p2 is the block number p3 is the number of blocks read by the operation Waiting for a Full Table Scan: WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25 WAIT #1: nam="db file scattered read" ela= 7 p1=4 p2=1461 p3=32 WAIT #1: nam="db file scattered read" ela= 7 p1=4 p2=1493 p3=32 The first wait indicates a mutliblock read was issued for 25 blocks starting at file 4 block 1435. This took 5/100th of a second. The next 2 lines also show multiblock reads of 32 blocks Waiting for an Index Scan: WAIT #1: nam="db file sequential read" ela= 4 p1=4 p2=1224 p3=1 WAIT #1: nam="db file sequential read" ela= 4 p1=4 p2=1788 p3=1 This is the sort of output you would see on an index scan or an individual block access to table block.

No comments: