gettimeofday is not monotonic

Truxton Fulton (trux@truxton.com)
Mon, 22 Feb 1999 13:20:21 -0800 (PST)


Dear Linus et al,

Last week I posted a retraction of my "xclock is freezing in select()"
bug report, blaming the problem on Xt after a fresh X compilation fixed
the problem -- but the problem resurfaced two days later.

I'm tracing down the problem and I have found that gettimeofday()
is not monotonic. It produces a sawtooth output where the microseconds
jump back 10000 or 50000 depending on the kernel version (2.1.130 or
2.2.2 respectively) every 10 or 100000 iterations. The sawtooth mode
seems to be a system wide phenomenon that is triggered at some random
time after booting.

The non monotonicity of time is wreaking havoc on programs that
compute a delta time and then select(). The large select()'s that
people have been seeing are perhaps caused because the kernel
interprets a negative timeout as MAX_SCHEDULE_TIMEOUT in fs/select.c.
The shift into sawtooth mode seems to be somewhat correlated to a high
(greater than 2) load average and/or swap activity. With kernel version
2.1.130, the problem is easy to reproduce, and it is less severe
because there is just one glitch as opposed to hundreds of glitches
per second. With 2.2.2-pre4, it takes sometimes two days to reproduce,
but once it occurs, sawtooth mode continues on...

I did reproduce this in user mode with no X running at all (2.1.130).
although I also brought the system back to its senses once
by quitting X (2.2.2-pre4). Someone suggested that X may be to
blame.

This happens on a 486 with 24MB and nfs-mounted filesystems.
I have SiS 85C471 and 85C407 chips on a 486 motherboard, but no
RZ1000 nor CMD640 nor anything labeled "neptune".

In arch/i386/kernel/time.c I commented out #define BUGGY_NEPTUN_TIMER
and indeed when sawtooth time mode kicked in, I got bazillions of
"do_slow_gettimeoffset(): hardware timer problem?" messages,
although the bad sawtooth behaviour of gettimeofday seemed to
be the same as when BUGGY_NEPTUN_TIMER was defined.

I think that gettimeofday should be guaranteed to be monotonic.
If the kernel is interpolating time between jiffies, then it should
level out rather than jumping backwards in time because negative
time can be so hazardous.

If you would like me to run any additional tests, I would be glad to.

-Truxton

=============================================================================
timetest.c :

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

int main()
{
struct timeval t1,t2,*p1,*p2,*temp ;
long i,delta ;
int r ;

p1=&t1 ;
p2=&t2 ;
gettimeofday(p1,NULL) ;
for(i=0;;i++)
{
r=gettimeofday(p2,NULL) ;
delta=p2->tv_sec-p1->tv_sec ;
delta*=1000000 ;
delta+=p2->tv_usec-p1->tv_usec ;
if((r!=0) || (delta<0))
{
perror("gettimeofday") ;
printf("r=%d\t\ti=%ld\tsec=%ld\tusec=%ld\n",r,i-1,p1->tv_sec,p1->tv_usec) ;
printf("delta=%ld\ti=%ld\tsec=%ld\tusec=%ld\n",delta,i,p2->tv_sec,p2->tv_usec) ;
}
temp=p1 ;
p1=p2 ;
p2=temp ;
}
return(0) ;
}

=================================

vaiva@endorphin(~/temp)>uname -a
Linux endorphin.truxton.com 2.2.2 #3 Thu Feb 18 23:32:00 PST 1999 i486 unknown
vaiva@endorphin(~/temp)>uptime
11:49am up 14:29, 6 users, load average: 1.13, 0.68, 0.35
vaiva@endorphin(~/temp)>free -t
total used free shared buffers cached
Mem: 22632 22068 564 15224 4 10680
-/+ buffers/cache: 11384 11248
Swap: 83284 19896 63388
Total: 105916 41964 63952
vaiva@endorphin(~/temp)>./timetest
gettimeofday: Success
r=0 i=6 sec=919503941 usec=722639
delta=-50847 i=7 sec=919503941 usec=671792
gettimeofday: Success
r=0 i=17 sec=919503941 usec=731779
delta=-50847 i=18 sec=919503941 usec=680932
gettimeofday: Success
r=0 i=30 sec=919503941 usec=733500
delta=-50846 i=31 sec=919503941 usec=682654
gettimeofday: Success
r=0 i=33 sec=919503941 usec=733718
delta=-50847 i=34 sec=919503941 usec=682871
gettimeofday: Success
r=0 i=36 sec=919503941 usec=733936
delta=-50847 i=37 sec=919503941 usec=683089
gettimeofday: Success
r=0 i=39 sec=919503941 usec=734368
delta=-50846 i=40 sec=919503941 usec=683522
gettimeofday: Success
r=0 i=42 sec=919503941 usec=735015
delta=-50846 i=43 sec=919503941 usec=684169
gettimeofday: Success
r=0 i=44 sec=919503941 usec=730728
delta=-50204 i=45 sec=919503941 usec=680524
gettimeofday: Success
r=0 i=48 sec=919503941 usec=744769
delta=-50632 i=49 sec=919503941 usec=694137
gettimeofday: Success
r=0 i=50 sec=919503941 usec=743699
delta=-50202 i=51 sec=919503941 usec=693497
gettimeofday: Success
r=0 i=52 sec=919503941 usec=740699
delta=-50203 i=53 sec=919503941 usec=690496
gettimeofday: Success
r=0 i=55 sec=919503941 usec=742633
delta=-50632 i=56 sec=919503941 usec=692001
gettimeofday: Success
r=0 i=58 sec=919503941 usec=744138
delta=-50846 i=59 sec=919503941 usec=693292
gettimeofday: Success
r=0 i=60 sec=919503941 usec=741782
delta=-50204 i=61 sec=919503941 usec=691578
gettimeofday: Success
r=0 i=63 sec=919503941 usec=744574
delta=-50846 i=64 sec=919503941 usec=693728
gettimeofday: Success
r=0 i=65 sec=919503941 usec=741574
delta=-50204 i=66 sec=919503941 usec=691370
gettimeofday: Success
r=0 i=68 sec=919503941 usec=743723
delta=-50846 i=69 sec=919503941 usec=692877
gettimeofday: Success
r=0 i=71 sec=919503941 usec=744799
delta=-50632 i=72 sec=919503941 usec=694167
gettimeofday: Success
r=0 i=73 sec=919503941 usec=742442
delta=-49988 i=74 sec=919503941 usec=692454
gettimeofday: Success
r=0 i=75 sec=919503941 usec=740944
delta=-18963 i=76 sec=919503941 usec=721981
gettimeofday: Success
r=0 i=77 sec=919503941 usec=933937
delta=-48272 i=78 sec=919503941 usec=885665
gettimeofday: Success
r=0 i=89 sec=919503941 usec=933083
delta=-50848 i=90 sec=919503941 usec=882235
gettimeofday: Success
r=0 i=92 sec=919503941 usec=934802
delta=-50846 i=93 sec=919503941 usec=883956
gettimeofday: Success
r=0 i=94 sec=919503941 usec=932016
delta=-18748 i=95 sec=919503941 usec=913268
gettimeofday: Success
r=0 i=97 sec=919503941 usec=943698
delta=-50632 i=98 sec=919503941 usec=893066
gettimeofday: Success
r=0 i=100 sec=919503941 usec=944774
delta=-50847 i=101 sec=919503941 usec=893927
gettimeofday: Success
r=0 i=102 sec=919503941 usec=941130
delta=-49989 i=103 sec=919503941 usec=891141
gettimeofday: Success
r=0 i=105 sec=919503941 usec=943279
delta=-50847 i=106 sec=919503941 usec=892432
gettimeofday: Success
r=0 i=108 sec=919503941 usec=944569
delta=-50631 i=109 sec=919503941 usec=893938
gettimeofday: Success
r=0 i=110 sec=919503941 usec=941354
delta=-50203 i=111 sec=919503941 usec=891151
gettimeofday: Success
r=0 i=113 sec=919503941 usec=942860
delta=-50633 i=114 sec=919503941 usec=892227
gettimeofday: Success
r=0 i=115 sec=919503941 usec=941149
delta=-49774 i=116 sec=919503941 usec=891375
gettimeofday: Success
r=0 i=117 sec=919503941 usec=943942
delta=-50203 i=118 sec=919503941 usec=893739
gettimeofday: Success
r=0 i=119 sec=919503941 usec=941370
delta=-50203 i=120 sec=919503941 usec=891167
gettimeofday: Success
r=0 i=124 sec=919503941 usec=951979
delta=-50847 i=125 sec=919503941 usec=901132
gettimeofday: Success
r=0 i=126 sec=919503941 usec=952840
delta=-50202 i=127 sec=919503941 usec=902638
gettimeofday: Success
r=0 i=128 sec=919503941 usec=952200
delta=-50203 i=129 sec=919503941 usec=901997
gettimeofday: Success
r=0 i=130 sec=919503941 usec=950916
delta=-50203 i=131 sec=919503941 usec=900713
gettimeofday: Success
r=0 i=133 sec=919503941 usec=953923
delta=-50846 i=134 sec=919503941 usec=903077
gettimeofday: Success
r=0 i=136 sec=919503941 usec=954356
delta=-50847 i=137 sec=919503941 usec=903509
gettimeofday: Success
r=0 i=138 sec=919503941 usec=950926
delta=-50203 i=139 sec=919503941 usec=900723
gettimeofday: Success
r=0 i=141 sec=919503941 usec=952646
delta=-50633 i=142 sec=919503941 usec=902013
gettimeofday: Success
r=0 i=144 sec=919503941 usec=953722
delta=-50632 i=145 sec=919503941 usec=903090
gettimeofday: Success
r=0 i=147 sec=919503941 usec=955013
delta=-50847 i=148 sec=919503941 usec=904166
gettimeofday: Success
r=0 i=149 sec=919503941 usec=951583
delta=-50203 i=150 sec=919503941 usec=901380
gettimeofday: Success
r=0 i=152 sec=919503941 usec=952016
delta=-50633 i=153 sec=919503941 usec=901383
gettimeofday: Success
r=0 i=159 sec=919503941 usec=962410
delta=-50848 i=160 sec=919503941 usec=911562
gettimeofday: Success
r=0 i=162 sec=919503941 usec=963271
delta=-50632 i=163 sec=919503941 usec=912639
gettimeofday: Success
r=0 i=165 sec=919503941 usec=964347
delta=-50632 i=166 sec=919503941 usec=913715
gettimeofday: Success
r=0 i=168 sec=919503941 usec=964994
delta=-50632 i=169 sec=919503941 usec=914362
gettimeofday: Success
r=0 i=170 sec=919503941 usec=960707
delta=-50204 i=171 sec=919503941 usec=910503
gettimeofday: Success
r=0 i=174 sec=919503941 usec=965001
delta=-50846 i=175 sec=919503941 usec=914155
gettimeofday: Success
r=0 i=176 sec=919503941 usec=960928
delta=-49989 i=177 sec=919503941 usec=910939
gettimeofday: Success
r=0 i=179 sec=919503941 usec=962218
delta=-50632 i=180 sec=919503941 usec=911586
gettimeofday: Success
r=0 i=182 sec=919503941 usec=962222
delta=-50633 i=183 sec=919503941 usec=911589
gettimeofday: Success
r=0 i=185 sec=919503941 usec=962440
delta=-50847 i=186 sec=919503941 usec=911593
gettimeofday: Success
r=0 i=188 sec=919503941 usec=963730
delta=-50846 i=189 sec=919503941 usec=912884
gettimeofday: Success
r=0 i=195 sec=919503941 usec=972193
delta=-50847 i=196 sec=919503941 usec=921346
gettimeofday: Success
r=0 i=199 sec=919503941 usec=971982
delta=-50632 i=200 sec=919503941 usec=921350
gettimeofday: Success
r=0 i=211 sec=919503941 usec=973272
delta=-50846 i=212 sec=919503941 usec=922426
gettimeofday: Success
r=0 i=225 sec=919503941 usec=973274
delta=-50846 i=226 sec=919503941 usec=922428
gettimeofday: Success
r=0 i=239 sec=919503941 usec=972633
delta=-50847 i=240 sec=919503941 usec=921786
gettimeofday: Success
r=0 i=253 sec=919503941 usec=972207
delta=-50633 i=254 sec=919503941 usec=921574
gettimeofday: Success
r=0 i=267 sec=919503941 usec=971351
delta=-50633 i=268 sec=919503941 usec=920718
gettimeofday: Success
r=0 i=282 sec=919503941 usec=975001
delta=-50846 i=283 sec=919503941 usec=924155
gettimeofday: Success
r=0 i=296 sec=919503941 usec=973931
delta=-50632 i=297 sec=919503941 usec=923299
gettimeofday: Success
r=0 i=310 sec=919503941 usec=973504
delta=-50632 i=311 sec=919503941 usec=922872
gettimeofday: Success
r=0 i=324 sec=919503941 usec=972863
delta=-50847 i=325 sec=919503941 usec=922016
gettimeofday: Success
r=0 i=338 sec=919503941 usec=972222
delta=-50633 i=339 sec=919503941 usec=921589
gettimeofday: Success
r=0 i=352 sec=919503941 usec=971581
delta=-50847 i=353 sec=919503941 usec=920734
gettimeofday: Success
r=0 i=366 sec=919503941 usec=971798
delta=-50847 i=367 sec=919503941 usec=920951
gettimeofday: Success
r=0 i=380 sec=919503941 usec=971800
delta=-50632 i=381 sec=919503941 usec=921168
gettimeofday: Success
r=0 i=386 sec=919503941 usec=982407
delta=-50847 i=387 sec=919503941 usec=931560
gettimeofday: Success
r=0 i=399 sec=919503941 usec=983911
delta=-50846 i=400 sec=919503941 usec=933065
gettimeofday: Success
r=0 i=413 sec=919503941 usec=984128
delta=-50846 i=414 sec=919503941 usec=933282
gettimeofday: Success
r=0 i=427 sec=919503941 usec=983702
delta=-50846 i=428 sec=919503941 usec=932856
gettimeofday: Success
r=0 i=441 sec=919503941 usec=983490
delta=-50846 i=442 sec=919503941 usec=932644
gettimeofday: Success
r=0 i=455 sec=919503941 usec=982634
delta=-50847 i=456 sec=919503941 usec=931787
gettimeofday: Success
r=0 i=469 sec=919503941 usec=982637
delta=-50847 i=470 sec=919503941 usec=931790
gettimeofday: Success
r=0 i=483 sec=919503941 usec=981996
delta=-50848 i=484 sec=919503941 usec=931148
gettimeofday: Success
r=0 i=497 sec=919503941 usec=981783
delta=-50632 i=498 sec=919503941 usec=931151
gettimeofday: Success
r=0 i=511 sec=919503941 usec=981571
delta=-50847 i=512 sec=919503941 usec=930724
gettimeofday: Success
r=0 i=526 sec=919503941 usec=984792
delta=-50632 i=527 sec=919503941 usec=934160
gettimeofday: Success
r=0 i=540 sec=919503941 usec=984580
delta=-50632 i=541 sec=919503941 usec=933948
gettimeofday: Success
r=0 i=554 sec=919503941 usec=984154
delta=-50847 i=555 sec=919503941 usec=933307
gettimeofday: Success
r=0 i=568 sec=919503941 usec=983727
delta=-50632 i=569 sec=919503941 usec=933095
gettimeofday: Success
r=0 i=582 sec=919503941 usec=983300
delta=-50846 i=583 sec=919503941 usec=932454
gettimeofday: Success
r=0 i=596 sec=919503941 usec=983088
delta=-50846 i=597 sec=919503941 usec=932242
gettimeofday: Success
r=0 i=602 sec=919503941 usec=993695
delta=-50846 i=603 sec=919503941 usec=942849
gettimeofday: Success
r=0 i=615 sec=919503941 usec=991552
delta=-50847 i=616 sec=919503941 usec=940705
gettimeofday: Success
r=0 i=629 sec=919503941 usec=991984
delta=-50847 i=630 sec=919503941 usec=941137
gettimeofday: Success
r=0 i=643 sec=919503941 usec=992630
delta=-50847 i=644 sec=919503941 usec=941783
gettimeofday: Success
r=0 i=657 sec=919503941 usec=993276
delta=-50632 i=658 sec=919503941 usec=942644
gettimeofday: Success
r=0 i=671 sec=919503941 usec=994137
delta=-50632 i=672 sec=919503941 usec=943505
gettimeofday: Success
r=0 i=685 sec=919503941 usec=994998
delta=-50847 i=686 sec=919503941 usec=944151
gettimeofday: Success
r=0 i=698 sec=919503941 usec=991567
delta=-50847 i=699 sec=919503941 usec=940720
gettimeofday: Success
r=0 i=712 sec=919503941 usec=992857
delta=-50847 i=713 sec=919503941 usec=942010
gettimeofday: Success
r=0 i=726 sec=919503942 usec=373704
delta=-50847 i=727 sec=919503942 usec=322857
gettimeofday: Success
r=0 i=736 sec=919503942 usec=372635
delta=-50847 i=737 sec=919503942 usec=321788
gettimeofday: Success
r=0 i=738 sec=919503942 usec=370707
delta=-50203 i=739 sec=919503942 usec=320504
gettimeofday: Success
r=0 i=740 sec=919503942 usec=373073
delta=-49988 i=741 sec=919503942 usec=323085
gettimeofday: Success
r=0 i=741 sec=919503942 usec=323085
delta=-2572 i=742 sec=919503942 usec=320513
gettimeofday: Success
r=0 i=744 sec=919503942 usec=374582
delta=-50846 i=745 sec=919503942 usec=323736
gettimeofday: Success
r=0 i=746 sec=919503942 usec=372869
delta=-49988 i=747 sec=919503942 usec=322881
gettimeofday: Success
r=0 i=748 sec=919503942 usec=371585
delta=-50204 i=749 sec=919503942 usec=321381
gettimeofday: Success
r=0 i=755 sec=919503942 usec=384339
delta=-50847 i=756 sec=919503942 usec=333492
gettimeofday: Success
r=0 i=756 sec=919503942 usec=333492
delta=-2786 i=757 sec=919503942 usec=330706
gettimeofday: Success
r=0 i=766 sec=919503942 usec=379640
delta=-43337 i=767 sec=919503942 usec=336303
gettimeofday: Success
r=0 i=771 sec=919503942 usec=384793
delta=-50846 i=772 sec=919503942 usec=333947
gettimeofday: Success
r=0 i=773 sec=919503942 usec=384796
delta=-49988 i=774 sec=919503942 usec=334808
gettimeofday: Success
r=0 i=774 sec=919503942 usec=334808
delta=-3215 i=775 sec=919503942 usec=331593
gettimeofday: Success
r=0 i=786 sec=919503942 usec=382875
delta=-19431 i=787 sec=919503942 usec=363444
gettimeofday: Success
r=0 i=791 sec=919503942 usec=391981
delta=-50632 i=792 sec=919503942 usec=341349
gettimeofday: Success
r=0 i=793 sec=919503942 usec=392414
delta=-50203 i=794 sec=919503942 usec=342211
gettimeofday: Success
r=0 i=795 sec=919503942 usec=391773
delta=-49989 i=796 sec=919503942 usec=341784
gettimeofday: Success
r=0 i=798 sec=919503942 usec=394780
delta=-50846 i=799 sec=919503942 usec=343934
gettimeofday: Success
r=0 i=800 sec=919503942 usec=393282
delta=-50203 i=801 sec=919503942 usec=343079
gettimeofday: Success
r=0 i=802 sec=919503942 usec=393714
delta=-50202 i=803 sec=919503942 usec=343512
gettimeofday: Success
r=0 i=804 sec=919503942 usec=392001
delta=-49989 i=805 sec=919503942 usec=342012
gettimeofday: Success
r=0 i=806 sec=919503942 usec=390932
delta=-50203 i=807 sec=919503942 usec=340729
gettimeofday: Success
r=0 i=809 sec=919503942 usec=394368
delta=-50632 i=810 sec=919503942 usec=343736
gettimeofday: Success
r=0 i=811 sec=919503942 usec=393084
delta=-50202 i=812 sec=919503942 usec=342882
gettimeofday: Success
r=0 i=813 sec=919503942 usec=391586
delta=-50204 i=814 sec=919503942 usec=341382
gettimeofday: Success
r=0 i=817 sec=919503942 usec=403696
delta=-50846 i=818 sec=919503942 usec=352850
gettimeofday: Success
r=0 i=819 sec=919503942 usec=404343
delta=-50203 i=820 sec=919503942 usec=354140
gettimeofday: Success
r=0 i=821 sec=919503942 usec=403917
delta=-50202 i=822 sec=919503942 usec=353715
gettimeofday: Success
r=0 i=823 sec=919503942 usec=403277
delta=-49988 i=824 sec=919503942 usec=353289
gettimeofday: Success
r=0 i=825 sec=919503942 usec=402851
delta=-50202 i=826 sec=919503942 usec=352649
gettimeofday: Success
r=0 i=827 sec=919503942 usec=402855
delta=-49989 i=828 sec=919503942 usec=352866
gettimeofday: Success
r=0 i=829 sec=919503942 usec=403502
delta=-50203 i=830 sec=919503942 usec=353299
gettimeofday: Success
r=0 i=831 sec=919503942 usec=403076
delta=-50203 i=832 sec=919503942 usec=352873
gettimeofday: Success
r=0 i=833 sec=919503942 usec=402650
delta=-50203 i=834 sec=919503942 usec=352447
gettimeofday: Success
r=0 i=835 sec=919503942 usec=402010
delta=-49989 i=836 sec=919503942 usec=352021
gettimeofday: Success
r=0 i=837 sec=919503942 usec=403086
delta=-50203 i=838 sec=919503942 usec=352883
gettimeofday: Success

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/