RE: mostly latch-free SCN?
- From: "Cary Millsap" <cary.millsap@xxxxxxxxxx>
- To: <Oracle-L@xxxxxxxxxxxxx>
- Date: Thu, 9 Dec 2004 21:26:09 -0600
John,
Your 'latch free' excerpt is microscopic and definitely not a concern in =
the
excerpt. That particular type of 'latch free' event has contributed only
0.000049 seconds to the approximately 6.5 MINUTES represented by your =
trace
data. Pursuing a fix to your latch "problem" will improve your response =
time
by--at most!--about 0.000013%. So, you're asking the wrong question. :)
The *** lines you're seeing are emitted by Oracle kernel calls to
dbms_system.ksdddt(). The Oracle kernel behaves as if there's a function
called "write_to_trace()" in the kernel code that handles Oracle =
extended
SQL trace file writing in the following manner:
{
static int time_of_prior_write =3D 0;
subroutine write_to_trace(TRACE, text) {
if now() - time_of_prior_write > 10 seconds {
ksdddt;
}
time_of_prior_write =3D now();
write(TRACE, text);
}
}
The *** line doesn't mean that your 'latch free' consumed a bunch of =
time.
The ela value for each timed event shows you how much time that event =
has
consumed. The *** line is telling you that it's a long time between =
calls to
Oracle timed events. This almost always indicates that the process being
traced is accessing the database buffer cache way too many times. This =
is
common because so many books, courses, etc. teach you that making sure
everything is in the buffer cache is golden goodness.
The dbcall (PARSE, EXEC, FETCH, ...) that immediately /follows/ this =
excerpt
will have a huge c value (lots of CPU service consumption for the call), =
and
a huge e value (lots of elapsed time for the call). It will almost
undoubtedly also have a huge cr+cu value as well, which will confirm =
that
you're suffering from, I would estimate, on the order of tens of =
millions of
unnecessary "consistent gets" and "db block gets."
Bottom line: You have some very inefficient SQL here that you need to =
fix.
The book "Optimizing Oracle Performance" explains further.
Cary Millsap
Hotsos Enterprises, Ltd.
http://www.hotsos.com
* Nullius in verba *
Upcoming events:
- Performance Diagnosis 101: 1/4 Calgary
- SQL Optimization 101: 12/13 Atlanta
- Hotsos Symposium 2005: March 6-10 Dallas
- Visit www.hotsos.com for schedule details...
-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx =
[mailto:oracle-l-bounce@xxxxxxxxxxxxx]
On Behalf Of John Clarke
Sent: Thursday, December 09, 2004 4:51 PM
To: oracle-l@xxxxxxxxxxxxx
Subject: mostly latch-free SCN?
Anyone have any idea what this is=3D3F
I was 10046 tracing a process and found it post a wait on mostly =
latch-f=3D
ree SCN latch. Excerpt from trace file below.
WAIT #2: nam=3D3D'db file scattered read' ela=3D3D 1054 p1=3D3D17 =
p2=3D3D30500 p=3D
3=3D3D3
WAIT #2: nam=3D3D'db file sequential read' ela=3D3D 1377 p1=3D3D17 =
p2=3D3D30504 =3D
p3=3D3D1
*** 2004-12-09 17:27:55.695
WAIT #2: nam=3D3D'latch free' ela=3D3D 49 p1=3D3D-4611686009467115424 =
p2=3D3D88 =3D
p3=3D3D0
*** 2004-12-09 17:34:20.573
WAIT #2: nam=3D3D'db file sequential read' ela=3D3D 4850 p1=3D3D50 =
p2=3D3D119591=3D
p3=3D3D1
WAIT #2: nam=3D3D'db file sequential read' ela=3D3D 6175 p1=3D3D50 =
p2=3D3D119590=3D
p3=3D3D1
I'm not positive what the "^***" lines mean, but what I can tell is =
that=3D
when hit the latch wait and displayed a wall time of 17:27, it didn't =
d=3D
o anything until the next "^***" line. Shouldn't the ela in either the =
=3D
current or next wait match the elasped time=3D3F
Thanks in advance.
--
//www.freelists.org/webpage/oracle-l
--
//www.freelists.org/webpage/oracle-l
Other related posts:
