Oracle Trace - tkprof

Oracle Trace 

 Explain plan provides an approximation of the cost of an individual SQL statement . It doesn’t always correspond to what is happening when SQL is executed and it doesn’t tell you the elapsed time or other important statistics.

We can then analyse the trace file using tkprof to present the output in a more meaningful manner for subsequent analysis.

How to do trace

• Initiate a forms or PL/SQL session
• Identify the Sid and Serial# of the session you wish to trace via PL/SQL Developer (Tools-Sessions menu entry)
• Establish a point in the application where you want to initiate tracing e.g. on a button click
• Log in as dba or ask a colleague to do so if you don’t have access
• Run the following SQL as dba to initiate the trace
  begin dbms_monitor.session_trace_enable(session_id => Sid , serial_num => Serial#); end;
• Run the following SQL as awcdba to stop tracing
       begin dbms_monitor.session_trace_disable(session_id => Sid , serial_num => Serial#); end;
• Log in to the database server .
• The log file will be available in the USER_DUMP_DEST directory. In our environments this is set to /oralog//udump.

Running TKPROF

• Identifying the trace file
• ALTER SESSION SET TRACEFILE_IDENTIFIER = 'my_trace_id';
• Formatting the trace file using tkprof
• tkprof filename.trc output_filename.txt sys=no sort=(prsela,fchela,exeela)
• This sorts the statements from longest running to shortest running. This format allows you to concentrate on the top two or three statements for the most impact.
  Sort on elapsed parse time, fetch-time, elapsed executed time
• SYS=NO omits SQL executed by the SYS user or recursive SQL.
• Warning: You need to ensure that the trace file isn’t too large. Limit the size of the trace file using the following SQL.
• ALTER SESSION SET MAX_DUMP_FILE_SIZE = 10M;

Interpreting Trace File Output

The Parse Phase – Oracle finds the Query in the Shared Pool or creates a new plan for the query (Hard Parse).
Note: Hard parses aren’t good in OLTP systems. That’s why we should always use bind variables.

The Execute Phase – This is the work done by Oracle on OPEN or EXECUTE of the query. For a SELECT this will be empty whereas for an UPDATE, this will be where all the work is done.

The Fetch Phase – For a SELECT this will be where most of the work is done and visible, but an update will show no work.

Column Headings
COUNT      - How many times the event occurred
CPU           - In CPU seconds; how much time was spent
ELAPSED  - As measured by the wall clock
DISK           - How many Physical I/O’s to disk
QUERY      - Blocks read in Consistent mode from Undo segment
CURRENT – Blocks accessed as they are now for UPDATES or Data Dictionary lookups.


Observations on the query plans In trace file

1. CR  Consistent Read ie. Logical IO from the Buffer Cache in the SGA in query mode
2. PR  Physical Read from disk.
3. If the ratio of PR to CR is high then we have a problem!
4. We aren’t using logical IO and the buffer cache
5. The query is returning too much data and swamping the buffer cache.

Advantages of tracing

• Tracing is very useful for diagnosing poor performance.
• It provides far more detail than a simple explain plan.
• Using proper sorts quickly identifies the “worst offenders”
• Experiment with different access paths. Try to reduce the cost of the query.
• Hints don’t always work. The Cost Based Optimiser often knows best.
• Remove functions on join predicates where you can to enable index use.
• Pay attention to cardinality/selectivity of predicates to determine join order.
• Often application tuning gains the best results. e.g. Amalgamate SQL. Use Analytic SQL