Received: from localhost (unknown [200.46.204.183])
	by postgresql.org (Postfix) with ESMTP id 8ECC79F9D5E
	for <pgsql-performance-postgresql.org@postgresql.org>;
	Thu, 13 Sep 2007 12:36:13 -0300 (ADT)
Received: from postgresql.org ([200.46.204.71])
	by localhost (mx1.hub.org [200.46.204.183]) (amavisd-maia, port 10024)
	with ESMTP id 50009-02 for
	<pgsql-performance-postgresql.org@postgresql.org>;
	Thu, 13 Sep 2007 12:36:09 -0300 (ADT)
X-Greylist: from auto-whitelisted by SQLgrey-1.7.5
Received: from mail.libertyrms.com (vgateway.libertyrms.info [207.219.45.62])
	by postgresql.org (Postfix) with ESMTP id F0FB29F9C95
	for <pgsql-performance@postgresql.org>;
	Thu, 13 Sep 2007 12:36:08 -0300 (ADT)
Received: from dba5.int.libertyrms.com ([10.1.3.44])
	by mail.libertyrms.com with esmtp (Exim 4.22)
	id 1IVqjc-00084q-K9; Thu, 13 Sep 2007 11:36:04 -0400
Subject: Re: Long Running Commits - Not Checkpoints
From: Brad Nicholson <bnichols@ca.afilias.info>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: pgsql-performance@postgresql.org
In-Reply-To: <15180.1189696209@sss.pgh.pa.us>
References: <1189692915.8624.22.camel@bnicholson-desktop>
	<1189695802.8624.25.camel@bnicholson-desktop>
	<15180.1189696209@sss.pgh.pa.us>
Content-Type: text/plain
Date: Thu, 13 Sep 2007 11:35:59 -0400
Message-Id: <1189697763.8624.30.camel@bnicholson-desktop>
Mime-Version: 1.0
X-Mailer: Evolution 2.8.1 
Content-Transfer-Encoding: 7bit
X-SA-Exim-Mail-From: bnichols@ca.afilias.info
X-SA-Exim-Scanned: No; SAEximRunCond expanded to false
X-Virus-Scanned: Maia Mailguard 1.0.1
X-Archive-Number: 200709/249
X-Sequence-Number: 26794

On Thu, 2007-09-13 at 11:10 -0400, Tom Lane wrote:
> Brad Nicholson <bnichols@ca.afilias.info> writes:
> > On Thu, 2007-09-13 at 10:15 -0400, Brad Nicholson wrote:
> >> I'm having a problem with long running commits appearing in my database
> >> logs.  It may be hardware related, as the problem appeared when we moved
> >> the database to a new server connected to a different disk array.
> 
> > More on this - we also have long running commits on installations that
> > do have the wal files on a separate partition.
> 
> What's your definition of "long running commit" --- seconds? milliseconds?
> Exactly what are you measuring?  Can you correlate the problem with what

log_min_duration is set to 150ms

Commits running over that up to 788ms.  Here is what we see in the logs
(with obfuscated dbname, username and IP):

2007-09-13 10:01:49.787 CUT [782426] dbname username 1.2.3.171 LOG:
duration: 224.286 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 10:19:16.373 CUT [737404] dbname username 1.2.3.174 LOG:
duration: 372.545 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 10:19:24.437 CUT [1806498] dbname username 11.2.3.171 LOG:
duration: 351.544 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 10:33:11.204 CUT [962598] dbname username 1.2.3.170 LOG:
duration: 504.057 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 10:40:33.735 CUT [1282104] dbname username 1.2.3.174 LOG:
duration: 250.127 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 10:49:54.752 CUT [1188032] dbname username 1.2.3.170 LOG:
duration: 382.781 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]
2007-09-13 11:30:43.339 CUT [1589464] dbname username 1.2.3.172 LOG:
duration: 408.463 ms  statement: EXECUTE <unnamed>  [PREPARE:  commit]


-- 
Brad Nicholson  416-673-4106
Database Administrator, Afilias Canada Corp.