What is SQL Trace and TKPROF?

SQL Trace:

The SQL Trace facility and TKPROF lets you accurately assess the efficiency of the SQL statements an application runs.

How to use SQL Trace?

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.

Tracing a particular user's session:

1.) First get the SID and serial# of the session:

SQL>conn / as sysdba

SQL>select sid,serial# from v$session where username='SCOTT';

      SID    SERIAL#

---------- ----------

         1      136

2.) Enable tracing for your selected process:

SQL> ALTER SYSTEM SET timed_statistics = true;

Timed statistics means CPU and elapsed times as well as the collection of various statistics in the dynamic performance tables.

SQL> execute dbms_system.set_sql_trace_in_session(1, 136, true);

3.) Ask user to run the sql's:

4.) Look for trace file in USER_DUMP_DEST:

   D:\oracle\product\10.2.0\admin\tsm\udump

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.

Steps for TKPROF:

1.) Creating a plan_table:

The plan table is the table that Oracle fills when you have it explain an execution plan for an SQL statement. You must make sure such a plan table exists.You can use the SQL script utlxplan.sql to manually create a local PLAN_TABLE in your schema.

@ORACLE_HOME\rdbms\admin\utlxplan.sql

CREATE PUBLIC SYNONYM PLAN_TABLE FOR SYS.PLAN_TABLE;

GRANT SELECT, INSERT, UPDATE, DELETE ON SYS.PLAN_TABLE TO PUBLIC;

2.) Trace files which you obtained from SQL Trace utility now can be readable using TKPROF

TKPROF D:\oracle\product\10.2.0\admin\tsm\udump\tsm_ora_2688 c:\output.txt explain=scott/tiger@service table=sys.plan_table

Output:

select * 

from

 tab

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        3      0.00       0.00          0          0          0           0

Execute      3      0.00       0.00          0          0          0           0

Fetch        6      0.04       0.04         21       1884          0           6

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       12      0.04       0.04         21       1884          0           6

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 54  

Rows     Row Source Operation

-------  ---------------------------------------------------

      2  NESTED LOOPS OUTER (cr=628 pr=21 pw=0 time=25030 us)

      2   TABLE ACCESS FULL OBJ$ (cr=621 pr=20 pw=0 time=21996 us)

      2   TABLE ACCESS CLUSTER TAB$ (cr=7 pr=1 pw=0 time=3051 us)

      2    INDEX UNIQUE SCAN I_OBJ# (cr=4 pr=1 pw=0 time=3033 us)(object id 3)

Enjoy:-)