Understanding SQL Trace and TKPROF

posted Sep 15, 2010, 6:48 AM by Sachchida Ojha

The SQL Trace facility provides performance information on individual SQL statements. It 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
  • Username under which each parse occurred
  • Each commit and rollback
  • Wait event data for each SQL statement, and a summary for each trace file

If the cursor for the SQL statement is closed, SQL Trace also provides row source information that includes:

  • Row operations showing the actual execution plan of each SQL statement
  • Number of rows, number of consistent reads, number of physical reads, number of physical writes, and time elapsed for each operation on a row

You can enable the SQL Trace facility for a session or for an instance. When the SQL Trace facility is enabled, performance statistics for all SQL statements executed in a user session or in the instance are placed into trace files. The additional overhead of running the SQL Trace facility against an application with performance problems is normally insignificant compared with the inherent overhead caused by the application's inefficiency.

Understanding TKPROF

You can run the TKPROF program to format the contents of the trace file and place the output into a readable output file. TKPROF can also:

  • Create a SQL script that stores the statistics in the database
  • Determine the execution plans of SQL statements
If the cursor for a SQL statement is not closed, TKPROF output does not automatically include the actual execution plan of the SQL statement. In this situation, you can use the EXPLAIN option with TKPROF to generate an execution plan.

Using the SQL Trace Facility and TKPROF


Follow these steps to use the SQL Trace facility and TKPROF:

   1. Set initialization parameters for trace file management.
   2. Enable the SQL Trace facility for the desired session, and run the application. This step produces a trace file containing statistics for the SQL statements issued by the application.
   3. Run TKPROF to translate the trace file created in Step 2 into a readable output file. This step can optionally create a SQL script that can be used to store the statistics in a database.
   4. Interpret the output file created in Step 3.
   5. Optionally, run the SQL script produced in Step 3 to store the statistics in the database.

When the SQL Trace facility is enabled for a session, Oracle generates a trace file containing statistics for traced SQL statements for that session. When the SQL Trace facility is enabled for an instance, Oracle creates a separate trace file for each process. Before enabling the SQL Trace facility:

Check the settings of the TIMED_STATISTICS, MAX_DUMP_FILE_SIZE, and USER_DUMP_DEST initialization parameters.

TIMED_STATISTICS

This enables and disables the collection of timed statistics, such as CPU and elapsed times, by the SQL Trace facility, as well as the collection of various statistics in the dynamic performance tables. The default value of false disables timing. A value of true enables timing. Enabling timing causes extra timing calls for low-level operations. This is a dynamic parameter. It is also a session parameter.

MAX_DUMP_FILE_SIZE

When the SQL Trace facility is enabled at the instance level, every call to the server produces a text line in a file in the operating system's file format. The maximum size of these files (in operating system blocks) is limited by this initialization parameter. The default is 500. If you find that the trace output is truncated, then increase the value of this parameter before generating another trace file. This is a dynamic parameter. It is also a session parameter.

USER_DUMP_DEST

This must fully specify the destination for the trace file according to the conventions of the operating system. The default value is the default destination for system dumps on the operating system.This value can be modified with ALTER SYSTEM SET USER_DUMP_DEST= newdir. This is a dynamic parameter. It is also a session parameter.



Devise a way of recognizing the resulting trace file.

Be sure you know how to distinguish the trace files by name. Oracle writes them to the user dump destination specified by USER_DUMP_DEST. However, this directory can soon contain many hundreds of files, usually with generated names. It might be difficult to match trace files back to the session or process that created them. You can tag trace files by including in your programs a statement like SELECT 'program_name' FROM DUAL. You can then trace each file back to the process that created it.

You can also set the TRACEFILE_IDENTIFIER initialization parameter to specify a custom identifier that becomes part of the trace file name. For example, you can add my_trace_id to subsequent trace file names for easy identification with the following:

ALTER SESSION SET TRACEFILE_IDENTIFIER = 'my_trace_id';

If the operating system retains multiple versions of files, then be sure that the version limit is high enough to accommodate the number of trace files you expect the SQL Trace facility to generate.

The generated trace files can be owned by an operating system user other than yourself. This user must make the trace files available to you before you can use TKPROF to format them.

Enabling the SQL Trace Facility

Enable the SQL Trace facility for the session by using one of the following:

    * DBMS_SESSION.SET_SQL_TRACE procedure
    * ALTER SESSION SET SQL_TRACE = TRUE;
   
Because running the SQL Trace facility increases system overhead, enable it only when tuning SQL statements, and disable it when you are finished.
You might need to modify an application to contain the ALTER SESSION statement. For example, to issue the ALTER SESSION statement in Oracle Forms, invoke Oracle Forms using the -s option, or invoke Oracle Forms (Design) using the statistics option.

To disable the SQL Trace facility for the session, enter:

ALTER SESSION SET SQL_TRACE = FALSE;

The SQL Trace facility is automatically disabled for the session when the application disconnects from Oracle.

You can enable the SQL Trace facility for an instance by setting the value of the SQL_TRACE initialization parameter to TRUE in the initialization file.

SQL_TRACE = TRUE

After the instance has been restarted with the updated initialization parameter file, SQL Trace is enabled for the instance and statistics are collected for all sessions. If the SQL Trace facility has been enabled for the instance, you can disable it for the instance by setting the value of the SQL_TRACE parameter to FALSE.

Formatting Trace Files with TKPROF

TKPROF accepts as input a trace file produced by the SQL Trace facility, and it produces a formatted output file. TKPROF can also be used to generate execution plans.

After the SQL Trace facility has generated a number of trace files, you can:

    * Run TKPROF on each individual trace file, producing a number of formatted output files, one for each session.
    * Concatenate the trace files, and then run TKPROF on the result to produce a formatted output file for the entire instance.
    * Run the trcsess command-line utility to consolidate tracing information from several trace files, then run TKPROF on the result. See "Using the trcsess Utility".

TKPROF does not report COMMITs and ROLLBACKs that are recorded in the trace file.
Sample TKPROF Output

Sample output from TKPROF is as follows:

SELECT * FROM emp, dept
WHERE emp.deptno = dept.deptno;

call   count      cpu    elapsed     disk    query current    rows
---- -------  -------  --------- -------- -------- -------  ------
Parse      1     0.16      0.29         3       13       0       0
Execute    1     0.00      0.00         0        0       0       0
Fetch      1     0.03      0.26         2        2       4      14
 
Misses in library cache during parse: 1
Parsing user id: (8) SCOTT

Rows     Execution Plan
-------  ---------------------------------------------------

14  MERGE JOIN
 4   SORT JOIN
 4     TABLE ACCESS (FULL) OF 'DEPT'
14    SORT JOIN
14      TABLE ACCESS (FULL) OF 'EMP'

For this statement, TKPROF output includes the following information:

    * The text of the SQL statement
    * The SQL Trace statistics in tabular form
    * The number of library cache misses for the parsing and execution of the statement.
    * The user initially parsing the statement.
    * The execution plan generated by EXPLAIN PLAN.

TKPROF also provides a summary of user level statements and recursive SQL calls for the trace file.
Syntax of TKPROF

TKPROF is run from the operating system prompt. The syntax is:

tkprof filename1 filename2 [waits=yes|no] [sort=option] [print=n]
    [aggregate=yes|no] [insert=filename3] [sys=yes|no] [table=schema.table]
    [explain=user/password] [record=filename4] [width=n]
                       
                   


Comments