Re: What is syslog:duration reporting ... ? - Mailing list pgsql-admin

From Michael Fuhr
Subject Re: What is syslog:duration reporting ... ?
Date
Msg-id 20050826013121.GA89046@winnie.fuhr.org
Whole thread Raw
In response to Re: What is syslog:duration reporting ... ?  (Aldor <an@mediaroot.de>)
Responses Re: What is syslog:duration reporting ... ?  ("Marc G. Fournier" <scrappy@postgresql.org>)
Re: What is syslog:duration reporting ... ?  (Aldor <an@mediaroot.de>)
List pgsql-admin
On Fri, Aug 26, 2005 at 12:50:29AM +0100, Aldor wrote:
> Aug 25 14:53:32 forgehouse-s1 postgres[23721]: [2-1] LOG:  duration:
> 567.559 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='7537b74eab488de54d6e0167d1919207';
> Aug 25 14:53:32 forgehouse-s1 postgres[23722]: [2-1] LOG:  duration:
> 565.966 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='d84613009a95296fb511c2cb051ad618';
> Aug 25 14:53:33 forgehouse-s1 postgres[23723]: [2-1] LOG:  duration:
> 1192.789 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='d84613009a95296fb511c2cb051ad618';
> Aug 25 14:53:53 forgehouse-s1 postgres[23727]: [2-1] LOG:  duration:
> 12159.162 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='d84613009a95296fb511c2cb051ad618';
> Aug 25 14:53:54 forgehouse-s1 postgres[23728]: [2-1] LOG:  duration:
> 3283.185 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='7537b74eab488de54d6e0167d1919207';
> Aug 25 14:53:57 forgehouse-s1 postgres[23729]: [2-1] LOG:  duration:
> 2116.516 ms  statement: UPDATE session SET hit_time=now() WHERE
> md5='7537b74eab488de54d6e0167d1919207';
>
> Take a look to the timestamps... they are not really close to each other...

Eh?  The timestamps show that the updates *are* close to each other.
What we don't know is whether this log excerpt shows all statements
that were executed during its time frame.  It might have been grep'ed
from the full log file, or the log_min_duration_statement setting
might be such that only statements lasting more than a certain
amount of time are logged and we're not seeing similar updates that
happened quickly, nor when any of the updates were committed.

Marc, does my hypothesis of updates being blocked by other transactions
sound plausible in your environment?  How complete a log did you
post -- is it everything, or are there other statements that you
omitted or that weren't logged because of the log_min_duration_statement
setting?

--
Michael Fuhr

pgsql-admin by date:

Previous
From: "Colin E. Freas"
Date:
Subject: Re: pgcrypto regression test: how can I change the port?
Next
From: "Marc G. Fournier"
Date:
Subject: Re: What is syslog:duration reporting ... ?