How to generate Trace & TKProf analysis ?

Autotrace :

- Go to sqlplus and login as scott/tiger.

Issue the following command at the sqlplus prompt :

sql> set autotrace on

set autotrace on; -- Results, Explain Plan, Statistics

set autotrace traceonly explain; -- Explain Plan

set autotrace traceonly explain statistics; -- Explain Plan, Statistics

Now if you run the following query you will see the subsequent output from trace.

sql> select max(sal) from emp;

MAX(SAL)
----------
5000


Execution Plan
----------------------------------------------------------
Plan hash value: 2083865914

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 4 | 3 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 4 | | |
| 2 | TABLE ACCESS FULL| EMP | 14 | 56 | 3 (0)| 00:00:01 |
---------------------------------------------------------------------------

Statistics
----------------------------------------------------------
232 recursive calls
0 db block gets
49 consistent gets
0 physical reads
0 redo size
411 bytes sent via SQL*Net to client
381 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
6 sorts (memory)
0 sorts (disk)
1 rows processed

TKPROF

However, TKPROF provides more information than trace. To get the tkprof information, follow these steps :

a)

exec dbms_monitor.session_trace_enable( waits=>true );

OR
sql> alter session set sql_trace=true

sql> alter system set timed_statistics=true;

Log out of sqlplus.

Note : Issues these grants to scott, if you are not able to set the above.

grant alter session to scott;

grant alter system to scott;

b) cd \oracle\product\10.2.0\admin\[Oracle SID]\udump

Note : Replace with your SID from tnsnames.ora.

c)In Linux :

$ ls -t | head -1

The ouput of this command would be a file with an extension .trc.

Eg : test_ora_2996.trc

d) Now, tkprof the trace file into a temporary text file so that you can see.

$ tkprof test_ora_2996.trc tmp.txt explain=scott/tiger

e) $ vi tmp.txt

Look for the tkprof output for the sql you have fired.

ps : To quit from vi, just issue :q

In the text file, look for : select max(sal) from emp

select max(sal)
from
emp


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.01 0 7 0 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 54 (SCOTT)

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=7 pr=0 pw=0 time=61 us)
14 TABLE ACCESS FULL EMP (cr=7 pr=0 pw=0 time=54 us)


Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1 SORT (AGGREGATE)
14 TABLE ACCESS MODE: ANALYZED (FULL) OF 'EMP' (TABLE)

f) If you don't want the tmp.txt anymore,

$ rm tmp.txt

Note : You need to use the 10046 trace event to get waits in the trace file.

sql> alter session set events '10046 trace name context forever, level 12'

instead of sql_trace=true;

That's it.

References :

Auto Trace

Explain Plan

TKProf Explanation