Oracle TKProf Usage

The TKProf facility accepts as input a SQL trace file and produces a formatted output file.

TKPROF filename_source filename_output EXPLAIN=[username/password] SYS=[YES/No] TABLE=[tablename]

filename_source: The trace file that needs to be formatted.
filename_output: The output file where the formatted file will be written.
EXPLAIN: This option causes TKProf to generate an execution plan for each SQL statement in the trace file as though it was been parsed at the time the TKProf is being run. TKProf connects as the user [username] and uses the EXPLAIN PLAN command to generate an execution plan for each traced SQL statement. These explain plans are written to the output file. Note that in later releases, the raw trace file automatically records the explain plan that was used at execution time and TKProf will automatically output this plan. If the EXPLAIN option is selected then two explain plans appear in the TKProf output. The first explain plan is the plan that was used at execution time. The second plan is the plan that was generated dynamically at the time the TKProf runs. If session settings etc have changed between the execution time and when the trace file is TKProffed then the first and second plans may differ.
TABLE: Specifies the schema and name of the table into which TKPROF temporarily places execution plans before writing them to the output file. If the specified table already exists, TKProf deletes its rows then uses it for the EXPLAIN PLAN command and then deletes its rows. If this table does not exist, TKProf creates, uses, then drops it. This parameter is ignored if the EXPLAIN parameter isn't used.
SYS: Enables and disables the listing of SQL statements issued by the user SYS (recursive SQL statements) into the output file. The default value is YES.

We create a SQL Trace by using following command:-

#Enable tracing.
alter session set tracefile_identifier='10046'; 
alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
alter session set events '10046 trace name context forever,level 12';  

#Query

select * from all_objects;

#Disable tracing
alter session set events '10046 trace name context off';

Since we are tracing current session the tracefile can be identified by following query:-

select tracefile from v$process join v$session on (addr=paddr)

where sys_context('userenv','sessionid') = audsid

/

This tracefile contains lot of data but doesn’t appear to be quite eye friendly. Once tracefile is identified use following tkprof command to get a tkprof formatted output.

tkprof ORCL11_ora_12383_10046.trc tkprof.out explain=admin/admin table=sys.plan_table

This would generate a tkprof formatted file tkprof.out, something like:

TKPROF: Release 12.2.0.1.0 - Development on Thu Dec 27 05:39:56 2018
 Copyright (c) 1982, 2017, Oracle and/or its affiliates.  All rights reserved.
 Trace file: tracefile_10046.trc
 Sort options: default
 
 count    = number of times OCI procedure was executed
 cpu      = cpu time in seconds executing
 elapsed  = elapsed time in seconds executing
 disk     = number of physical reads of buffers from disk
 query    = number of buffers gotten for consistent read
 current  = number of buffers gotten in current mode (usually for update)
 rows     = number of rows processed by the fetch or execute call
 
 SQL ID: 4m94ckmu16f9k Plan Hash: 3910148636
 select count(*)
 from
  dual
 call     count       cpu    elapsed       disk      query    current        rows
 ------- ------  -------- ---------- ---------- ---------- ----------  ----------
 Parse        1      0.00       0.00          0          0          0           0
 Execute      1      0.00       0.00          0          0          0           0
 Fetch        2      0.00       0.00          0          0          0           1
 ------- ------  -------- ---------- ---------- ---------- ----------  ----------
 total        4      0.00       0.00          0          0          0           1
 Misses in library cache during parse: 1
 Optimizer mode: ALL_ROWS
 Parsing user id: SYS
 Number of plan statistics captured: 1
 Rows (1st) Rows (avg) Rows (max)  Row Source Operation
 ---------- ---------- ----------  ---------------------------------------------------
          1          1          1  SORT AGGREGATE (cr=0 pr=0 pw=0 time=21 us starts=1)
          1          1          1   FAST DUAL  (cr=0 pr=0 pw=0 time=1 us starts=1 cost=2 size=0 card=1)
 Elapsed times include waiting on following events:
   Event waited on                             Times   Max. Wait  Total Waited
   ----------------------------------------   Waited  ----------  ------------
   Disk file operations I/O                        1        0.00          0.00
   SQLNet message to client                       2        0.00          0.00   SQLNet message from client                     2       10.63         10.63