Sunday, August 24, 2008

Oracle Instrumentation: Tracing Events



The typical trace file traces the activity of the Cost Based Optimizer (cbo). Because Oracle does not document any of the settings, there is no guarantee that they will be constant, but they have been more or less constant over the years. Most people are aware of a few of the traces that can be turned on, and some people (perhaps Oracle employees) have documented most of them. To developers there are only one that is used often, and only about three more that are really interesting when you want to improve your code. Here is the format, and my list:

alter session set events '10046 trace name context forever, level 8'

10032 trace -- activity for a dump sort
10033 trace -- io for dump sort intermediate stats
10046 trace -- wait states when selecting levels 8 or 12
10053 trace -- cbo trace level 1 or 2
10104 trace -- hash join statistics use level 10

See http://www.juliandyke.com/Diagnostics/Events/EventReference.html for more of them

Two important things to remember:
1. you can trace more than one thing at a time; turn them on one by one, as you see above.
2. turn them off, like below, or just exit the session to turn them off and close the file.

alter session set events '10032 trace name context off';

Three other good things to know are that you can find your trace file (to run tkprof on it) with some simple code, if you run this on a shared server your stats will be in more than one file and you will need a utility to sort that out (Oracle now emits markers into trace files to identify sessions), and you can name the trace file for a dedicated session, which makes finding it easy.

Here is how a trace might be started, found, and formatted:

alter session set timed_statistics=true;

alter session set events
10046 trace name context forever, level 12';
--- now do something so Oracle as activity to trace
select count(*) from big_table
/

select *
from big_table
where owner = 'SYS'
and object_type = 'PACKAGE'
and object_name like 'F%'
/
--- get the name of the trace file
select rtrim(c.value,'/') || '/' || d.instance_name ||
'_ora_' || ltrim(to_char(a.spid)) || '.trc'
from v$process a, v$session b, v$parameter c, v$instance d
where a.addr = b.paddr
and b.audsid = sys_context( `userenv', 'sessionid')
and c.name = 'user_dump_dest'
/

(on Linux or Solaris, the above should give you the default name of the trace file)

If you want to avoid turning the trace off, just exit the session where you turned it on.
You need to do that anyway so you can do the next step at the OS command line.
(now run tkprof on file to format it so it makes some sense)

$ tkprof (the file name you got above) tk.prf (the name you want for the report).
-- tkyte book 2 page 123

Note this is the default settings for tkprof, and if you wanted to provide the same or other available settings, they would look something like this:

$ tkprof trace_file output file sort ='(prsela, exeela, fchela)' explain=user_name/password (this reports
IO and CPU use).


Jonathan Lewis has written a lot about figuring the cbo out and his book makes the best of a gruesome subject. Sadly, the parts that help you solve problems with Oracle are not a 12 step process, but if you want to really get a grip on how to get your code back on track, this would be part of that.

No comments: