Hi,
We've been seeing some strange behaviour on some of our applications
recently. I've tracked this down to gettimeofday() returning spurious
values occasionally.
Specifically, gettimeofday() will suddenly, for a single call, return
a value about 4398 seconds (~1 hour 13 minutes) in the future. The
following call goes back to a normal value.
This seems to be occurring when the clock source goes slightly
backwards for a single call. In
kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
So a small decrease in time here will (this is all unsigned
arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
this by some value, then right shifts by 22. The resulting value (in
nanoseconds) is approximately 4398 seconds; this gets added on to the
xtime value, giving us our jump into the future. The next call to
gettimeofday() returns to normal as we don't have this huge nanosecond
offset.
This system is a 2-socket core 2 quad machine (8 cpus), running 32 bit
mode. It's a dell poweredge 1950. The kernel selects the TSC as the
clock source, having determined that the tsc runs synchronously on
this system. Switching the systems to use a different time source
seems to make the problem go away (which is fine for us, but we'd like
to get this fixed properly upstream).
We've also seen this behaviour with a synthetic test program (which
just runs 4 threads all calling gettimeofday() in a loop as fast as
possible and testing that it doesn't jump) on an older machine, a dell
poweredge SC1425 with two p4 hyperthreaded xeons.
Can anyone advise on what's going wrong here? I can't find much in the
way of documentation on whether the TSC is guaranteed to be
monotonically increasing on intel systems. Should the code choose not
to use the TSC? Or should the TSC reading code ensure that the
returned values are monotonic?
Is there any more information that would be useful? I'll be on a plane
for most of tomorrow, so might be a little slow responding.
Thanks,
Mike
[ CCs added ]
On Thu, 2007-08-23 at 13:08 +0200, Michael Smith wrote:
> Hi,
>
> We've been seeing some strange behaviour on some of our applications
> recently. I've tracked this down to gettimeofday() returning spurious
> values occasionally.
>
> Specifically, gettimeofday() will suddenly, for a single call, return
> a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> following call goes back to a normal value.
>
> This seems to be occurring when the clock source goes slightly
> backwards for a single call. In
> kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
>
> So a small decrease in time here will (this is all unsigned
> arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> this by some value, then right shifts by 22. The resulting value (in
> nanoseconds) is approximately 4398 seconds; this gets added on to the
> xtime value, giving us our jump into the future. The next call to
> gettimeofday() returns to normal as we don't have this huge nanosecond
> offset.
>
> This system is a 2-socket core 2 quad machine (8 cpus), running 32 bit
> mode. It's a dell poweredge 1950. The kernel selects the TSC as the
> clock source, having determined that the tsc runs synchronously on
> this system. Switching the systems to use a different time source
> seems to make the problem go away (which is fine for us, but we'd like
> to get this fixed properly upstream).
>
> We've also seen this behaviour with a synthetic test program (which
> just runs 4 threads all calling gettimeofday() in a loop as fast as
> possible and testing that it doesn't jump) on an older machine, a dell
> poweredge SC1425 with two p4 hyperthreaded xeons.
>
> Can anyone advise on what's going wrong here? I can't find much in the
> way of documentation on whether the TSC is guaranteed to be
> monotonically increasing on intel systems. Should the code choose not
> to use the TSC? Or should the TSC reading code ensure that the
> returned values are monotonic?
>
> Is there any more information that would be useful? I'll be on a plane
> for most of tomorrow, so might be a little slow responding.
The exact version of the kernel you're using might be good thing to
start with :-)
On 8/23/07, Peter Zijlstra <[email protected]> wrote:
> [ CCs added ]
>
> On Thu, 2007-08-23 at 13:08 +0200, Michael Smith wrote:
> > Hi,
> >
> > We've been seeing some strange behaviour on some of our applications
> > recently. I've tracked this down to gettimeofday() returning spurious
> > values occasionally.
> >
> > Specifically, gettimeofday() will suddenly, for a single call, return
> > a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> > following call goes back to a normal value.
> >
> > This seems to be occurring when the clock source goes slightly
> > backwards for a single call. In
> > kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> > cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> >
> > So a small decrease in time here will (this is all unsigned
> > arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> > this by some value, then right shifts by 22. The resulting value (in
> > nanoseconds) is approximately 4398 seconds; this gets added on to the
> > xtime value, giving us our jump into the future. The next call to
> > gettimeofday() returns to normal as we don't have this huge nanosecond
> > offset.
> >
> > This system is a 2-socket core 2 quad machine (8 cpus), running 32 bit
> > mode. It's a dell poweredge 1950. The kernel selects the TSC as the
> > clock source, having determined that the tsc runs synchronously on
> > this system. Switching the systems to use a different time source
> > seems to make the problem go away (which is fine for us, but we'd like
> > to get this fixed properly upstream).
> >
> > We've also seen this behaviour with a synthetic test program (which
> > just runs 4 threads all calling gettimeofday() in a loop as fast as
> > possible and testing that it doesn't jump) on an older machine, a dell
> > poweredge SC1425 with two p4 hyperthreaded xeons.
> >
> > Can anyone advise on what's going wrong here? I can't find much in the
> > way of documentation on whether the TSC is guaranteed to be
> > monotonically increasing on intel systems. Should the code choose not
> > to use the TSC? Or should the TSC reading code ensure that the
> > returned values are monotonic?
> >
> > Is there any more information that would be useful? I'll be on a plane
> > for most of tomorrow, so might be a little slow responding.
>
> The exact version of the kernel you're using might be good thing to
> start with :-)
My apologies. It's always the obvious things one forgets to put in...
This was originally seen on an FC5 system running:
2.6.18-1.2257.fc5smp
We've reproduced it on the same system with a kernel built from
linus's git tree yesterday: 2.6.23-rc3.
Mike
On Thu, Aug 23, 2007 at 01:08:27PM +0200, Michael Smith wrote:
> Hi,
>
> We've been seeing some strange behaviour on some of our applications
> recently. I've tracked this down to gettimeofday() returning spurious
> values occasionally.
>
> Specifically, gettimeofday() will suddenly, for a single call, return
> a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> following call goes back to a normal value.
I have seen this as well (on a 2.6.20.4 kernel). The value returned was
always identical each time the glitch occured (just a little over 4398
seconds). I saw it watching packet receive timestamps and on the system in
question, it would generally hit this problem around once a minute. When
moving forward to a 2.6.21 kernel, the problem seemed to go away (also back
to 2.6.17, unfortunately I didn't have any sample points inbetween).
I didn't have free time to spend bisecting attempting to find when the
behavior started or stopped.
The hardware in this case was an HP Proliant DL380 G5 with two dueal-core
Core2 processors and was using the tsc as timesource.
-- Gerald
> This seems to be occurring when the clock source goes slightly
> backwards for a single call. In
> kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
>
> So a small decrease in time here will (this is all unsigned
> arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> this by some value, then right shifts by 22. The resulting value (in
> nanoseconds) is approximately 4398 seconds; this gets added on to the
> xtime value, giving us our jump into the future. The next call to
> gettimeofday() returns to normal as we don't have this huge nanosecond
> offset.
>
> This system is a 2-socket core 2 quad machine (8 cpus), running 32 bit
> mode. It's a dell poweredge 1950. The kernel selects the TSC as the
> clock source, having determined that the tsc runs synchronously on
> this system. Switching the systems to use a different time source
> seems to make the problem go away (which is fine for us, but we'd like
> to get this fixed properly upstream).
>
> We've also seen this behaviour with a synthetic test program (which
> just runs 4 threads all calling gettimeofday() in a loop as fast as
> possible and testing that it doesn't jump) on an older machine, a dell
> poweredge SC1425 with two p4 hyperthreaded xeons.
>
> Can anyone advise on what's going wrong here? I can't find much in the
> way of documentation on whether the TSC is guaranteed to be
> monotonically increasing on intel systems. Should the code choose not
> to use the TSC? Or should the TSC reading code ensure that the
> returned values are monotonic?
>
> Is there any more information that would be useful? I'll be on a plane
> for most of tomorrow, so might be a little slow responding.
>
> Thanks,
>
> Mike
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
>
Gerald Britton wrote:
> On Thu, Aug 23, 2007 at 01:08:27PM +0200, Michael Smith wrote:
>
>> Hi,
>>
>> We've been seeing some strange behaviour on some of our applications
>> recently. I've tracked this down to gettimeofday() returning spurious
>> values occasionally.
>>
>> Specifically, gettimeofday() will suddenly, for a single call, return
>> a value about 4398 seconds (~1 hour 13 minutes) in the future. The
>> following call goes back to a normal value.
>>
>
> I have seen this as well (on a 2.6.20.4 kernel). The value returned was
> always identical each time the glitch occured (just a little over 4398
> seconds). I saw it watching packet receive timestamps and on the system in
> question, it would generally hit this problem around once a minute. When
> moving forward to a 2.6.21 kernel, the problem seemed to go away (also back
> to 2.6.17, unfortunately I didn't have any sample points inbetween).
> I didn't have free time to spend bisecting attempting to find when the
> behavior started or stopped.
>
>
That value, in nanoseconds, is 0x3fffd3a4c00. The next second is
0x40038d51600. Is the wraparound at (0x400 << 32) significant?
--
error compiling committee.c: too many arguments to function
On Thu, 2007-08-23 at 14:20 +0200, Michael Smith wrote:
> On 8/23/07, Peter Zijlstra <[email protected]> wrote:
> > On Thu, 2007-08-23 at 13:08 +0200, Michael Smith wrote:
> > > We've been seeing some strange behaviour on some of our applications
> > > recently. I've tracked this down to gettimeofday() returning spurious
> > > values occasionally.
> > >
> > > Specifically, gettimeofday() will suddenly, for a single call, return
> > > a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> > > following call goes back to a normal value.
> > >
> > > This seems to be occurring when the clock source goes slightly
> > > backwards for a single call. In
> > > kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> > > cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> > >
> > > So a small decrease in time here will (this is all unsigned
> > > arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> > > this by some value, then right shifts by 22. The resulting value (in
> > > nanoseconds) is approximately 4398 seconds; this gets added on to the
> > > xtime value, giving us our jump into the future. The next call to
> > > gettimeofday() returns to normal as we don't have this huge nanosecond
> > > offset.
> > >
> > > This system is a 2-socket core 2 quad machine (8 cpus), running 32 bit
> > > mode. It's a dell poweredge 1950. The kernel selects the TSC as the
> > > clock source, having determined that the tsc runs synchronously on
> > > this system. Switching the systems to use a different time source
> > > seems to make the problem go away (which is fine for us, but we'd like
> > > to get this fixed properly upstream).
Hmm. That does sound like unsycned TSCs. Normally Intel systems don't
skew unless they are NUMA systems or you're entering low power states.
We try to catch both of those cases, so I'm not sure how you box is
slipping through.
Can you run the following test to verify that the TSCs are skewed?
thanks
-john
Gerald Britton wrote:
> I have seen this as well (on a 2.6.20.4 kernel). The value returned was
> always identical each time the glitch occured (just a little over 4398
> seconds).
I would guess an off by 2^32 error is at play.
-hpa
Avi Kivity wrote:
> Gerald Britton wrote:
>> On Thu, Aug 23, 2007 at 01:08:27PM +0200, Michael Smith wrote:
>>
>>> Hi,
>>>
>>> We've been seeing some strange behaviour on some of our applications
>>> recently. I've tracked this down to gettimeofday() returning spurious
>>> values occasionally.
>>>
>>> Specifically, gettimeofday() will suddenly, for a single call, return
>>> a value about 4398 seconds (~1 hour 13 minutes) in the future. The
>>> following call goes back to a normal value.
>>>
>>
>> I have seen this as well (on a 2.6.20.4 kernel). The value returned was
>> always identical each time the glitch occured (just a little over 4398
>> seconds). I saw it watching packet receive timestamps and on the
>> system in
>> question, it would generally hit this problem around once a minute. When
>> moving forward to a 2.6.21 kernel, the problem seemed to go away (also
>> back
>> to 2.6.17, unfortunately I didn't have any sample points inbetween).
>> I didn't have free time to spend bisecting attempting to find when the
>> behavior started or stopped.
>
> That value, in nanoseconds, is 0x3fffd3a4c00. The next second is
> 0x40038d51600. Is the wraparound at (0x400 << 32) significant?
>
This would be consistent with an off-by-2^32 error. In particular, if
either a CPU bug or a code bug could at some point produce 0x400fxxxxxxx
in between then that would produce exactly the observed characteristics.
-hpa
>
> Hmm. That does sound like unsycned TSCs. Normally Intel systems don't
> skew unless they are NUMA systems or you're entering low power states.
> We try to catch both of those cases, so I'm not sure how you box is
> slipping through.
>
> Can you run the following test to verify that the TSCs are skewed?
I ran this for the past two days, multiple copies to put some load on
the system (the initial problem with gettimeofday() was easier to
reproduce under load). Nothing.
So, I guess that rules out unsynced TSCs as the cause? Or perhaps it
only happens in other conditions, for some reason. I'm on holidays
right now, but my coworkers should be able to continue investigating
other possible causes.
Thanks for the advice/test program.
Mike
On Thu, 23 Aug 2007, Michael Smith wrote:
> We've been seeing some strange behaviour on some of our applications
> recently. I've tracked this down to gettimeofday() returning spurious
> values occasionally.
>
> Specifically, gettimeofday() will suddenly, for a single call, return
> a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> following call goes back to a normal value.
I have also seen this.
> This seems to be occurring when the clock source goes slightly
> backwards for a single call. In
> kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
>
> So a small decrease in time here will (this is all unsigned
> arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> this by some value, then right shifts by 22. The resulting value (in
> nanoseconds) is approximately 4398 seconds; this gets added on to the
> xtime value, giving us our jump into the future. The next call to
> gettimeofday() returns to normal as we don't have this huge nanosecond
> offset.
Indeed. I don't know where the suggestion of off by 2^32us came in
later in this thread. As you've already pointed out, it's off by
2^42ns.
I've no idea why the TSC might go backwards, but perhaps we should not
break horribly if it does. How about treating it as zero?
diff -urN linux-2.6.24.4/include/linux/clocksource.h linux/include/linux/clocksource.h
--- linux-2.6.24.4/include/linux/clocksource.h 2008-03-24 18:49:18.000000000 +0000
+++ linux/include/linux/clocksource.h 2008-03-28 11:15:02.000000000 +0000
@@ -176,7 +176,7 @@
*
* XXX - This could use some mult_lxl_ll() asm optimization
*/
-static inline s64 cyc2ns(struct clocksource *cs, cycle_t cycles)
+static inline u64 cyc2ns(struct clocksource *cs, cycle_t cycles)
{
u64 ret = (u64)cycles;
ret = (ret * cs->mult) >> cs->shift;
diff -urN linux-2.6.24.4/kernel/time/timekeeping.c linux/kernel/time/timekeeping.c
--- linux-2.6.24.4/kernel/time/timekeeping.c 2008-03-24 18:49:18.000000000 +0000
+++ linux/kernel/time/timekeeping.c 2008-03-28 11:15:01.000000000 +0000
@@ -64,14 +64,17 @@
* called. Returns the number of nanoseconds since the
* last call to update_wall_time() (adjusted by NTP scaling)
*/
-static inline s64 __get_nsec_offset(void)
+static inline u64 __get_nsec_offset(void)
{
cycle_t cycle_now, cycle_delta;
- s64 ns_offset;
+ u64 ns_offset;
/* read clocksource: */
cycle_now = clocksource_read(clock);
+ if (cycle_now < clock->cycle_last)
+ return 0;
+
/* calculate the delta since the last update_wall_time: */
cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
@@ -91,7 +94,7 @@
static inline void __get_realtime_clock_ts(struct timespec *ts)
{
unsigned long seq;
- s64 nsecs;
+ u64 nsecs;
do {
seq = read_seqbegin(&xtime_lock);
@@ -207,7 +210,7 @@
}
#else
static inline void change_clocksource(void) { }
-static inline s64 __get_nsec_offset(void) { return 0; }
+static inline u64 __get_nsec_offset(void) { return 0; }
#endif
/**
@@ -272,7 +275,7 @@
/* time in seconds when suspend began */
static unsigned long timekeeping_suspend_time;
/* xtime offset when we went into suspend */
-static s64 timekeeping_suspend_nsecs;
+static u64 timekeeping_suspend_nsecs;
/**
* timekeeping_resume - Resumes the generic timekeeping subsystem.
Alternatively, we could try to make it work and have gettimeofday jump
back slightly in this case, but I don't like this as much, because I
think it's more complicated, slower and unnecessary.
diff -urN linux-2.6.24.4/arch/x86/vdso/vclock_gettime.c linux/arch/x86/vdso/vclock_gettime.c
--- linux-2.6.24.4/arch/x86/vdso/vclock_gettime.c 2008-03-24 18:49:18.000000000 +0000
+++ linux/arch/x86/vdso/vclock_gettime.c 2008-03-28 12:15:24.000000000 +0000
@@ -43,7 +43,8 @@
static noinline int do_realtime(struct timespec *ts)
{
- unsigned long seq, ns;
+ unsigned long seq;
+ long ns;
do {
seq = read_seqbegin(>od->lock);
ts->tv_sec = gtod->wall_time_sec;
diff -urN linux-2.6.24.4/include/linux/clocksource.h linux/include/linux/clocksource.h
--- linux-2.6.24.4/include/linux/clocksource.h 2008-03-24 18:49:18.000000000 +0000
+++ linux/include/linux/clocksource.h 2008-03-28 11:59:05.000000000 +0000
@@ -176,11 +176,9 @@
*
* XXX - This could use some mult_lxl_ll() asm optimization
*/
-static inline s64 cyc2ns(struct clocksource *cs, cycle_t cycles)
+static inline s64 cyc2ns(struct clocksource *cs, s64 cycles)
{
- u64 ret = (u64)cycles;
- ret = (ret * cs->mult) >> cs->shift;
- return ret;
+ return (cycles * cs->mult) >> cs->shift;
}
/**
diff -urN linux-2.6.24.4/include/linux/time.h linux/include/linux/time.h
--- linux-2.6.24.4/include/linux/time.h 2008-03-24 18:49:18.000000000 +0000
+++ linux/include/linux/time.h 2008-03-28 11:59:06.000000000 +0000
@@ -169,13 +169,17 @@
* @a: pointer to timespec to be incremented
* @ns: unsigned nanoseconds value to be added
*/
-static inline void timespec_add_ns(struct timespec *a, u64 ns)
+static inline void timespec_add_ns(struct timespec *a, s64 ns)
{
ns += a->tv_nsec;
while(unlikely(ns >= NSEC_PER_SEC)) {
ns -= NSEC_PER_SEC;
a->tv_sec++;
}
+ while(unlikely(ns < 0)) {
+ ns += NSEC_PER_SEC;
+ a->tv_sec--;
+ }
a->tv_nsec = ns;
}
#endif /* __KERNEL__ */
diff -urN linux-2.6.24.4/kernel/time/timekeeping.c linux/kernel/time/timekeeping.c
--- linux-2.6.24.4/kernel/time/timekeeping.c 2008-03-24 18:49:18.000000000 +0000
+++ linux/kernel/time/timekeeping.c 2008-03-28 12:31:48.000000000 +0000
@@ -47,7 +47,7 @@
static unsigned long total_sleep_time; /* seconds */
static struct timespec xtime_cache __attribute__ ((aligned (16)));
-static inline void update_xtime_cache(u64 nsec)
+static inline void update_xtime_cache(s64 nsec)
{
xtime_cache = xtime;
timespec_add_ns(&xtime_cache, nsec);
@@ -66,8 +66,8 @@
*/
static inline s64 __get_nsec_offset(void)
{
- cycle_t cycle_now, cycle_delta;
- s64 ns_offset;
+ cycle_t cycle_now;
+ s64 ns_offset, cycle_delta;
/* read clocksource: */
cycle_now = clocksource_read(clock);
@@ -75,6 +75,12 @@
/* calculate the delta since the last update_wall_time: */
cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
+ /* Sign-extend. */
+ if (cycle_now < clock->cycle_last)
+ {
+ cycle_delta |= ~clock->mask;
+ }
+
/* convert to nanoseconds: */
ns_offset = cyc2ns(clock, cycle_delta);
@@ -182,7 +188,7 @@
{
struct clocksource *new;
cycle_t now;
- u64 nsec;
+ s64 nsec;
new = clocksource_get_next();
@@ -455,7 +461,17 @@
return;
#ifdef CONFIG_GENERIC_TIME
- offset = (clocksource_read(clock) - clock->cycle_last) & clock->mask;
+ offset = clocksource_read(clock) - clock->cycle_last;
+
+ /* Mask but preserving sign. */
+ if (offset < 0)
+ {
+ offset = (offset & clock->mask) | ~clock->mask;
+ }
+ else
+ {
+ offset &= clock->mask;
+ }
#else
offset = clock->cycle_interval;
#endif
@@ -464,7 +480,7 @@
/* normally this loop will run just once, however in the
* case of lost or late ticks, it will accumulate correctly.
*/
- while (offset >= clock->cycle_interval) {
+ while (offset >= (s64)clock->cycle_interval) {
/* accumulate one interval */
clock->xtime_nsec += clock->xtime_interval;
clock->cycle_last += clock->cycle_interval;
--
Tim
Quidquid latine dictum sit, altum viditur.
Tim Ricketts <[email protected]> writes:
[adding right people to cc just in case it slipped past their filters,
keeping enough quote for context]
> On Thu, 23 Aug 2007, Michael Smith wrote:
>
> > We've been seeing some strange behaviour on some of our applications
> > recently. I've tracked this down to gettimeofday() returning spurious
> > values occasionally.
> >
> > Specifically, gettimeofday() will suddenly, for a single call, return
> > a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> > following call goes back to a normal value.
>
> I have also seen this.
>
> > This seems to be occurring when the clock source goes slightly
> > backwards for a single call. In
> > kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> > cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> >
> > So a small decrease in time here will (this is all unsigned
> > arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> > this by some value, then right shifts by 22. The resulting value (in
> > nanoseconds) is approximately 4398 seconds; this gets added on to the
> > xtime value, giving us our jump into the future. The next call to
> > gettimeofday() returns to normal as we don't have this huge nanosecond
> > offset.
>
> Indeed. I don't know where the suggestion of off by 2^32us came in
> later in this thread. As you've already pointed out, it's off by
> 2^42ns.
[...]
> +static inline u64 __get_nsec_offset(void)
> {
> cycle_t cycle_now, cycle_delta;
> - s64 ns_offset;
> + u64 ns_offset;
>
> /* read clocksource: */
> cycle_now = clocksource_read(clock);
>
> + if (cycle_now < clock->cycle_last)
> + return 0;
The old x86-64 pre-clocksource gettimeofday() implementation had a similar
check. It came from painful experience.
-Andi
On Sun, 30 Mar 2008, Tim Ricketts wrote:
> On Thu, 23 Aug 2007, Michael Smith wrote:
>
> > We've been seeing some strange behaviour on some of our applications
> > recently. I've tracked this down to gettimeofday() returning spurious
> > values occasionally.
> >
> > Specifically, gettimeofday() will suddenly, for a single call, return
> > a value about 4398 seconds (~1 hour 13 minutes) in the future. The
> > following call goes back to a normal value.
>
> I have also seen this.
>
> > This seems to be occurring when the clock source goes slightly
> > backwards for a single call. In
> > kernel/time/timekeeping.c:__get_nsec_offset(), we have this:
> > cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> >
> > So a small decrease in time here will (this is all unsigned
> > arithmetic) give us a very large cycle_delta. cyc2ns() then multiplies
> > this by some value, then right shifts by 22. The resulting value (in
> > nanoseconds) is approximately 4398 seconds; this gets added on to the
> > xtime value, giving us our jump into the future. The next call to
> > gettimeofday() returns to normal as we don't have this huge nanosecond
> > offset.
>
> Indeed. I don't know where the suggestion of off by 2^32us came in
> later in this thread. As you've already pointed out, it's off by
> 2^42ns.
>
> I've no idea why the TSC might go backwards, but perhaps we should not
> break horribly if it does. How about treating it as zero?
> + if (cycle_now < clock->cycle_last)
> + return 0;
> +
No, this breaks wrapping clocksources e.g. pmtimer. We need a
different sanity check for that TSC crap.
Thanks,
tglx
On Mon, 2008-03-31 at 10:55 +0200, Thomas Gleixner wrote:
>
> > + if (cycle_now < clock->cycle_last)
> > + return 0;
> > +
>
> No, this breaks wrapping clocksources e.g. pmtimer. We need a
> different sanity check for that TSC crap.
Yea. If you're going to do that sort of logic (which requires a costly
cmpxchg as well), it should be done in the read() function of the
clocksource.
thanks
-john