Re: gettimeofday() goes backwards on FreeBSD 4.9 - Mailing list pgsql-hackers

"Nigel J. Andrews" <nandrews@investsystems.co.uk> writes:
> On an Intel Linux 2.4.18 I get them quite often, 25 in 1'45", but they
> are all just a microsecond.

What do you mean by "just a microsecond"?

Attached is a tightened-up test program that will only complain if the
value of gettimeofday goes backward (at all) or forward by more than
10 seconds (adjustable as MAX_SKIP).  This should be suitable to run on
moderately loaded machines where the test program might occasionally not
get dispatched for a few seconds.

I still see no failures on my own (non-BSD) machines, fairly frequent
failures on pgsql74.hub.org:

> ./a.out
out of order tv_sec: 1070066031 262048, prev 1070066726 688240
out of order tv_sec: 1070066726 785019, prev 1070066031 262048
out of order tv_sec: 1070066062 62622, prev 1070066757 588814
out of order tv_sec: 1070066757 771848, prev 1070066062 62622
out of order tv_sec: 1070066093 262974, prev 1070066788 689167
out of order tv_sec: 1070066788 777486, prev 1070066093 262974
out of order tv_sec: 1070066114 113410, prev 1070066809 589602
out of order tv_sec: 1070066809 724663, prev 1070066114 113410
out of order tv_sec: 1070066145 113899, prev 1070066840 590097
out of order tv_sec: 1070066840 726558, prev 1070066145 113899
out of order tv_sec: 1070066155 263911, prev 1070066850 690103
out of order tv_sec: 1070066850 781343, prev 1070066155 263911
out of order tv_sec: 1070066176 164307, prev 1070066871 590505
out of order tv_sec: 1070066871 643350, prev 1070066176 164307
out of order tv_sec: 1070066217 264846, prev 1070066912 691039
out of order tv_sec: 1070066912 775989, prev 1070066217 264846
out of order tv_sec: 1070066248 65394, prev 1070066943 591592
out of order tv_sec: 1070066943 773822, prev 1070066248 65394
^C

and rarer failures on cvs.postgresql.org:

> ./a.out
out of order tv_sec: 1070066099 389427, prev 1070066794 865617
out of order tv_sec: 1070066795 17855, prev 1070066099 389427
out of order tv_sec: 1070066252 541729, prev 1070066947 967921
out of order tv_sec: 1070066948 38715, prev 1070066252 541729
out of order tv_sec: 1070066371 393525, prev 1070067066 869715
out of order tv_sec: 1070067068 24754, prev 1070066371 393525
^C

It seems consistent that the error is 695 seconds and change
when it happens, and that the very next read gives a correct
(or at least plausible) value again.
        regards, tom lane


#include <stdio.h>
#include <sys/time.h>

#define MAX_SKIP  10

int
main()
{struct timeval prevtime;struct timeval curtime;
gettimeofday(&prevtime, NULL);
for (;;){    gettimeofday(&curtime, NULL);
    if (curtime.tv_usec < 0 || curtime.tv_usec >= 1000000)        fprintf(stderr, "bogus tv_usec: %ld %ld, prev %ld
%ld\n",               (long int) curtime.tv_sec,                (long int) curtime.tv_usec,                (long int)
prevtime.tv_sec,               (long int) prevtime.tv_usec);    else if (curtime.tv_sec < prevtime.tv_sec ||
curtime.tv_sec > prevtime.tv_sec + MAX_SKIP)        fprintf(stderr, "out of order tv_sec: %ld %ld, prev %ld %ld\n",
          (long int) curtime.tv_sec,                (long int) curtime.tv_usec,                (long int)
prevtime.tv_sec,               (long int) prevtime.tv_usec);    else if (curtime.tv_usec < prevtime.tv_usec &&
  curtime.tv_sec == prevtime.tv_sec)        fprintf(stderr, "out of order tv_usec: %ld %ld, prev %ld %ld\n",
   (long int) curtime.tv_sec,                (long int) curtime.tv_usec,                (long int) prevtime.tv_sec,
          (long int) prevtime.tv_usec);
 
    prevtime = curtime;}
return 0;
}