Re: 2.6.14-rc4-rt7

[William Weston <weston@lysdexia.org>]

On Wed, 26 Oct 2005, Rui Nuno Capela wrote:

> Just noticed a couple or more of this on dmesg. Maybe its old news and 
> being discussed already. Otherwise my P4@2.53Ghz/UP laptop boots and 
> runs without hicups on 2.6.14-rc5-rt7 (config.gz attached).
> 
> ... time warped from 13551912584 to 13551905960.
> ... system time:     13488892865 .. 13488892865.
> udevstart/1579[CPU#0]: BUG in get_monotonic_clock_ts at 
> kernel/time/timeofday.c:
> 262
>   [<c0116fcb>] __WARN_ON+0x4f/0x6c (8)
>   [<c012f8b0>] get_monotonic_clock_ts+0x27a/0x2f0 (40)
>   [<c0141c9d>] kmem_cache_alloc+0x51/0xac (76)
>   [<c0114826>] copy_process+0x2ff/0xeed (44)
>   [<c0139444>] unlock_page+0x17/0x4a (12)
>   [<c0147a8a>] do_wp_page+0x245/0x372 (20)
>   [<c01154f5>] do_fork+0x69/0x1b5 (56)
>   [<c02c120b>] do_page_fault+0x432/0x543 (32)
>   [<c01017aa>] sys_clone+0x32/0x36 (72)
>   [<c0102a9b>] sysenter_past_esp+0x54/0x75 (16)

I'm getting these with two different machines running 2.6.14-rc5-rt7 with
Steven's ktimer_interrupt() patch from yesterday.  Did not see these with
previous -rt kernels.  Shutting down NTP makes no difference.

This is from the athlon-xp/via-kt400 box (xeon smt box looks similar):

... time warped from 945167068424 to 945167068179.
... system time:     945133952528 .. 945133952528.
crond/2584[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c011600f>] activate_task+0x5f/0x70 (12)
 [<c011a12b>] do_fork+0x6b/0x1f0 (68)
 [<c0335285>] __schedule+0x365/0x6b0 (24)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (32)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)
... time warped from 6853686562624 to 6853686562329.
... system time:     6853631273662 .. 6853631273662.
top/3207[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c0198cde>] uptime_read_proc+0x2e/0xd0 (84)
 [<c01411a5>] audit_filter_syscall+0x45/0xd0 (28)
 [<c0198cb0>] uptime_read_proc+0x0/0xd0 (20)
 [<c0196740>] proc_file_read+0x1a0/0x250 (16)
 [<c01965a0>] proc_file_read+0x0/0x250 (48)
 [<c0163ce6>] vfs_read+0xb6/0x170 (4)
 [<c0164071>] sys_read+0x41/0x70 (24)
 [<c0102ddd>] syscall_call+0x7/0xb (28)
... time warped from 8420727047178 to 8420727046873.
... system time:     8420661679983 .. 8420661679983.
wget/3250[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c012dcc0>] posix_ktime_get_ts+0x0/0x10 (68)
 [<c0133790>] ktimer_get_res+0x0/0x20 (4)
 [<c012dcc7>] posix_ktime_get_ts+0x7/0x10 (12)
 [<c012ed44>] sys_clock_gettime+0x74/0x90 (4)
 [<c0102ddd>] syscall_call+0x7/0xb (20)
(          phasex-3174 |#0): new 27 us maximum-latency wakeup.
... time warped from 10109461139641 to 10109461139296.
... system time:     10109399212009 .. 10109399212009.
top/3207[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c0198cde>] uptime_read_proc+0x2e/0xd0 (84)
 [<c01411a5>] audit_filter_syscall+0x45/0xd0 (28)
 [<c0198cb0>] uptime_read_proc+0x0/0xd0 (20)
 [<c0196740>] proc_file_read+0x1a0/0x250 (16)
 [<c01965a0>] proc_file_read+0x0/0x250 (48)
 [<c0163ce6>] vfs_read+0xb6/0x170 (4)
 [<c0164071>] sys_read+0x41/0x70 (24)
 [<c0102ddd>] syscall_call+0x7/0xb (28)
... time warped from 32482693158437 to 32482693158230.
... system time:     32482660250031 .. 32482660250031.
top/3725[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c0198cde>] uptime_read_proc+0x2e/0xd0 (84)
 [<c01411a5>] audit_filter_syscall+0x45/0xd0 (28)
 [<c0198cb0>] uptime_read_proc+0x0/0xd0 (20)
 [<c0196740>] proc_file_read+0x1a0/0x250 (16)
 [<c01965a0>] proc_file_read+0x0/0x250 (48)
 [<c0163ce6>] vfs_read+0xb6/0x170 (4)
 [<c0164071>] sys_read+0x41/0x70 (24)
 [<c0102ddd>] syscall_call+0x7/0xb (28)
... time warped from 32716462596526 to 32716462596335.
... system time:     32716439248732 .. 32716439248732.
bash/2994[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c013427b>] __init_rt_mutex+0x1b/0x30 (12)
 [<c011a12b>] do_fork+0x6b/0x1f0 (68)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (56)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)
... time warped from 35905926422502 to 35905926422326.
... system time:     35905875002399 .. 35905875002399.
0logwatch/3805[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c011a12b>] do_fork+0x6b/0x1f0 (80)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (56)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)
... time warped from 35906285042477 to 35906285042296.
... system time:     35906218002396 .. 35906218002396.
sh/4023[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c011a12b>] do_fork+0x6b/0x1f0 (80)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (56)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)
... time warped from 35907691480506 to 35907691480313.
... system time:     35907639002385 .. 35907639002385.
sh/4038[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c011a12b>] do_fork+0x6b/0x1f0 (80)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (56)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)
... time warped from 35929004908544 to 35929004908333.
... system time:     35928954002217 .. 35928954002217.
makewhatis.cron/4201[CPU#0]: BUG in get_monotonic_clock_ts at 
kernel/time/timeofday.c:262
 [<c011befe>] __WARN_ON+0x5e/0xa0 (8)
 [<c013610e>] get_monotonic_clock_ts+0x24e/0x2c0 (48)
 [<c011953d>] copy_process+0x41d/0xf10 (84)
 [<c011a12b>] do_fork+0x6b/0x1f0 (80)
 [<c0107302>] do_syscall_trace+0x1d2/0x1f0 (56)
 [<c01019b2>] sys_clone+0x32/0x40 (28)
 [<c0102ddd>] syscall_call+0x7/0xb (16)


--ww

Attachment: config-2.6.14-rc5-rt7.gz
Description: GNU Zip compressed data

Attachment: dmesg-2.6.14-rc5-rt7.gz
Description: GNU Zip compressed data