BUG in check_monotonic_clock()

BUG in check_monotonic_clock()

[Daniel Walker]

This is off a dual P3 during boot with 2.6.15-rt6. I'll send the .config
privately . I had a fair amount of debugging on.


check_monotonic_clock: monotonic inconsistency detected!
        from        1a27e7384 (7021163396) to        19f92d748 (6972168008).
udev/238[CPU#1]: BUG in check_monotonic_clock at kernel/time/timeofday.c:160
 [<c0105b03>] dump_stack+0x23/0x30 (20)
 [<c0129e43>] __WARN_ON+0x63/0x80 (40)
 [<c0148584>] check_monotonic_clock+0xd4/0xe0 (52)
 [<c01489b8>] get_monotonic_clock+0xc8/0x100 (56)
 [<c014475d>] __hrtimer_start+0xdd/0x100 (40)
 [<c0400046>] schedule_hrtimer+0x46/0xd0 (48)
 [<c0144f0f>] hrtimer_nanosleep+0x5f/0x130 (104)
 [<c0145053>] sys_nanosleep+0x73/0x80 (36)
 [<c0104b2a>] syscall_call+0x7/0xb (-4020)
---------------------------
| preempt count: 00000002 ]
| 2-level deep critical section nesting:
----------------------------------------
.. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
.....[<c0143e2a>] ..   ( <= lock_hrtimer_base+0x2a/0x60)
.. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
.....[<c0129df6>] ..   ( <= __WARN_ON+0x16/0x80)

Re: BUG in check_monotonic_clock()

[George Anzinger]

[-- Attachment #1: Type: text/plain, Size: 1615 bytes --]

Daniel Walker wrote:
> 
> This is off a dual P3 during boot with 2.6.15-rt6. I'll send the .config
> privately . I had a fair amount of debugging on.

Has the attached patch been applied?  Fixed this for me....

George
-- 
> 
> 
> check_monotonic_clock: monotonic inconsistency detected!
>         from        1a27e7384 (7021163396) to        19f92d748 (6972168008).
> udev/238[CPU#1]: BUG in check_monotonic_clock at kernel/time/timeofday.c:160
>  [<c0105b03>] dump_stack+0x23/0x30 (20)
>  [<c0129e43>] __WARN_ON+0x63/0x80 (40)
>  [<c0148584>] check_monotonic_clock+0xd4/0xe0 (52)
>  [<c01489b8>] get_monotonic_clock+0xc8/0x100 (56)
>  [<c014475d>] __hrtimer_start+0xdd/0x100 (40)
>  [<c0400046>] schedule_hrtimer+0x46/0xd0 (48)
>  [<c0144f0f>] hrtimer_nanosleep+0x5f/0x130 (104)
>  [<c0145053>] sys_nanosleep+0x73/0x80 (36)
>  [<c0104b2a>] syscall_call+0x7/0xb (-4020)
> ---------------------------
> | preempt count: 00000002 ]
> | 2-level deep critical section nesting:
> ----------------------------------------
> .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> .....[<c0143e2a>] ..   ( <= lock_hrtimer_base+0x2a/0x60)
> .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> .....[<c0129df6>] ..   ( <= __WARN_ON+0x16/0x80)
> 
> 
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/
> 

-- 
George Anzinger   george@wildturkeyranch.net
HRT (High-res-timers):  http://sourceforge.net/projects/high-res-timers/

[-- Attachment #2: ktime_conversion.patch --]
[-- Type: text/plain, Size: 911 bytes --]

 kernel/time.c |   13 ++++++++-----
 1 files changed, 8 insertions(+), 5 deletions(-)

Index: linux-2.6.16-rc/kernel/time.c
===================================================================
--- linux-2.6.16-rc.orig/kernel/time.c
+++ linux-2.6.16-rc/kernel/time.c
@@ -702,16 +702,19 @@ void set_normalized_timespec(struct time
  *
  * Returns the timespec representation of the nsec parameter.
  */
-inline struct timespec ns_to_timespec(const nsec_t nsec)
+struct timespec ns_to_timespec(const nsec_t nsec)
 {
 	struct timespec ts;
 
-	if (nsec)
+	if (!nsec) return (struct timespec){0, 0};
+
+	if (nsec < 0) {
+		ts.tv_sec = div_long_long_rem_signed(-nsec, NSEC_PER_SEC,
+						     &ts.tv_nsec);
+		set_normalized_timespec(&ts, -ts.tv_sec, -ts.tv_nsec);
+	} else
 		ts.tv_sec = div_long_long_rem_signed(nsec, NSEC_PER_SEC,
 						     &ts.tv_nsec);
-	else
-		ts.tv_sec = ts.tv_nsec = 0;
-
 	return ts;
 }
 

Re: BUG in check_monotonic_clock()

[Daniel Walker]

No . I'll try it though .

Daniel


On Fri, 2006-01-20 at 10:07 -0800, George Anzinger wrote:
> Daniel Walker wrote:
> > 
> > This is off a dual P3 during boot with 2.6.15-rt6. I'll send the .config
> > privately . I had a fair amount of debugging on.
> 
> Has the attached patch been applied?  Fixed this for me....
> 
> George
> -- 
> > 
> > 
> > check_monotonic_clock: monotonic inconsistency detected!
> >         from        1a27e7384 (7021163396) to        19f92d748 (6972168008).
> > udev/238[CPU#1]: BUG in check_monotonic_clock at kernel/time/timeofday.c:160
> >  [<c0105b03>] dump_stack+0x23/0x30 (20)
> >  [<c0129e43>] __WARN_ON+0x63/0x80 (40)
> >  [<c0148584>] check_monotonic_clock+0xd4/0xe0 (52)
> >  [<c01489b8>] get_monotonic_clock+0xc8/0x100 (56)
> >  [<c014475d>] __hrtimer_start+0xdd/0x100 (40)
> >  [<c0400046>] schedule_hrtimer+0x46/0xd0 (48)
> >  [<c0144f0f>] hrtimer_nanosleep+0x5f/0x130 (104)
> >  [<c0145053>] sys_nanosleep+0x73/0x80 (36)
> >  [<c0104b2a>] syscall_call+0x7/0xb (-4020)
> > ---------------------------
> > | preempt count: 00000002 ]
> > | 2-level deep critical section nesting:
> > ----------------------------------------
> > .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> > .....[<c0143e2a>] ..   ( <= lock_hrtimer_base+0x2a/0x60)
> > .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> > .....[<c0129df6>] ..   ( <= __WARN_ON+0x16/0x80)
> > 
> > 
> > -
> > To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> > Please read the FAQ at  http://www.tux.org/lkml/
> > 
> 
> plain text document attachment (ktime_conversion.patch)
>  kernel/time.c |   13 ++++++++-----
>  1 files changed, 8 insertions(+), 5 deletions(-)
> 
> Index: linux-2.6.16-rc/kernel/time.c
> ===================================================================
> --- linux-2.6.16-rc.orig/kernel/time.c
> +++ linux-2.6.16-rc/kernel/time.c
> @@ -702,16 +702,19 @@ void set_normalized_timespec(struct time
>   *
>   * Returns the timespec representation of the nsec parameter.
>   */
> -inline struct timespec ns_to_timespec(const nsec_t nsec)
> +struct timespec ns_to_timespec(const nsec_t nsec)
>  {
>  	struct timespec ts;
>  
> -	if (nsec)
> +	if (!nsec) return (struct timespec){0, 0};
> +
> +	if (nsec < 0) {
> +		ts.tv_sec = div_long_long_rem_signed(-nsec, NSEC_PER_SEC,
> +						     &ts.tv_nsec);
> +		set_normalized_timespec(&ts, -ts.tv_sec, -ts.tv_nsec);
> +	} else
>  		ts.tv_sec = div_long_long_rem_signed(nsec, NSEC_PER_SEC,
>  						     &ts.tv_nsec);
> -	else
> -		ts.tv_sec = ts.tv_nsec = 0;
> -
>  	return ts;
>  }
>  

Re: BUG in check_monotonic_clock()

[john stultz]

On Fri, 2006-01-20 at 09:51 -0800, Daniel Walker wrote:
> 
> This is off a dual P3 during boot with 2.6.15-rt6. I'll send the .config
> privately . I had a fair amount of debugging on.
> 
> 
> check_monotonic_clock: monotonic inconsistency detected!
>         from        1a27e7384 (7021163396) to        19f92d748 (6972168008).
> udev/238[CPU#1]: BUG in check_monotonic_clock at kernel/time/timeofday.c:160
>  [<c0105b03>] dump_stack+0x23/0x30 (20)
>  [<c0129e43>] __WARN_ON+0x63/0x80 (40)
>  [<c0148584>] check_monotonic_clock+0xd4/0xe0 (52)
>  [<c01489b8>] get_monotonic_clock+0xc8/0x100 (56)
>  [<c014475d>] __hrtimer_start+0xdd/0x100 (40)
>  [<c0400046>] schedule_hrtimer+0x46/0xd0 (48)
>  [<c0144f0f>] hrtimer_nanosleep+0x5f/0x130 (104)
>  [<c0145053>] sys_nanosleep+0x73/0x80 (36)
>  [<c0104b2a>] syscall_call+0x7/0xb (-4020)
> ---------------------------
> | preempt count: 00000002 ]
> | 2-level deep critical section nesting:
> ----------------------------------------
> .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> .....[<c0143e2a>] ..   ( <= lock_hrtimer_base+0x2a/0x60)
> .. [<c014cf1c>] .... add_preempt_count+0x1c/0x20
> .....[<c0129df6>] ..   ( <= __WARN_ON+0x16/0x80)

Hey Daniel,
	Thanks for the bug report. Could you tell me what clocksource was being
used at the time? I'm guessing its the TSC, but usually we'll see
separate TSC inconsistency messages in the log.

thanks
-john

Re: BUG in check_monotonic_clock()

[Daniel Walker]

On Fri, 2006-01-20 at 10:38 -0800, john stultz wrote:

> Hey Daniel,
> 	Thanks for the bug report. Could you tell me what clocksource was being
> used at the time? I'm guessing its the TSC, but usually we'll see
> separate TSC inconsistency messages in the log.
> 
> thanks
> -john
> 

I had CONFIG_HPET_TIMER turned on. Also X86_TSC was on. 

Daniel

Re: BUG in check_monotonic_clock()

[john stultz]

On Fri, 2006-01-20 at 10:48 -0800, Daniel Walker wrote:
> On Fri, 2006-01-20 at 10:38 -0800, john stultz wrote:
> 
> > Hey Daniel,
> > 	Thanks for the bug report. Could you tell me what clocksource was being
> > used at the time? I'm guessing its the TSC, but usually we'll see
> > separate TSC inconsistency messages in the log.
> > 
> > thanks
> > -john
> > 
> 
> I had CONFIG_HPET_TIMER turned on. Also X86_TSC was on. 

So, booting up the box, what is the last message that looks like:

	Time: xyz clocksource has been installed.


thanks
-john

Re: BUG in check_monotonic_clock()

[Daniel Walker]

On Fri, 2006-01-20 at 10:52 -0800, john stultz wrote:
> On Fri, 2006-01-20 at 10:48 -0800, Daniel Walker wrote:
> > On Fri, 2006-01-20 at 10:38 -0800, john stultz wrote:
> > 
> > > Hey Daniel,
> > > 	Thanks for the bug report. Could you tell me what clocksource was being
> > > used at the time? I'm guessing its the TSC, but usually we'll see
> > > separate TSC inconsistency messages in the log.
> > > 
> > > thanks
> > > -john
> > > 
> > 
> > I had CONFIG_HPET_TIMER turned on. Also X86_TSC was on. 
> 
> So, booting up the box, what is the last message that looks like:
> 
> 	Time: xyz clocksource has been installed.

Last one is,
kernel: Time: tsc clocksource has been installed.

Isn't there a handy proc entry for this? 

Like /proc/sys/kernel/clocksource ?

Daniel

Re: BUG in check_monotonic_clock()

[john stultz]

On Fri, 2006-01-20 at 11:02 -0800, Daniel Walker wrote:
> On Fri, 2006-01-20 at 10:52 -0800, john stultz wrote:
> > On Fri, 2006-01-20 at 10:48 -0800, Daniel Walker wrote:
> > > On Fri, 2006-01-20 at 10:38 -0800, john stultz wrote:
> > > 
> > > > Hey Daniel,
> > > > 	Thanks for the bug report. Could you tell me what clocksource was being
> > > > used at the time? I'm guessing its the TSC, but usually we'll see
> > > > separate TSC inconsistency messages in the log.
> > > > 
> > > > thanks
> > > > -john
> > > > 
> > > 
> > > I had CONFIG_HPET_TIMER turned on. Also X86_TSC was on. 
> > 
> > So, booting up the box, what is the last message that looks like:
> > 
> > 	Time: xyz clocksource has been installed.
> 
> Last one is,
> kernel: Time: tsc clocksource has been installed.

That's what I was guessing. So there aren't any TSC inconsistency
messages in the dmesg? Odd.


> Isn't there a handy proc entry for this? 

Yep, there's a sysfs entry:

	/sys/devices/system/clocksource/clocksource0/current_clocksource 

thanks
-john

Re: BUG in check_monotonic_clock()

[Daniel Walker]

On Fri, 2006-01-20 at 11:09 -0800, john stultz wrote:

> That's what I was guessing. So there aren't any TSC inconsistency
> messages in the dmesg? Odd.

I didn't see any ..

> 
> > Isn't there a handy proc entry for this? 
> 
> Yep, there's a sysfs entry:
> 
> 	/sys/devices/system/clocksource/clocksource0/current_clocksource 

Great! The patch that George sent me fixed it .. Thanks George !

Daniel

Re: BUG in check_monotonic_clock()

[john stultz]

On Fri, 2006-01-20 at 11:23 -0800, Daniel Walker wrote:
> Great! The patch that George sent me fixed it .. Thanks George !

Good to hear!

George, mind sending that patch to Andrew?

thanks
-john

Re: BUG in check_monotonic_clock()

[George Anzinger]

Daniel Walker wrote:
> On Fri, 2006-01-20 at 11:09 -0800, john stultz wrote:
> 
> 
>>That's what I was guessing. So there aren't any TSC inconsistency
>>messages in the dmesg? Odd.
> 
> 
> I didn't see any ..
> 
> 
>>>Isn't there a handy proc entry for this? 
>>
>>Yep, there's a sysfs entry:
>>
>>	/sys/devices/system/clocksource/clocksource0/current_clocksource 
> 
> 
> Great! The patch that George sent me fixed it .. Thanks George !

By the way, this means you are using a 64-bit ktime and not the dual 32-bit 
ktime.  This _may_ not be what you want on a 32-bit kernel.  There is a 
config option to change this....

-- 
George Anzinger   george@wildturkeyranch.net
HRT (High-res-timers):  http://sourceforge.net/projects/high-res-timers/