Simpler Navigation for Servers and Operating Systems - Please Update Your Bookmarks
Completed: a much simpler Servers and Operating Systems section of the Community. We combined many of the older boards, so you won't have to click through so many levels to get at the information you need. Check the consolidated boards here as many sub-forums are now single boards.
If you have bookmarked forums or discussion boards in Servers and Operating Systems, we suggest you check and update them as needed.
Showing results for 
Search instead for 
Did you mean: 

Tkprof interpretation !

Go to solution
Chris Fung
Frequent Advisor

Tkprof interpretation !

Hi all,

I collected sql_trace statistics and use tkprof to format the trace report. However I have some doubt about the meaning of elapsed time ?? Any idea ? What is the relationship between cpu and elapsed time? What are their significant in determinining the performance of the sql statement ?

Appreciated for your comments.

Many thanks,

Chris Fung,
Honored Contributor

Re: Tkprof interpretation !


CPU - In CPU seconds, how much time was spent on this phase of the query execution. This is only filled in if TIMED_STATISTICS are enabled.

ELAPSED - As measured by the wall clock; how long this phase of query execution took. This is again only filled in if TIMED_STATISTICS are enabled.

Let us see a tkprof that shows you things like:

update emp set ename = ename

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 39.04 0 19 16 14
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 39.04 0 19 16 14

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 241

Rows Row Source Operation
------- ---------------------------------------------------

so apparently, that took 0.01 cpu seconds yet it took 39.04 seconds by the wall clock. The end user waited AT LEAST 39.04 seconds for that result to be returned -- maybe more (that is your Y above -- 39.04, you need the X to compute whether the server or client is the bottleneck)

Now, since I have 9i we get the wait events in the tkprof as well, they are separate and distinct from ELAPSED times:

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
enqueue 14 2.99 39.03
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00

here we see the database, during the processing of this statement waited on an enqueue (a LOCK -- i locked all rows in emp in another session first). It timed out 14 times and went back and waited again. That cumulative time -- 39.03 seconds -- accounts for the difference between the CPU time above and the ELAPSED time. If we wait for nothing -- cpu and elapsed are the same, if we wait for some resource - they will differ.

Hope this helps!

Best Regards
No person was ever honoured for what he received. Honour has been the reward for what he gave (clavin coolidge)
Honored Contributor

Re: Tkprof interpretation !

hi again,
sorry for the output problem.
posting the reply in the attached text file

No person was ever honoured for what he received. Honour has been the reward for what he gave (clavin coolidge)
Chris Fung
Frequent Advisor

Re: Tkprof interpretation !

Hi Yogeeraj,

Thanks your your detailed explanation.

Very helpful to me !!!

I am very appreciated. Think that you probably an "OCM" !!