DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=beta;
	h=received:message-id:date:from:user-agent:mime-version:to:cc:subject:references:in-reply-to:content-type:content-transfer-encoding:sender;
	b=rgF+pPQ0lFHGZrICgtgWj0bpT58pUY+ll/OKlMrTJl7OBcIRu5NWgqXNPXYJhqDez6zsAhc0Y2lqZbKx551141Ohw7NZ/wJxGlhqn4A0burZk8gvP1JHYl6JBthaJGcL3su1GakcZo6yYKSQq3mMDlCKo0uJR1zqBUGGq0B18RE=
Message-ID: <465C6932.4070800@enterprisedb.com>
Date: Tue, 29 May 2007 18:56:02 +0100
From: Heikki Linnakangas <heikki@enterprisedb.com>
User-Agent: Icedove 1.5.0.10 (X11/20070329)
MIME-Version: 1.0
To: Greg Smith <gsmith@gregsmith.com>
CC: pgsql-patches@postgresql.org
Subject: Re: Logging checkpoints and other slowdown causes
References: <Pine.GSO.4.64.0704010051050.14920@westnet.com>
	<200704030814.33999.peter_e@gmx.net>
	<Pine.GSO.4.64.0704030927180.5732@westnet.com>
	<46443F02.6060300@enterprisedb.com>
	<Pine.GSO.4.64.0705111009080.18685@westnet.com>
	<465B3ABB.6010709@enterprisedb.com>
	<Pine.GSO.4.64.0705282200190.28443@westnet.com>
In-Reply-To: <Pine.GSO.4.64.0705282200190.28443@westnet.com>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

Greg Smith wrote:
> I'll take another stab at refining this can of worms I opened.  The one 
> thing I noticed on a quick review is that it's almost possible to skip 
> all the calls to gettimeofday if log_checkpoints is off now.  I'd like 
> to make that a specific goal, because that will make me feel better that 
> adding this code has almost no performance impact relative to now unless 
> you turn the feature on.

Saving a couple of gettimeofday calls on an event that happens as 
infrequently as checkpoints is not going to make any difference. 
Especially if you compare it to all the other work that's done on 
checkpoint.

> I agree with Simon that tracking create/drop separately is unnecessary. 
> As for why all the timing info is in ms, given the scale of the numbers 
> typically encountered I found it easier to work with.  I originally 
> wanted resolution down to 0.1ms if the underlying OS supports it, which 
> means 4 figures to the right of the decimal point if the unit was 
> switched to seconds.  Quite often the times reported are less than 
> 100ms, so you'll normally be dealing with fractional part of a second.  
> If we take Heikki's example:
> 
> LOG:  checkpoint complete; buffers written=3.1 MB (9.6%) write=96.8 ms 
> sync=32.0 ms
> 
> And switch it to seconds:
> 
> LOG:  checkpoint complete; buffers written=3.1 MB (9.6%) write=0.0968 ms 
> sync=0.0320 ms
> 
> I don't find that as easy to work with.  The only way a timing in 
> seconds would look OK is if the resolution of the whole thing is reduced 
> to ms, which then makes 3 decimal points--easy to read as ms instead.  
> Having stared at a fair amount of this data now, that's probably fine; 
> I'll collect up some more data on it from a fast server this week to 
> confirm whether's it's worthless precision or worth capturing.

The checkpoint will take at least a couple of seconds on any interesting 
system, so 0.1 s resolution should be enough IMHO.

-- 
   Heikki Linnakangas
   EnterpriseDB   http://www.enterprisedb.com