SQL Trace & TKPROF

1.Compare the number of parses to number of executions. 

A well-tuned system will have one parse per n executions of a statement and will eliminate the re-parsing of the same statement. 

2.Search for SQL statements that do not use bind variables (:variable). These statements should be modified to use bind variables.

3. Identify those statements that perform full table scans, multiple disk reads, and high CPU consumption. 

These performance benchmarks are defined by the DBA and need to be tailored to each database. What may be considered a high number of disk reads for an OLTP application may not even be minimal for a data warehouse implementation.

Understanding the SQL Trace Facility

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

Using the SQL Trace facility can have a severe performance impact and may result in

• increased system overhead,
• excessive CPU usage, and
• inadequate disk space.

Using the SQL Trace Facility and TKPROF

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

• Set initialization parameters for trace file management.
• 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.
• 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.
• Interpret the output file created in Step 3.
• Optionally, run the SQL script produced in Step 3 to store the statistics in the database.

Step 1: Setting Initialization Parameters for Trace File Management

Before enabling the SQL Trace facility:
Check the settings of the TIMED_STATISTICS, MAX_DUMP_FILE_SIZE, and USER_DUMP_DEST initialization parameters.

• Enable Timed Statistics – This parameter enables the collection of certain vital statistics such as CPU execution time, wait events, and elapsed times. The resulting trace output is more meaningful with these statistics. The command to enable timed statistics is: 

ALTER SYSTEM SET TIMED_STATISTICS = TRUE; 

• Check the User Dump Destination Directory – The trace files generated by Oracle can be numerous and large. These files are placed by Oracle in the user_dump_dest directory as specified in the init.ora. The user dump destination can also be specified for a single session using the alter session command. Make sure that enough space exists on the device to support the number of trace files that you expect to generate. 

Devise a way of recognizing the resulting trace file.
You can 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';

Step 2: Enabling the SQL Trace Facility

By default, tracing is disabled due to the burden (5-10%) it places on the database. 
Tracing can be defined at the session level: 

  

ALTER SESSION SET SQL_TRACE = TRUE; 

  

DBMS_SESSION.SET_SQL_TRACE(TRUE); 

A DBA may enable tracing for another user’s session by using the following statement: 

 DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(sid,serial#,true);

The sid (Session ID) and serial# can be obtained from the v$session view. 
Once tracing with Oracle tkprof is enabled, Oracle generates and stores the statistics in the trace file. The trace file name is version specific.

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

  

- Enable Oracle tkprof tracing only on those sessions that are having problems. 

- Explain Plan is not as useful when used in conjunction with tkprof since the trace file contains the actual execution path of the SQL statement. Use Explain Plan when anticipated execution statistics are desired without actually executing the statement. 

  

- When tracing a session, remember that nothing in v$session indicates that a session is being traced. Therefore, trace with caution and remember to disable tracing after an adequate amount of trace data has been generated.

  

  

Step 3: 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.

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]

The input and output files are the only required arguments.
 If you invoke TKPROF without arguments, then online help is displayed. 

TKPROF Arguments : check in  Link

TKPROF Example 1

If you are processing a large trace file using a combination of SORT parameters and the PRINT parameter, then you can produce a TKPROF output file containing only the highest resource-intensive statements.

For example, the following statement prints the 10 statements in the trace file that have generated the most physical I/O:
TKPROF ora53269.trc ora53269.prf SORT = (PRSDSK, EXEDSK, FCHDSK) PRINT = 10

 Note:

PRSDSK Number of physical reads from disk during parse. 
EXEDSK Number of physical reads from disk during execute. 
FCHDSK Number of physical reads from disk during fetch. 

TKPROF Example 2

This example runs TKPROF, accepts a trace file named dlsun12_jane_fg_sqlplus_007.trc, and writes a formatted output file named outputa.prf:

TKPROF dlsun12_jane_fg_sqlplus_007.trc OUTPUTA.PRF
EXPLAIN=scott/tiger TABLE=scott.temp_plan_table_a INSERT=STOREA.SQL SYS=NO
SORT=(EXECPU,FCHCPU)

This example is likely to be longer than a single line on the screen, and you might need to use continuation characters, depending on the operating system.

Note the other parameters in this example:

• The EXPLAIN value causes TKPROF to connect as the user scott and use the EXPLAIN PLAN statement to generate the execution plan for each traced SQL statement. You can use this to get access paths and row source counts.

Note:
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.

• The TABLE value causes TKPROF to use the table temp_plan_table_a in the schema scott as a temporary plan table.
• The INSERT value causes TKPROF to generate a SQL script named STOREA.SQL that stores statistics for all traced SQL statements in the database.
• The SYS parameter with the value of NO causes TKPROF to omit recursive SQL statements from the output file. In this way, you can ignore internal Oracle statements such as temporary table operations.
• The SORT value causes TKPROF to sort the SQL statements in order of the sum of the CPU time spent executing and the CPU time spent fetching rows before writing them to the output file. For greatest efficiency, always use SORT parameters.

Step 4: Interpreting TKPROF Output

This section provides pointers for interpreting TKPROF output.

• Tabular Statistics in TKPROF
• Row Source Operations
• Wait Event Information
• Interpreting the Resolution of Statistics
• Understanding Recursive Calls
• Library Cache Misses in TKPROF
• Statement Truncation in SQL Trace
• Identification of User Issuing the SQL Statement in TKPROF
• Execution Plan in TKPROF
• Deciding Which Statements to Tune

While TKPROF provides a very useful analysis, the most accurate measure of efficiency is the actual performance of the application in question. 

At the end of the TKPROF output is a summary of the work done in the database engine by the process during the period that the trace was running.

Check in detail : Link 

Interpreting TKPROF Output::


CALL Column Values CALL Value Meaning
PARSE
Translates the SQL statement into an execution plan, including checks for proper security authorization and checks for the existence of tables, columns, and other referenced objects.

EXECUTE
Actual execution of the statement by Oracle. For INSERT, UPDATE, and DELETE statements, this modifies the data. For SELECT statements, this identifies the selected rows.

FETCH
Retrieves rows returned by a query. Fetches are only performed for SELECT statements.

-------------
The sum of query and current is the total number of buffers accessed, also called Logical I/Os (LIOs).
-------------------------------
Row source operations provide the number of rows processed for each operation executed on the rows and additional row source information, such as physical reads and writes. The following is a sample:
Rows            Row Source Operation
-------       ---------------------------------------------------
0                 DELETE (cr=43141 r=266947 w=25854 time=60235565 us)
28144        HASH JOIN ANTI (cr=43057 r=262332 w=25854 time=48830056 us)
51427        TABLE ACCESS FULL STATS$SQLTEXT (cr=3465 r=3463 w=0 time=865083 us)
647529      INDEX FAST FULL SCAN STATS$SQL_SUMMARY_PK
                           (cr=39592 r=39325 w=0 time=10522877 us) (object id 7409)
---------------------------------------------------------------
To ensure that wait events information is written to the trace file for the session, run the following SQL statement:
ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';

---------------------------------------------
If recursive calls occur while the SQL Trace facility is enabled, then TKPROF produces statistics for the recursive SQL statements and marks them clearly as recursive SQL statements in the output file. 
You can suppress the listing of Oracle internal recursive calls (for example, space management) in the output file by setting the SYS command-line parameter to NO.
-----------------------------------
Deciding Which Statements to Tune::
You need to find which SQL statements use the most CPU or disk resource. If the TIMED_STATISTICS parameter is on, then you can find high CPU activity in the CPU column. If TIMED_STATISTICS is not on, then check the QUERY and CURRENT columns.
The following listing shows TKPROF output for one SQL statement as it appears in the output file:
SELECT *
FROM emp, dept
WHERE emp.deptno = dept.deptno;
call count cpu elapsed disk query current rows
---- ------- ------- --------- -------- -------- ------- ------
Parse 11 0.08 0.18 0 0 0 0
Execute 11 0.23 0.66 0 3 6 0
Fetch 35 6.70 6.83 100 12326 2 824
------------------------------------------------------------------
total 57 7.01 7.67 100 12329 8 826
Misses in library cache during parse: 0
If it is acceptable to have 7.01 CPU seconds and to retrieve 824 rows, then you need not look any further at this trace output. In fact, a major use of TKPROF reports in a tuning exercise is to eliminate processes from the detailed tuning phase.
You can also see that 10 unnecessary parse call were made (because there were 11 parse calls for this one statement) and that array fetch operations were performed. You know this because more rows were fetched than there were fetches performed. A large gap between CPU and elapsed timings indicates Physical I/Os (PIOs).

Step 5: Storing SQL Trace Facility Statistics

You might want to keep a history of the statistics generated by the SQL Trace facility for an application, and compare them over time. TKPROF can generate a SQL script that creates a table and inserts rows of statistics into it. 
This script contains:

• A CREATE TABLE statement that creates an output table named TKPROF_TABLE.
• INSERT statements that add rows of statistics, one for each traced SQL statement, to the TKPROF_TABLE.

After running TKPROF, you can run this script to store the statistics in the database.

5.1 Generating the TKPROF Output SQL Script
When you run TKPROF, use the INSERT parameter to specify the name of the generated SQL script. If you omit this parameter, then TKPROF does not generate a script.