Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> RE: mostly latch-free SCN?

RE: mostly latch-free SCN?

From: Cary Millsap <cary.millsap_at_hotsos.com>
Date: Thu, 9 Dec 2004 21:26:09 -0600
Message-ID: <007901c4de68$01ecfcd0$6501a8c0@CVMLAP02>


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

-----Original Message-----
From: oracle-l-bounce_at_freelists.org =
[mailto:oracle-l-bounce_at_freelists.org]
On Behalf Of John Clarke
Sent: Thursday, December 09, 2004 4:51 PM To: oracle-l_at_freelists.org
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.

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

--
http://www.freelists.org/webpage/oracle-l
Received on Thu Dec 09 2004 - 21:24:06 CST

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US