debian on amd64: Your time source seems to be instable

c-- · 12-01-2008, 12:33 PM

I have a debian server which locks up every week or so. It will respond to ping, but all other services fail. /var/log/messages says:

The server is running debian etch on 2 x Quad-Core AMD Opteron(tm) Processor 2360 SE

Code:

Nov 27 01:00:49 nwb00 kernel: warning: many lost ticks.
Nov 27 01:00:49 nwb00 kernel: Your time source seems to be instable or some driver is hogging interupts
Nov 27 01:00:49 nwb00 kernel: rip __do_softirq+0x53/0xd5
Nov 27 01:05:09 nwb00 kernel: oom-killer: gfp_mask=0x201d2, order=0
Nov 27 01:05:09 nwb00 kernel:
Nov 27 01:05:09 nwb00 kernel: Call Trace:
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff802a66d0>] out_of_memory+0x33/0x216
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff8020e00e>] __alloc_pages+0x220/0x2a9
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff80210dc1>] __do_page_cache_readahead+0x95/0x206
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff80226851>] sync_page+0x0/0x42
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff8025caf3>] io_schedule+0x28/0x33
Nov 27 01:05:09 nwb00 kernel:  [<ffffffff80226851>] sync_page+0x0/0x42
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff8025cd8a>] __wait_on_bit_lock+0x5b/0x66
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff8023d77f>] __lock_page+0x5e/0x64
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff802116fd>] filemap_nopage+0x148/0x314
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff80208718>] __handle_mm_fault+0x375/0x91a
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff802ac40c>] expand_stack+0xfe/0x12f
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff8020a69c>] do_page_fault+0x39d/0x706
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff8025c37e>] thread_return+0x0/0xe7
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff80226c3e>] do_sigaction+0x153/0x19e
Nov 27 01:05:10 nwb00 kernel:  [<ffffffff802588e5>] error_exit+0x0/0x84
Nov 27 01:05:10 nwb00 kernel:
Nov 27 01:05:10 nwb00 kernel: Mem-info:
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA per-cpu:
Nov 27 01:05:10 nwb00 kernel: cpu 0 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 0 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 1 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 1 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 2 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 2 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 3 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 3 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 4 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 4 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 5 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 5 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 6 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 6 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 7 hot: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 7 cold: high 0, batch 1 used:0
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA32 per-cpu:
Nov 27 01:05:10 nwb00 kernel: cpu 0 hot: high 186, batch 31 used:26
Nov 27 01:05:10 nwb00 kernel: cpu 0 cold: high 62, batch 15 used:60
Nov 27 01:05:10 nwb00 kernel: cpu 1 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 1 cold: high 62, batch 15 used:15
Nov 27 01:05:10 nwb00 kernel: cpu 2 hot: high 186, batch 31 used:36
Nov 27 01:05:10 nwb00 kernel: cpu 2 cold: high 62, batch 15 used:39
Nov 27 01:05:10 nwb00 kernel: cpu 3 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 3 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 4 hot: high 186, batch 31 used:135
Nov 27 01:05:10 nwb00 kernel: cpu 4 cold: high 62, batch 15 used:58
Nov 27 01:05:10 nwb00 kernel: cpu 5 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 5 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 6 hot: high 186, batch 31 used:22
Nov 27 01:05:10 nwb00 kernel: cpu 6 cold: high 62, batch 15 used:59
Nov 27 01:05:10 nwb00 kernel: cpu 7 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 7 cold: high 62, batch 15 used:2
Nov 27 01:05:10 nwb00 kernel: Node 0 Normal per-cpu:
Nov 27 01:05:10 nwb00 kernel: cpu 0 hot: high 186, batch 31 used:171
Nov 27 01:05:10 nwb00 kernel: cpu 0 cold: high 62, batch 15 used:53
Nov 27 01:05:10 nwb00 kernel: cpu 1 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 1 cold: high 62, batch 15 used:14
Nov 27 01:05:10 nwb00 kernel: cpu 2 hot: high 186, batch 31 used:18
Nov 27 01:05:10 nwb00 kernel: cpu 2 cold: high 62, batch 15 used:14
Nov 27 01:05:10 nwb00 kernel: cpu 3 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 3 cold: high 62, batch 15 used:53
Nov 27 01:05:10 nwb00 kernel: cpu 4 hot: high 186, batch 31 used:99
Nov 27 01:05:10 nwb00 kernel: cpu 4 cold: high 62, batch 15 used:48
Nov 27 01:05:10 nwb00 kernel: cpu 5 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 5 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 6 hot: high 186, batch 31 used:24
Nov 27 01:05:10 nwb00 kernel: cpu 6 cold: high 62, batch 15 used:51
Nov 27 01:05:10 nwb00 kernel: cpu 7 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 7 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: Node 0 HighMem per-cpu: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA per-cpu: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA32 per-cpu: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 Normal per-cpu:
Nov 27 01:05:10 nwb00 kernel: cpu 0 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 0 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 1 hot: high 186, batch 31 used:156
Nov 27 01:05:10 nwb00 kernel: cpu 1 cold: high 62, batch 15 used:14
Nov 27 01:05:10 nwb00 kernel: cpu 2 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 2 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 3 hot: high 186, batch 31 used:127
Nov 27 01:05:10 nwb00 kernel: cpu 3 cold: high 62, batch 15 used:50
Nov 27 01:05:10 nwb00 kernel: cpu 4 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 4 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 5 hot: high 186, batch 31 used:64
Nov 27 01:05:10 nwb00 kernel: cpu 5 cold: high 62, batch 15 used:51
Nov 27 01:05:10 nwb00 kernel: cpu 6 hot: high 186, batch 31 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 6 cold: high 62, batch 15 used:0
Nov 27 01:05:10 nwb00 kernel: cpu 7 hot: high 186, batch 31 used:82
Nov 27 01:05:10 nwb00 kernel: cpu 7 cold: high 62, batch 15 used:29
Nov 27 01:05:10 nwb00 kernel: Node 1 HighMem per-cpu: empty
Nov 27 01:05:10 nwb00 kernel: Free pages:       26552kB (0kB HighMem)
Nov 27 01:05:10 nwb00 kernel: Active:1022701 inactive:1013567 dirty:0 writeback:0 unstable:0 free:6638 slab:3062 mapped:15 pagetables:8581
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA free:12592kB min:16kB low:20kB high:24kB active:0kB inactive:0kB present:12212kB pages_scanned:0 all_unreclaimable? yes
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 3383 4014 4014
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA32 free:7356kB min:4816kB low:6020kB high:7224kB active:1741228kB inactive:1737716kB present:3464232kB pages_scanned:1209180 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 631 631
Nov 27 01:05:10 nwb00 kernel: Node 0 Normal free:852kB min:896kB low:1120kB high:1344kB active:285096kB inactive:284980kB present:646400kB pages_scanned:344886 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 0 0
Nov 27 01:05:10 nwb00 kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 0 0
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 4040 4040
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA32 free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 4040 4040
Nov 27 01:05:10 nwb00 kernel: Node 1 Normal free:5752kB min:5752kB low:7188kB high:8628kB active:2064648kB inactive:2031556kB present:4136960kB pages_scanned:816477 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 0 0
Nov 27 01:05:10 nwb00 kernel: Node 1 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Nov 27 01:05:10 nwb00 kernel: lowmem_reserve[]: 0 0 0 0
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA: 4*4kB 2*8kB 3*16kB 3*32kB 2*64kB 2*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 2*4096kB = 12592kB
Nov 27 01:05:10 nwb00 kernel: Node 0 DMA32: 7*4kB 10*8kB 1*16kB 0*32kB 3*64kB 1*128kB 1*256kB 1*512kB 0*1024kB 1*2048kB 1*4096kB = 7356kB
Nov 27 01:05:10 nwb00 kernel: Node 0 Normal: 1*4kB 14*8kB 2*16kB 2*32kB 2*64kB 0*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 852kB
Nov 27 01:05:10 nwb00 kernel: Node 0 HighMem: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 DMA32: empty
Nov 27 01:05:10 nwb00 kernel: Node 1 Normal: 10*4kB 10*8kB 0*16kB 6*32kB 1*64kB 0*128kB 1*256kB 0*512kB 1*1024kB 0*2048kB 1*4096kB = 5752kB
Nov 27 01:05:10 nwb00 kernel: Node 1 HighMem: empty
Nov 27 01:05:10 nwb00 kernel: Swap cache: add 1971733, delete 1971733, find 13250/15162, race 0+4
Nov 27 01:05:10 nwb00 kernel: Free swap  = 0kB
Nov 27 01:05:10 nwb00 kernel: Total swap = 7815612kB
Nov 27 01:05:10 nwb00 kernel: Free swap:            0kB
Nov 27 01:05:10 nwb00 kernel: 2260992 pages of RAM
Nov 27 01:05:10 nwb00 kernel: 199208 reserved pages
Nov 27 01:05:10 nwb00 kernel: 2914 pages shared
Nov 27 01:05:10 nwb00 kernel: 0 pages swap cached

loaded modules:

Code:

Module                  Size  Used by
ipv6                  286048  39 
button                 12192  0 
ac                     10376  0 
battery                15496  0 
dm_snapshot            20664  0 
dm_mirror              25216  0 
dm_mod                 62800  2 dm_snapshot,dm_mirror
loop                   20112  0 
i2c_piix4              14348  0 
serio_raw              12036  0 
i2c_core               27776  1 i2c_piix4
psmouse                44432  0 
pcspkr                  7808  0 
shpchp                 42156  0 
pci_hotplug            20872  1 shpchp
joydev                 15360  0 
evdev                  15360  0 
ext3                  138512  3 
jbd                    65392  1 ext3
mbcache                14216  1 ext3
ide_cd                 45088  0 
cdrom                  40488  1 ide_cd
usbhid                 45088  0 
serverworks            13712  0 [permanent]
sd_mod                 25856  5 
megaraid_sas           36280  4 
sata_svw               13828  0 
bnx2                   86640  0 
libata                106784  1 sata_svw
scsi_mod              153008  3 sd_mod,megaraid_sas,libata
ehci_hcd               36104  0 
generic                10500  0 [permanent]
ohci_hcd               24836  0 
ide_core              147584  3 ide_cd,serverworks,generic
thermal                20240  0 
processor              38248  1 thermal
fan                     9864  0

I have no idea what to do next with this issue, I'm a perl hacker and don't know much about the kernel. From what I've googled, I should try unloading kernel modules to see if I can find one that is "hogging interupts" and causing the issue, is there a better way to analyze this?

indienick · 12-01-2008, 12:50 PM

I do not know how to help solve your problem, but unloading (and furthermore blacklisting) kernel modules sounds like a good idea.

Looking at your lsmod output, I would suggest removing modules that the system obviously doesn't need:
- battery (because your server probably isn't a laptop)
- pcskpr (just because it's annoying)
- thermal (unless you need temperature monitoring)

...that's just for starters.