Re: Log message " last_statrequest ... is later than collector's time" - what does it mean?

Stephan Vollmer <vollmer(dot)stephan(at)googlemail(dot)com> writes:
> I upgraded our test database from PostgreSQL 8.4.8 to 9.0.4 via pg_dumpall.
> The database seems to work fine, but now the logfile of the new database is
> flooded with log messages like these:

> 2011-09-16 13:48:54 CEST: LOG: last_statrequest 2011-09-16
> 13:48:55.890743+02 is later than collector's time 2011-09-16
> 13:48:54.614476+02

Wow. AFAIK this is an indication of major system clock problems,
as in there's at least one backend process that is seeing gettimeofday()
results significantly later than what the stats collector process is
seeing. We have seen small processor-to-processor skews before, but
you've apparently got skews that are more than a second. It was
presumably happening before too, but pre-9.0 the stats collector doesn't
bleat about it --- we added that logging to try to diagnose such
problems.

Now it's relatively harmless so far as this particular issue goes (I
think the log bleating is the only real consequence); but it's not hard
to envision very serious problems elsewhere, for instance gmake failing
to rebuild things because file timestamps are in the future compared to
what it thinks the time is. You want to get that fixed.

> Configuration:
> - SUSE Linux Enterprise Server 10 (i586)
> - uname -a: Linux 2.6.16.21-0.8-bigsmp #1 SMP Mon Jul 3 18:25:39 UTC 2006
> i686 athlon i386 GNU/Linux

I'd file a bug report with SUSE. But probably the first thing they'd
say is you should be using a less ancient kernel, so maybe upgrade that
first and see if the issue goes away.

regards, tom lane