14.5 How do I…Analyze SQL statements with SQL*Trace and the TKPROF utility? Problem

I want to use SQL*Trace to analyze the execution plan of SQL statements within my application. Because SQL*Trace can analyze all SQL statements executed by an application or by the entire instance, I can use it to analyze the entire application as it runs. How do I use SQL*Trace and TKPROF to analyze queries?

Technique

SQL*Trace writes a file containing performance statistics. The volume of SQL*Trace output can be huge and the utility can adversely affect database performance so DBAs and developers should use it with care. There are four initialization parameters you can set to control SQL*Trace’s behavior; they appear in Table 14.6.

Table 14.6 Initialization parameters that control SQL*Trace

Parameter Setting Description
MAX_DUMP_SIZE Integer value Specifies the largest physical size that a trace file can become
SQL_TRACE TRUE When set to TRUE, SQL*Trace is enabled for all database users. FALSE is the default. If TRUE, SQL*Trace is executed for ALL SQL statements on the database
TIMED_STATISITICS TRUE When set to TRUE, the database collects additional timing statistics that are important to SQL*Trace
USER_DUMP_DEST Directory spec. Specifies the location where the SQL*Trace will write the trace files.

When the SQL_TRACE database parameter is TRUE, overall response time can degrade noticeably because a trace file is created for every statement executed. The trace files quickly become too large to use, so a more reasonable strategy is to enable SQL*Trace for individual sessions by issuing the ALTER SESSION SET SQL_TRACE=TRUE statement.

Within PL/SQL, the DBMS_SESSION.SET_SQL_TRACE procedure performs the same action and DBAs can also use this procedure to enable SQL*Trace for another user’s session. The default format of the generated trace file is not legible, so the TKPROF utility reformats trace files to a more readable form. TKPROF runs from the operating system command line and the syntax of the statement is shown below. Table 14.7 summarizes the arguments TKPROF accepts. Table 14.8 lists valid values for the SORT parameter in the TKPROF command line.

TKPROF tracefile outputfile [SORT = parameters] [PRINT = number]

[INSERT = script filename] [SYS = yes/no] [TABLE = schema.tablename] \

[EXPLAIN = username/password] [RECORD = sql filename]

Table 14.7 Arguments to the TKPROF utility

Argument Description
TRACEFILE Name of input file produced by SQL*Trace
OUTPUTFILE Name of output file produced by TKPROF
SORT TKPROF presents output in order of parameters when this is specified (see Table 14.6).
PRINT TKPROF only includes the number of SQL statements in its output file
INSERT Creates a SQL script file named script filename to store trace statistics in a database table
SYS If YES, the default, TKPROF includes recursive SQL calls from user SYS. If NO, TKPROF ignores recursive SQL
TABLE Specifies which schema and tablename for TKPROF to explain plan output
EXPLAIN TKPROF includes execution path information if the username and password of a database account is specified here
RECORD TKPROF writes all analyzed statements to sql filename if this parameter is specified

Table 14.8 TKPROF sort parameters

Parameter Description
EXECNT Number of executes.
EXECPU CPU time spent executing.
EXEELA Elapsed time spent executing.
EXEDSK Number of physical reads during execute.
EXEQRY Number of consistent reads during execute.
EXECU Number of current reads during execute.
EXEROW Number of rows processed during execute.
EXEMIS Number of library cache misses during execute.
FCHCNT Number of fetches.
FCHCPU CPU time spent fetching.
FCHELA Elapsed time spent fetching.
FCHDSK Number of physical reads during fetch.
FCHQRY Number of consistent reads during fetch.
FCHCU Number of current reads during fetch.
FCHROW Number of rows fetched.
PRSCNT Number of times parsed.
PRSCPU CPU time spent parsing.
PRSELA Elapsed time spent parsing.
PRSDSK Number of physical reads during parse.
PRSMIS Number of consistent reads during parse.
PRSCU Number of current reads during parse.
PRSMIS Number of library cache misses during parse.

Steps

1. Locate the INIT.ORA file for your database and open it using any text editor. Under Windows NT, the initialization file is in \ORANT\DATABASE and is named INIT <DATABASE INSTANCE ID>.ORA.

Edit or add the values for the MAX_DUMP_SIZE, TIMED_STATISTICS, and USER_DUMP_DEST parameters as shown in Figure 14.6. Shutdown and restart the database so that the new initialization parameters are active.

Note - Do not set the SQL_TRACE parameter to TRUE unless you are the only user of the database and want to run the SQL*Trace facility on all statements. Running SQL*Trace on all SQL statements for an instance degrades performance and generates huge trace files.

2. The SQL script CHP14_9.SQL creates three sample tables similar to the familiar SCOTT schema objects. Start SQL*Plus, connect as the WAITE user, and use the START command to load and execute this script. The script appears in Figure 14.7.

3. Use the START command to load and execute the script CHP14_10.SQL. Figure 14.8 displays the script and its output.

The ALTER SESSION command enables the SQL*Trace facility to analyze all future SQL statements.

4. Use the START command to load and execute CHP14_11.SQL. Figure 14.9 features the query; the query’s results, 100 rows of data from the three tables, is not shown to conserve space.

The query extracts rows from the three tables created in Step 2, joins them with a WHERE clause in lines 5 and 6, and finally presents them in employee name order via an ORDER BY clause in line 7. Because Step 3 enabled the SQL*Trace facility, Oracle8 generates statistics in the trace file when it executes this query.

5. Use the START command to load and execute the CHP14_12.SQL script to disable the SQL*Trace utility (see Figure 14.10).

6. Get to an operating system prompt and locate the trace file that SQL*Trace created during Step 4. Enter the following command to execute the TKPROF utility and create a readable version of the trace file.

TKPROF ora00133.trc tkprof.out sys=no explain=waite/press

This command executes the raw trace file called ORA00133.TRC and creates a readable trace file called TKPROF.OUT. Replace the trace file name in the previous command with the name of the trace file you want to format. The SYS=NO option suppresses analysis of recursive (Oracle internal) SQL and the EXPLAIN option requests execution path analysis. The username and password is necessary because execution path analysis requires a database connection.

7. Use any ASCII text display facility, such as Windows Wordpad, to display the reformatted trace file. If the TKPROF command line included the EXPLAIN option, then the trace file will contain a statistics section and an execution path section for each analyzed SQL statement. The statistics section appears in Figure 14.11.

The PARSE row contains statistics for the parse steps the SQL statements generated. The EXECUTE row shows statistics for the execute steps of the statements. If the statement is a data manipulation statement, the number of rows processed are shown in this row. The FETCH row shows statistics for the fetch steps performed by the statement. The value of 100 shown in this row indicates that the SELECT statement processed 100 data rows. Table 14.9 shows the columns TKPROF includes in the statistics portion of its report.

Table 14.9 Columns displayed in the statistics portion of the TKPROF report

Column Description
CALL Type of call: parse, execute, or fetch
COUNT Number of parses, executes, or fetches
CPU Total CPU (in seconds) for this call type
ELAPSED Total elapsed (real) time (in seconds) for this call type
DISK Physical blocks retrieved from disk
QUERY Consistent mode retrieves for this call type
CURRENT Current mode retrieves for this call type
ROWS Number of rows processed (not including subquery rows)

Figure 14.12 shows the execution path portion of the TKPROF output file. This section reports the execution path for the SQL statement and the number of rows processed in each step.

How It Works

Step 1 outlines the modifications to the initialization parameter file to enable SQL*Trace processing and Step 2 creates some sample objects for SQL*Trace analysis. The ALTER SESSION command enables the SQL*Trace utility in Step 3. The SQL statement in Step 4 results in a SQL*Trace statistics file, which Step 6 reformats via the TKPROF utility. Step 5 shows how to disable SQL statement analysis by turning the SQL*Trace utility off. Step 7 shows how to display and interpret SQL*Trace and TKPROF output using any ASCII text editor.

Comments

SQL*Trace provides a good starting point for application tuning because it can analyze all SQL statements issued during any user session. The CHP14_10.SQL script highlights a useful minor technique to help developers find SQL*Trace output files for a database where many such files may exist. The inclusion of a statement like this one:

SELECT ‘statement identifier’ FROM DUAL;

will serve this purpose because the SELECT statement resides within the SQL*Trace output file as an aid in identification.