Trace Files

Trace files are stored in the Automatic Diagnostic Repository (ADR), in the trace directory under each ADR home. To help you locate individual trace files within this directory, you can use data dictionary views. For example, you can find the path to your current session's trace file or to the trace file for each Oracle Database process.

To find the trace file for your current session:

• Submit the following query:

  SELECT VALUE FROM V$DIAG_INFO WHERE NAME = 'Default Trace File';
  

  The full path to the trace file is returned.

To find all trace files for the current instance:

• Submit the following query:

  SELECT VALUE FROM V$DIAG_INFO WHERE NAME = 'Diag Trace';
  

  The path to the ADR trace directory for the current instance is returned.

To determine the trace file for each Oracle Database process:

• Submit the following query:

  SELECT PID, PROGRAM, TRACEFILE FROM V$PROCESS;

  
  In oracle10g, we find trace files under below directory->
  
  
  
  
  /oracle/<SID>/saptrace/usertrace
  
  
  
  
  but in oracle11g
  
  
  
  
  /oracle/<SID>/saptrace/diag/rdbms/qas/<SID>/trace. Although usertrace folder is present in oracle11g-> /oracle/<SID>/saptrace/usertrace..
  
  
  
  
  
   TRACE Utility
  
  The Oracle TRACE utility is used to measure timing statistics for a given query, a batch process, or an entire system. It is a fast method of finding where potential bottlenecks on the system reside. TRACE has the following functionality:
  
  TRACE runs the query and generates statistics about an Oracle query that is executed.
  TRACE helps developers analyze every section of a query.
  
  
  Simple Steps for TRACE with a Simple Query
  
  The steps for setting up and running Oracle's TRACE utility are as follows:
  
  Set the following init.ora parameters:
    TIMED.STATISTICS = TRUE
    MAX_DUMP_FILE_SIZE = 2000000 (Not 2M)
    USER_DUMP_DEST = /oracle8/rich_trc
    
  In Oracle7, the database must be shut down and restarted for these parameters to take effect. In Oracle8, the TIMED_STATISTICS parameter may be set via an ALTER SESSION (for an individual session) or ALTER SYSTEM (for the entire system) command. The USER_DUMP_DEST specifies the location to put the files and the MAX_DUMP_FILE_SIZE specifies the maximum file size.
  
  
  Enable TRACE for a SQL*Plus session (this starts TRACing for an individual session):
    alter session set SQL_TRACE true;
    
  
  Run the query to be TRACEd:
    select    table_name,
              owner, 
              initial_extent,
              uniqueness
    from	    ind2
    where	    owner || '' = 'SCOTT';
    --    (Note: An index on "OWNER" is suppressed)
    
  
  Disable TRACE for the SQL*Plus session:
    alter session set SQL_TRACE false;
    
  
  You can also enable TRACE for all sessions by setting the SQLTRACE parameter in the init.ora. You must shut down and restart the database for this to take effect. This is not suggested!
    SQL_TRACE = TRUE
    
  After running TRACE, your output file will look something like the following:
    5_19554.trc
    
  TIP Setting TIMED_STATISTICS=TRUE in the init.ora will begin TRACing upon the user's command. But, be careful; setting SQLTRACE=TRUE in the init.ora will cause the entire system and all queries to be TRACEd and could cause performance degradations.
  
  
  Run TKPROF to put the TRACE file into readable format:
    tkprof 5_19554.trc rich2.prf explain=system/manager
    
  The TKPROF utility translates the TRACE file generated by the SQLTRACE facility to a readable format. You can run TKPROF against a TRACE file that you have previously created, or you can run it while the program that is creating the TRACE file is still running. Options for TKPROF are listed next.
    tkprof tracefile output_file [sort = parameters]
    [print =number] [explain=username/password@sid]
    
  Command-Line Options:
  
  TRACEfile
  The name of the TRACE file containing the statistics by SQL_TRACE.
  output_file
  The name of the file where TKPROF writes its output.
  SORT= parameters
  The order in which to display the statements in the output. There are about 20 different options for sorting the output-you can even combine these options.
  PRINT=number
  The number of statements to include in the output. included, TKPROF will list all statements in the output.
  EXPLAIN=username/password@sid
  Run the EXPLAIN PLAN on the user's SQL statements in the TRACE file. This option will create a PLAN_TABLE of its own, so the user will need to have privileges to create the table and space in which to create it. When TKPROF is finished, this	table is dropped.
  
  New options in 7.3+:
  INSERT= filename
  This option creates a script to create a table and store the TRACE file statistics for each SQL statement TRACEd.
  RECORD= filename
  This option will produce a file of all the user's SQL statements.
  SYS= YES/NO
  This option allows the user to request the recursive SQL statements not be displayed in the output. The default is set to YES.
  SORT= parameters
  There is a tremendous number of sorting options that are available. My favorites are FCHCPU (CPU time of fetch), FCHDSK (disk reads for fetch), FCHCU and FCHQRY (memory reads for fetch), FCH ROW (number of rows fetched), EXEDSK (disk reads during execute), EXECU and EXEQRY (memory reads during execute), EXEROW (rows processed during execute), EXECPU (execute CPU time), and PRSCNT (times parsed).
  TIP
  
  The TKPROF utility puts a TRACEd output into a readable format. Without running TKPROF, it would be difficult to read the output of a TRACE. By specifying "explain=username/password" (noted earlier), we are able to get the EXPLAIN PLAN execution path in addition to the execution statistics of the query.
  
  
  The output of the file rich2.prf (query with the index suppressed):
    select    table_name,
              owner,
              initial_extent,
              uniqueness
    from      ind2
    where     owner = 'SCOTT';
  
  	count	cpu	elap	disk	query	current	  rows
  
  Parse:	    1     1        2       0        0         0
  Execute:    1     0        0       0        0         2      0
  Fetch:	    2    69      113     142      430         0     36
    
  Execution Plan (no index used):
  TABLE ACCESS (FULL) OF 'IND2'
    
  The output shows 142 disk reads and 430 memory reads (query + current). Having such a high number of disk reads compared to physical reads is certainly a potential problem. The execution path shows a full table scan confirming that we may have a potential problem.TIP A TRACEd query with a large number of physical reads usually indicates a missing index. The disk column indicates the physical reads (usually where an index is not used) and the query added to the current columns indicates the memory reads (usually reads where an index is being used).
  
  
  
  Here's what happens when I rerun the query (after restarting the system) to be TRACEd, now using an index on the owner table:
    select    table_name,
              owner,
              initial_extent,
              uniqueness
    from      ind2
    where     owner = 'SCOTT';
    (The index on "OWNER" is not suppressed)
  
  	count	cpu	elap	disk	query	current	  rows
  
  Parse:	    2     0        0       0        0         0
  Execute:    2     0        0       0        0         0      0
  Fetch:	    4     6        6       0      148         0     72 
    
  Execution Plan (index used):
  TABLE ACCESS (BY ROWID) OF 'IND2'
    INDEX (RANGE SCAN) OF 'IND2_1' (NON-UNIQUE)
    
  TIPA TRACEd query output with only memory reads (query-consistent reads) indicates that an index is being used.
  
  
  The Sections of a TRACE Output
  
  The TRACE utility has multiple sections including the SQL statements, statistics, information, and the EXPLAIN PLAN. Each of these different topics are discussed in the following sections.
  
  The SQL Statement
  
  The first section of a TKPROF statement is the SQL statement. This statement will be the exact same as the statement that was executed. If there were any hints or comments in the statement, they would be retained in this output. This can be helpful when you are reviewing the output from multiple sessions. If you find a statement causing problems, you would be able to search for the exact statement. Remember, some of the statements from Oracle forms are generated	 dynamically.
  
  The Statistics Section
  
  This section contains all the statistics for this SQL statement and all the recursive SQL statements generated to satisfy this statement. In this section there are eight columns, the first being the type of call to the database. There are three types of calls, parse, execute, and fetch. Each type of call will generate a separate line of statistics. The other seven columns are the statistics for each type of call.
  
  count
  The number of times this type of call was made.
  cpu
  The total CPU time for all of the calls of this type for this statement. If the TIMED_STATISTICS parameter in the init.ora is not set to TRUE, this statistic and the elapsed statistic will be 0.
  elapsed
  The total elapsed time for this call.
  disk
  The total number of data blocks retrieved from disk to satisfy this call.
  query
  The total number of data buffers retrieved from memory for this type SELECT statements usually retrieve buffers in this mode.
  current
  The total number of data buffers retrieved from memory for this type of call. UPDATE, INSERT, or DELETE the usual access buffers in this mode.
  rows
  The total number of rows processed by this statement. The rows statements will appear in the row of Fetch statistics. INSERTS, UPDATES, and DELETES will appear in the execute row.