Re: 'alter session set sql_trace=true' bug or feature ?

From: Holger Baer <holger.baer_at_science-computing.de>
Date: Tue, 23 Dec 2003 15:02:16 +0100
Message-ID: <bs9ht8$1pf$1@news.BelWue.DE>

Holger Baer wrote:
> VC wrote:
>

>> Hello Holger,
>>
>> "Holger Baer" <holger.baer_at_science-computing.de> wrote in message
>> news:bs9d7c$pvi$1_at_news.BelWue.DE...
>>
>>> VC wrote:
>>>
>>> Sorry if I missed something in this thread sofar, but what is actually
>>
>>
>> your
>>
>>> problem? If you turn on tracing, then your goal is not to measure 
>>> elapsed
>>
>>
>> wallclock
>>
>>> time for the complete query, but rather create a trace file with explain
>>
>>
>> plan,
>>
>>> waits etc.
>>
>>
>>
>> The problem is that the increase is not 'wall-clock', or run-time 
>> delta but
>> pure and solid 100% CPU time. If you'd taken the trouble of looking at 
>> the
>> trace files,  you'd discovered it yourself before rushing to comment.
>>
>>
>>> So while an massivly increased response time might bother you, it 
>>> doesn't
>>
>>
>> render
>>
>>> sql_trace useless.
>>
>>
>>
>> Then how would you go about tuning a query for which tkprof shows CPU 
>> time
>> 250 seconds and 210 of those seconds were contributed by the trace 
>> itself ?
>> Please enlighten us.

>
>
> See, that was my question. Until now I've only seen examples with wallclock
> timings. But when you say that tkprof reports them as well, I see your
> problem.
>

>>
>> Now,  we also have a complex query that runs fro about 10 minutes.  
>> Enabling
>> trace in order to obtain tkprof data makes it run close to an hour. Your
>> recommendations ?
>>

>
> What should I recommend faced with an obvious bug? ;-) But since you
> asked so
> nicely, I repeated your steps on Windows with 9.2.0.4 first with
> sql_trace = true,
> then with event '10046 trace name context forever, level 12'. Strangely
> enough,
> when tracing is on, after each fetch there is a fairly high wait reported
> for 'SQL*NET message from client' which in turn amounts to about 87% of
> the total
> runtime.
>
> This could be reproduced with pl/sql developer, so it seems not a
> sql*plus bug,
> but in the oracle kernel.
>
> So with the current state of 9.2.0.4 your only chance seems to step back
> from 9.2.0.4
> to any version that had not this problem (perhaps an extra tuning
> instance)?
>

I should have mentioned that the waits are only reported in the raw trace file, wherease tkprof seems unable to assign them to the correct statement.

Holger Received on Tue Dec 23 2003 - 08:02:16 CST