SQL Trace and the Command Line Interface

28th November 2016

I recently purchased “Expert one-on-one Oracle” by Tom Kyte. Packed full of years of knowledge from the export himself, one of the first sections I dived into was on tuning strategies and tools. In particular, SQL_TRACE, TIMED_STATISTICS, and TKPROF. As Tom alludes to, tuning tools are not used enough, which he believes is generally down to ignorance of their existence. I know I fall into that bucket.

SQL_TRACE (Parameter)

Enables the logging of all the SQL you run, performance statistics regarding the execution of that SQL, and the query plans your SQL actually used.

TIMED_STATISTICS (Parameter)

It controls whether Oracle will collect timing information for various activities in the database. It’s very useful so Tom recommends setting it to TRUE even when not tuning. Its performance impact on a database is negligible in general. It can be set at either SYSTEM or SESSION level. As of 11g its set to TRUE by default.

TKPROF (Tool)

A simple command line tool to format a raw trace file into a readable format.

SQL> set echo on

SQL> show parameter timed_statistics;

NAME TYPE VALUE

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

timed_statistics boolean TRUE

SQL> alter session set sql_trace=true;

Session altered.

If the TIMED_STATISTICS is set to FALSE, then run the following to enable it.

SQL> alter session set timed_statistics=true;

Once these two parameters have been set, we need to obtain the SPID (server process ID). This will allow us to identify the relevant trace file.

SQL> select a.spid

2 from v$process a, v$session b

3 where a.addr = b.paddr

4 and b.audsid = userenv('sessionid');

SPID

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

12997

Next we need to obtain the value for USER_DUMP_DEST init.ora parameter. The easiest way to do this is via DBMS_UTILITY.

SQL> declare

2 l_intval number;

3 l_strval varchar2(2000);

4 l_type number;

5 begin

6 l_type :=

7 dbms_utility.get_parameter_value('user_dump_dest',l_intval,l_strval);

8 dbms_output.put_line(l_strval);

9 end;

10 /

PL/SQL procedure successfully completed.

This will give us the full path of the trace files on the server that the Oracle database is running. In my environment its set to;

/u01/app/oracle/product/11.2/db_1/rdbms/log

Next we’ll run a simple SQL statement, which we can trace.

SQL> select owner, count(*) from all_objects group by owner;

OWNER COUNT(*)

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

AUDSYS 33

DVSYS 11

GSMADMIN_INTERNAL 27

ORDSYS 2546

...

25 rows selected.

Next go to the directory on the server where the trace files are located. My Oracle database is sitting on a Linux OS.

[oracle@localhost ~]$ cd /u01/app/oracle/product/11.2/db_1/rdbms/log

[oracle@localhost log]$ ls -ltr

total 12

-rw-r-----. 1 oracle oinstall 950 Nov 27 2016 ora020507.trc

-rw-r-----. 1 oracle oinstall 950 Nov 27 2016 ora020616.trc

-rw-r-----. 1 oracle oinstall 950 Nov 27 2016 ora020696.trc

-rw-r-----. 1 oracle oinstall 950 Nov 28 2016 ora020844.trc

...

Run the following, replacing <PSID> with the value obtained earlier.

$ tkprof ora0<PSID>.trc report.txt

This will use the input trace file of "ora0<PSID>.trc" and output the results to "report.txt". For example;

[oracle@localhost log]$ tkprof ora012997.trc report.txt

You will now be able to query the file report.txt to see the trace file information in a nicely presented format.

I would recommend reading Tom’s book for more details on what’s contained within the trace files.

Back to blogs