Re: CPU time and Elapsed time in tkprof
From: Frank <fvanbortel_at_netscape.net>
Date: Thu, 20 Mar 2003 20:51:30 +0100
Message-ID: <3E7A1BC2.9000100_at_netscape.net>
>>Sam To wrote:
>>
>>>I'm using 8.1.7.4 and I have the following SQL:
>>>DELETE FROM MY_TAB WHERE id = :b1
>>>
>>>There is an Oracle Text index defined on MY_TAB, so when the above
>>>executes it executes a bunch of recursive SQL.
>>>
>>>My question is if the tkprof report shows:
>>>DELETE FROM MY_TAB WHERE id = :b1
>>>
>>>call count cpu elapsed disk query current
>>> rows
>>>------- ------ -------- ---------- ---------- ---------- ----------
>>>----------
>>>Parse 1 0.02 0.34 9 66 0
>>> 0
>>>Execute 4 522.76 619.75 249 30183 72098
>>> 9993
>>>Fetch 0 0.00 0.00 0 0 0
>>> 0
>>>------- ------ -------- ---------- ---------- ---------- ----------
>>>----------
>>>total 5 522.78 620.09 258 30249 72098
>>> 9993
>>>
>>>Does elapsed time and cpu time include the time taken for the
>>>recursive sql? Or do I need to sum this with the elapsed time of each
>>>of the recursive sql to get an accurate measurement of how long this
>>>statement took? Is the behavior different in 8.1.7.4 vs 9.2 regarding
>>>the measurement of how long a SQL took?
>>>
>>>Thanks
>>>Sam
>>
>>Not clear from what you posted - recursive sql is shown when the right
>>switches are used - there should be an entry in the report showing
>>recursive sql with timing.
>>
>>Apart from that, notice the four (4) executions.
Date: Thu, 20 Mar 2003 20:51:30 +0100
Message-ID: <3E7A1BC2.9000100_at_netscape.net>
Sam To wrote:
> Frank <fvanbortel_at_netscape.net> wrote in message news:<3E78B447.6030806_at_netscape.net>... >
>>Sam To wrote:
>>
>>>I'm using 8.1.7.4 and I have the following SQL:
>>>DELETE FROM MY_TAB WHERE id = :b1
>>>
>>>There is an Oracle Text index defined on MY_TAB, so when the above
>>>executes it executes a bunch of recursive SQL.
>>>
>>>My question is if the tkprof report shows:
>>>DELETE FROM MY_TAB WHERE id = :b1
>>>
>>>call count cpu elapsed disk query current
>>> rows
>>>------- ------ -------- ---------- ---------- ---------- ----------
>>>----------
>>>Parse 1 0.02 0.34 9 66 0
>>> 0
>>>Execute 4 522.76 619.75 249 30183 72098
>>> 9993
>>>Fetch 0 0.00 0.00 0 0 0
>>> 0
>>>------- ------ -------- ---------- ---------- ---------- ----------
>>>----------
>>>total 5 522.78 620.09 258 30249 72098
>>> 9993
>>>
>>>Does elapsed time and cpu time include the time taken for the
>>>recursive sql? Or do I need to sum this with the elapsed time of each
>>>of the recursive sql to get an accurate measurement of how long this
>>>statement took? Is the behavior different in 8.1.7.4 vs 9.2 regarding
>>>the measurement of how long a SQL took?
>>>
>>>Thanks
>>>Sam
>>
>>Not clear from what you posted - recursive sql is shown when the right
>>switches are used - there should be an entry in the report showing
>>recursive sql with timing.
>>
>>Apart from that, notice the four (4) executions.
> > > The recursive sqls were indeed shown in the trace file. My question > is, to get the total elapsed time of the original sql as the user > would have observed (e.g. by waiting in front of a terminal), do I > have to sum the elapsed time of the original sql and the recusrive > sqls? Or does the elapsed time in the trace file for the original sql > already include the elapsed time of the original sql? > > How can I find which recursive sqls resulted from the original > statement DELETE FROM MY_TAB WHERE id = :b1? > > Thanks > Sam
I always though, recursive as show in tkprof is oracle overhead, e.g. block allocation/de-allocation. And yes - as the transaction isn't complete without that, that would be counted in for the total.
-- Regards, Frank van BortelReceived on Thu Mar 20 2003 - 20:51:30 CET