Christian Bilien’s Oracle performance and tuning blog

February 22, 2007

Trace analyzer vs Tkprof : beware of the recursive calls

Filed under: Oracle — christianbilien @ 10:02 am

Metrology (the science of measurement) is often underestimated. I came across a splendid example of ‘know what you are measuring’ today: I always use the trace analyzer in place of tkprof nowadays. However, a customer had already traced a session and came to me with tkprof metrics to work on. I spotted a huge difference in cpu and elapsed time on a few calls between statspack and the tkprof results.  Tkprof indeed does NOT account for recursive statements, and the time spent performing triggers is subtracted out of the statement.

An insert is triggering a select.

Here is the trace analyzer vs tkprof output, both for the insert and the underlying select. “Per insert” are the result of the total cpu and elapsed time divided by the number of calls.

Trace analyzer:

Per insert

elapsed (ms)

cpu (ms)

Insert

59

14

select (trigger)

26

6

Tkprof:

Per insert

elapsed (ms)

cpu (ms)

Insert

5,74

2,01

select (trigger)

26,14

5,84

3 Comments »

  1. Recently Joze Senegacnik was in İstanbul for a 2 Day Seminar on Optimizing for Performance. We also discussed on this topic, in my opinion tkprof is good for basic analysis but lacks of;
    * sql statemet hierarchy
    * exclusive timings for recursive sql statements
    * report for SQLs which were not parsed
    * report for cursor #0

    Two questions I didn’t have time to investigate yet are;
    * also trcsess after 10g may introduced some new pitfalls during merging,
    * what about 11g, is there any progress with tkprof pitfalls?

    I hope Oracle will invest more in tkprof since 10046 responce time based analysis is very important with root cause analysis of application performance tuning. We may not need anymore the support of trace analysers like itrprof in the future.

    ps: my seminar notes.

    Comment by H.Tonguç Yılmaz — August 29, 2007 @ 6:32 am

  2. Tonguç,

    Thanks very much for the notes. I mainly use trcsess because of the html output. However it really takes time to compile the reports when the trace is big. I had not realized the recursive stuff I wrote about until I nearly fell into trap.

    Christian

    Comment by christianbilien — August 29, 2007 @ 7:25 pm

  3. You may want to take a look at our new product Digger here http://www.fourthelephant.com/digger.html

    It supports recursive cursors and understands a difference beetween Oracle cursors and calls which is very important in calculating the times and statistics. As far as we know nobody else does that.

    Sorry for this blatant ad, but we believe that this tools is much better than any of the competitors and Oracle own analyzers and people need to know about it.

    Comment by Dmitry Skavish — September 11, 2007 @ 6:06 pm


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Blog at WordPress.com.

%d bloggers like this: