Re: negative duration times in query logs

"George Pavlov" <gpavlov(at)mynewplace(dot)com> writes:
> I started seeing some negative durations in my production query logs --
> a "-" sign preceding the duration number, e.g.:

> % grep 'duration: -' postgresql-Wed-*
> postgresql-Wed-09.log:2008-01-02 08:56:33 PST [11705]: [538-1] LOG:
> duration: -268280.421 ms

AFAICS this is only possible if gettimeofday() goes backwards, ie,
a later call returns a time less than an earlier one did.

> I am running:
> PostgreSQL 8.1.10 on x86_64-redhat-linux-gnu, compiled by GCC gcc (GCC)
> 3.4.6 20060404 (Red Hat 3.4.6-3)

A quick search in Red Hat's bugzilla turns up several known instances of
time-going-backwards on various x86_64 hardware, eg
https://bugzilla.redhat.com/show_bug.cgi?id=241373
https://bugzilla.redhat.com/show_bug.cgi?id=244697
You might want to try to duplicate the problem using one of the test
programs mentioned there, and then add your hardware and kernel
details to the thread ... or open a new bug if it seems to be different
from these.

If your kernel isn't fully up-to-date, don't bother testing until you
have one that is ...

regards, tom lane