Trace it!

I often give people the advice to trace their SQL session to see what is going on. Knowing how to trace is one of the tools that every developer and DBA should have in their toolbox.

By tracing, I mean capturing all the SQL in a user's session, or a SQL trace. As you can tell from the Oracle Performance Tuning Guide and Reference, there are many ways to enable tracing. Below are two methods I use as a DBA in my day-to-day routine.


Turn tracing on

Enabling tracing in your own session is very easy. From SQL*Plus, just alter your session and set sql_trace=true.

SQL> alter session set sql_trace=true;

Session altered.

Dude, you're tracing. Every query you run from now on will go into a trace file until you set sql_trace to false.

Sometimes, a session is already underway and you need to start a trace midway through it's execution. Here, you need to be a DBA and enable the 10046 event in the user's session. This is a little more tricky since you have to know the sid and serial# from v$session in order to enable the tracing. For example,

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

     SID    SERIAL# USERNAME
---------- ---------- ------------------------------
      25          5 JEFFH

SQL> exec sys.dbms_system.set_ev(25, 5, 10046,8,'');

PL/SQL procedure successfully completed.

Statements get written to the trace file when they are first encountered after the trace is started. The statement that is executing may not be in the final trace file.

If you are using dedicated servers, the trace file will typically be in the directory on the server specified by the user_dump_dest parameter in the init.ora file. If you are using shared servers, the trace file will be in the directory specified by background_dump_dest. The trace file will have your server process id in it somewhere. If you are running the trace on your own session, you can create a stub with the ALTER SESSION SET TRACEFILE_IDENTIFIER=xxx; This way, your file will have the "xxx" name in it and be easier to identify.


What do I do with it?

OK, so you got this big file. It's just a simple ASCII file, go ahead and read it.

Nah, just kidding. Oracle gives you this program called TKProf that reads your trace file and spits out somewhat meaningful output. (I think Oracle uses tkprof as an acronym for Tom Kyte, Professor, but that's just speculation on my part.) My favorite option to tkprof is sort=prsela,fchela,exeela. This sorts the statements from longest running to shortest running. I prefer this format because I can concentrate on the top two or three statements for the most impact.

SQL> alter session set sql_trace=true;

Session altered.

SQL> alter session set tracefile_identifier='mytest';

Session altered.

SQL> select count(*) from xyz_master;

COUNT(*)
----------
       4

SQL> select count(*) from xyz_detail;

COUNT(*)
----------
      16

SQL> exit

D:\oracle\product\admin\xp10\udump>dir *mytest*
Volume in drive D has no label.
Volume Serial Number is 70AE-6E52

Directory of D:\oracle\product\admin\xp10\udump

07/04/2005  08:11 PM            38,785 xp10_ora_1544_mytest.trc
             1 File(s)         38,785 bytes
             0 Dir(s)  14,751,383,552 bytes free

D:\oracle\product\admin\xp10\udump>tkprof xp10_ora_1544_mytest.trc foo.out sort=prsela,exeela,fchela

TKPROF: Release 10.1.0.2.0 - Production on Mon Jul 4 20:16:53 2005

Copyright (c) 1982, 2004, Oracle.  All rights reserved.

D:\oracle\product\admin\xp10\udump>dir /od foo.out
Volume in drive D has no label.
Volume Serial Number is 70AE-6E52

Directory of D:\oracle\product\admin\xp10\udump

07/04/2005  08:16 PM            21,368 foo.out
             1 File(s)         21,368 bytes
             0 Dir(s)  14,751,358,976 bytes free

D:\oracle\product\admin\xp10\udump>

Things you will want to know about tracing

• The timed_statistics init.ora parameter must be set to true in order to get any meaningful timing data out of tkprof.


• I prefer to set the max_dump_file_size init.ora parameter to either unlimited or a really large value (2G). If you're going through the extra work of tracing a process you don't want to potentially miss the most important part.

For more details
Oracle-Base.com
Pete Finnigan