10046 trace - unaccounted for time

From: Keith Moore <kmoore_at_zephyrus.com>
Date: Wed, 6 Aug 2008 12:02:54 -0500 (CDT)
Message-ID: <33924.>

Oracle, 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.


Received on Wed Aug 06 2008 - 12:02:54 CDT

Original text of this message