Re: gettimeofday() goes backwards on FreeBSD 4.9

"Nigel J. Andrews" <nandrews(at)investsystems(dot)co(dot)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;
}