Re: 10046 trace - unaccounted for time

There is a 4th possible session state. It may be that the session is in an uninstrumented event. While this is unlikely, it does happen. I have seen this in active sessions where the event state is 'WAITED KNOWN TIME', the seconds_in_wait are increasing and the statistic 'CPU used by this session' is not increasing.

Check the FETCH entry that encompasses those WAITs. If the c value (cpu time) matches up with the 'missing' time, you were likely using a lot of CPU. If the cpu time does not match, you could be waiting on cpu or in an uninstrumented event.

Regards,
Daniel Fink

-- 
Daniel Fink

Help me support The Children's Hospital of Denver! 
I'm riding in the 2008 Courage Classic - 157 miles in 3 days
Help me reach my goal of $2,500.00 in donations.  
Visit my Personal Rider Page http://www.couragetours.com/2008/danielwfink to donate

OptimalDBA.com - Oracle Performance, Diagnosis, Data Recovery and Training

OptimalDBA    http://www.optimaldba.com
Oracle Blog   http://optimaldba.blogspot.com

Lost Data?    http://www.ora600.be/


Cary Millsap wrote:


> I agree with what Riyaj has said. It helps sometimes to realize that 

> "waits" just means essentially "OS calls."

>

> I'd expect your process is indeed doing a lot of buffer processing, 

> using data that's already in your database buffer cache. You can 

> confirm or refute this hypothesis quickly with a couple of snaps of 

> v$sess_io.

>

> Cary Millsap

> http://method-r.com

> http://carymillsap.blogspot.com

>

>

> On Wed, Aug 6, 2008 at 12:46 PM, Riyaj Shamsudeen 

> <riyaj.shamsudeen_at_gmail.com <mailto:riyaj.shamsudeen_at_gmail.com>> wrote:

>

>     Hi Keith

>      That means that process is either running on CPU or waiting for

>     CPU in the run queue, to be available. May be that all buffers it

>     is trying to access is in buffer cache and process is running on

>     the CPU without any waits.

>

>     Cheers

>     Riyaj

>     The Pythian Group

>     blog: http://orainternals.wordpress.com

>

>     Keith Moore wrote:

>

>         Oracle 9.2.0.4 <http://9.2.0.4>, Solaris

>

>         We are having a production issue where user processes are very

>         slow. We are

>         seeing 'cache buffers chains' latch events in the 10046 trace

>         file.

>

>         What I'm not fully understanding is the long periods of

>         unaccounted for time

>         where the process hangs. If I do a 'tail -f' on the trace file

>         I can see it

>         pause for several seconds. Here is a small sample of the output:

>

>         *** 2008-08-05 15:22:57.748

>         WAIT #23: nam='latch free' ela= 8 p1=16764558008 p2=98 p3=0

>         WAIT #23: nam='latch free' ela= 12 p1=16764645560 p2=98 p3=0

>         *** 2008-08-05 15:23:16.414

>         WAIT #23: nam='latch free' ela= 9 p1=16796730344 p2=98 p3=0

>         WAIT #23: nam='latch free' ela= 10 p1=16764600056 p2=98 p3=0

>         WAIT #23: nam='db file sequential read' ela= 1893 p1=66

>         p2=52489 p3=1

>         *** 2008-08-05 15:23:33.376

>         WAIT #23: nam='latch free' ela= 8 p1=16764602936 p2=98 p3=0

>         *** 2008-08-05 15:23:47.319

>         WAIT #23: nam='latch free' ela= 7 p1=16796666408 p2=98 p3=0

>

>         If you look at the first four lines, you see 20 seconds have

>         elapsed but the

>         only wait events are the two 'cache buffers chains' waits for

>         a total of 20

>         microseconds.

>

>         Can someone explain what is going on here and how to troubleshoot?

>

>         FYI, this process is deleting and the inserting a LOB and the

>         hot blocks seem

>         to be in the LOB index.

>

>         Thanks

>         Keith

>

>         --

>         http://www.freelists.org/webpage/oracle-l

>

>

>

>          

>

>

>     --

>     http://www.freelists.org/webpage/oracle-l

>

>

>




--
http://www.freelists.org/webpage/oracle-l