Subject: Re: Kernel Panic
From: Romain Riviere <romain.riviere@gmail.com>
Date: Tue, 18 Oct 2011 15:10:42 +0200

 Tue, 18 Oct 2011 15:10:42 +0200
Hi list,

There are lots of kernel logs below. I am looking for help with kernel panics that are
getting on my nerves these days. Please help me restore some of my health and sanity
:-) Here goes.

I have had another panic just like the one I've already described. The first time, this
is what happened:
1) Aug 30,  BUG unable to handle kernel paging request
2) Aug 30 to Sept 30, 1 to 2 page allocation failure per DAY, the trace is almost exactly
the same (see below)
3) Sept 30, BUG unable to handle kernel NULL pointer dereference, then kernel panic

The call trace for the first paging request and for the null pointer dereference consistently
display this line:
"last sysfs file: /sys/devices/platform/coretemp.3/temp1 input"

On Oct 15, 1) happened again, and on Oct 18, 3) happened again. The stack traces are
about 90% identical to the first occurrence. The kernel is still 2.6.38.7-vs2.3.0.37-rc15,
and munin always seems to be involved.

My questions, if someone can make sense out of this, are:
- the kernel paging request is consistent about the last sysfs file being coretemp.3/temp1
input: what would that indicate?
- the page allocation failures are also very consistent in their content: same question?
- I am running the same kernel on a nearly identical server (slightly different CPU
and RAID card, 8GB RAM instead of 4) and *NEVER* had a single call trace since I started
using the kernel. Would this conclusively prove that it is hardware related?

I am probably going to have the memory checked anyway, but any input would be greatly
appreciated.

Many thanks and very best,
--
Romain Riviere

Aug 30 05:45:04 srv505 BUG: unable to handle kernel 
Aug 30 05:45:04 srv505 paging request
Aug 30 05:45:04 srv505 at 00200200
Aug 30 05:45:04 srv505 IP:
Aug 30 05:45:04 srv505 [<c10ae56c>] unlink anon vmas+0x1c/0x93
Aug 30 05:45:04 srv505 *pdpt = 0000000000000000 
Aug 30 05:45:04 srv505 *pde = f000ff53f000e2c3 
Aug 30 05:45:04 srv505 
Aug 30 05:45:04 srv505 Oops: 0000 [#1] 
Aug 30 05:45:04 srv505 SMP 
Aug 30 05:45:04 srv505 
Aug 30 05:45:04 srv505 last sysfs file: /sys/devices/platform/coretemp.3/temp1 input
Aug 30 05:45:04 srv505 
Aug 30 05:45:04 srv505 Pid: 30663, comm: munin-node Not tainted 2.6.38.7-vs2.3.0.37-rc15
#2
Aug 30 05:45:04 srv505 
Aug 30 05:45:04 srv505 Supermicro X7SBi
Aug 30 05:45:04 srv505 /
Aug 30 05:45:04 srv505 X7SBi
Aug 30 05:45:04 srv505 
Aug 30 05:45:04 srv505 EIP: 0060:[<c10ae56c>] EFLAGS: 00010206 CPU: 0
Aug 30 05:45:04 srv505 EIP is at unlink anon vmas+0x1c/0x93
Aug 30 05:45:04 srv505 EAX: f263fd80 EBX: f263fd78 ECX: f277e934 EDX: 00100100
Aug 30 05:45:04 srv505 ESI: 00200200 EDI: 001000f8 EBP: f277ec24 ESP: d989dedc
Aug 30 05:45:04 srv505 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
Aug 30 05:45:04 srv505 Process munin-node (pid: 30663, ti=d989c000 task=f2898430 task.ti=d989c000)
(...)
Aug 30 05:45:04 srv505 Call Trace:
Aug 30 05:45:04 srv505 [<c10a90f1>] ? free pgtables+0x43/0x7e
Aug 30 05:45:04 srv505 [<c10aa6ec>] ? exit mmap+0xc4/0x113
Aug 30 05:45:04 srv505 [<c104d76d>] ? mmput+0x1c/0x7a
Aug 30 05:45:04 srv505 [<c1050a96>] ? exit mm+0x103/0x10b
Aug 30 05:45:04 srv505 [<c1052006>] ? do exit+0x1ca/0x618
Aug 30 05:45:04 srv505 [<c10524ae>] ? do group exit+0x5a/0x7d
Aug 30 05:45:04 srv505 [<c10524e2>] ? sys exit group+0x11/0x14
Aug 30 05:45:04 srv505 [<c102514c>] ? sysenter do call+0x12/0x22


Sep  5 00:50:10 srv505 kworker/0:1: page allocation failure. order:1, mode:0x20
Sep  5 00:50:10 srv505 Pid: 0, comm: kworker/0:1 Tainted: G      D     2.6.38.7-vs2.3.0.37-rc15
#2
Sep  5 00:50:10 srv505 Call Trace:
Sep  5 00:50:10 srv505 [<c1098b54>] ?   alloc pages nodemask+0x527/0x56d
Sep  5 00:50:10 srv505 [<c13d3aad>] ?   nf ct refresh acct+0x41/0xa2
Sep  5 00:50:10 srv505 [<c10b5b55>] ? cache alloc refill+0x23a/0x418
Sep  5 00:50:10 srv505 [<c10b5dff>] ? kmem cache alloc+0x40/0x62
Sep  5 00:50:10 srv505 [<c13a313a>] ? sk prot alloc+0x1a/0x84
Sep  5 00:50:10 srv505 [<c13a3259>] ? sk clone+0x15/0x28e
Sep  5 00:50:10 srv505 [<c13f5bbc>] ? inet csk clone+0xd/0x76
Sep  5 00:50:10 srv505 [<c140826f>] ? tcp create openreq child+0x1a/0x3d0
Sep  5 00:50:10 srv505 [<c1406e05>] ? tcp v4 syn recv sock+0x48/0x181
Sep  5 00:50:10 srv505 [<c1408133>] ? tcp check req+0x227/0x349
Sep  5 00:50:10 srv505 [<c14065d2>] ? tcp v4 do rcv+0xc1/0x1c3
Sep  5 00:50:10 srv505 [<c1406b16>] ? tcp v4 rcv+0x442/0x6e9
Sep  5 00:50:10 srv505 [<c13ee1e6>] ? ip local deliver finish+0x13d/0x216
Sep  5 00:50:10 srv505 [<c13eddfc>] ? ip rcv finish+0x2fc/0x30f
Sep  5 00:50:10 srv505 [<c13ac109>] ?   netif receive skb+0x410/0x437
Sep  5 00:50:10 srv505 [<c13acb67>] ? netif receive skb+0x5a/0x5f
Sep  5 00:50:10 srv505 [<c1324644>] ? e1000 receive skb+0x17/0x4e
Sep  5 00:50:10 srv505 [<c13acc29>] ? napi skb finish+0x1b/0x30
Sep  5 00:50:10 srv505 [<c13248ac>] ? e1000 clean rx irq+0x231/0x2da
Sep  5 00:50:10 srv505 [<c12bcfe9>] ? scsi run queue+0x295/0x319
Sep  5 00:50:10 srv505 [<c1325ded>] ? e1000 clean+0x63/0x21b
Sep  5 00:50:10 srv505 [<c13ad183>] ? net rx action+0x8c/0x16e
Sep  5 00:50:10 srv505 [<c105372e>] ?   do softirq+0x6a/0xed
Sep  5 00:50:10 srv505 [<c10536c4>] ?   do softirq+0x0/0xed
Sep  5 00:50:10 srv505 <IRQ> 
Sep  5 00:50:10 srv505 [<c1026581>] ? do IRQ+0x73/0x84
Sep  5 00:50:10 srv505 [<c10256a9>] ? common interrupt+0x29/0x30
Sep  5 00:50:10 srv505 [<c102a026>] ? mwait idle+0x51/0x56
Sep  5 00:50:10 srv505 [<c10244b4>] ? cpu idle+0x37/0x4f


Le 30 sept. 2011 à 08:56, Romain Riviere a écrit :

> Hello,
> 
> Here's a panic I just had this morning and that, for once, I was able to get information
for, thanks to netconsole. This *might* be a bug that I have had with vserver kernels
since approx 2.6.36+ and for which I have found no solution yet. Any help would be GREATLY
appreciated.
> 
> Cheers,
> --
> Romain
> 
> Here goes:
> 
> Sep 30 05:36:43 srv505 Kernel panic - not syncing: Fatal exception in interrupt
> Sep 30 05:36:43 srv505 Pid: 0, comm: swapper Tainted: G      D 2.6.38.7-vs2.3.0.37-rc15
#2
> Sep 30 05:36:43 srv505 Call Trace:
> Sep 30 05:36:43 srv505 [<c14aed50>] ? panic+0x4d/0x12b
> Sep 30 05:36:43 srv505 [<c10279a1>] ? oops end+0x6b/0x75
> Sep 30 05:36:43 srv505 [<c103acb9>] ? no context+0x13c/0x145
> Sep 30 05:36:43 srv505 [<c103adbd>] ?   bad area nosemaphore+0xfb/0x103
> Sep 30 05:36:43 srv505 [<c106af36>] ? vx update load+0x18/0x1e6
> Sep 30 05:36:43 srv505 [<c10444bb>] ? update cfs load+0x129/0x1d6
> Sep 30 05:36:43 srv505 [<c103adcf>] ? bad area nosemaphore+0xa/0xc
> Sep 30 05:36:43 srv505 [<c103b08b>] ? do page fault+0x157/0x344
> Sep 30 05:36:43 srv505 [<c104c5b2>] ? try to wake up+0x25a/0x266
> Sep 30 05:36:43 srv505 [<c106204f>] ? autoremove wake function+0xd/0x2d
> Sep 30 05:36:43 srv505 [<c1042551>] ?   wake up common+0x34/0x59
> Sep 30 05:36:43 srv505 [<c103af34>] ? do page fault+0x0/0x344
> Sep 30 05:36:43 srv505 [<c14b130a>] ? error code+0x5a/0x60
> Sep 30 05:36:43 srv505 [<c1226d1c>] ? cfq completed request+0x0/0x433
> Sep 30 05:36:43 srv505 [<c104007b>] ? aes dec blk+0x4cb/0xb6c
> Sep 30 05:36:43 srv505 [<c103af34>] ? do page fault+0x0/0x344
> Sep 30 05:36:43 srv505 [<c1226d42>] ? cfq completed request+0x26/0x433
> Sep 30 05:36:43 srv505 [<c128bf0d>] ? credit entropy bits+0x6a/0x7d
> Sep 30 05:36:43 srv505 [<c128bfe9>] ? add timer randomness+0xc9/0xd0
> Sep 30 05:36:43 srv505 [<c1219425>] ? elv completed request+0x3d/0x3f
> Sep 30 05:36:43 srv505 [<c121af09>] ?   blk put request+0x27/0x95
> Sep 30 05:36:43 srv505 [<c121b34e>] ? blk end bidi request+0x31/0x47
> Sep 30 05:36:43 srv505 [<c121b393>] ? blk end request+0x7/0x9
> Sep 30 05:36:43 srv505 [<c12be01a>] ? scsi io completion+0x15d/0x380
> Sep 30 05:36:43 srv505 [<c12b9628>] ? scsi finish command+0x72/0x8a
> Sep 30 05:36:43 srv505 [<c121f183>] ? blk done softirq+0x47/0x53
> Sep 30 05:36:43 srv505 [<c105372e>] ?   do softirq+0x6a/0xed
> Sep 30 05:36:43 srv505 [<c10536c4>] ?   do softirq+0x0/0xed
> Sep 30 05:36:43 srv505 <IRQ>
> Sep 30 05:36:43 srv505 [<c14b0eae>] ? call function single interrupt+0x2a/0x30
> Sep 30 05:36:43 srv505 [<c102a026>] ? mwait idle+0x51/0x56
> Sep 30 05:36:43 srv505 [<c10244b4>] ? cpu idle+0x37/0x4f
> Sep 30 05:36:43 srv505 [<c16b2951>] ? start kernel+0x2bd/0x2c0
> 
> This was preceded by :
> Sep 30 05:36:43 srv505 BUG: unable to handle kernel
> Sep 30 05:36:43 srv505 NULL pointer dereference
> Sep 30 05:36:43 srv505 at 0000029c
> Sep 30 05:36:43 srv505 IP:
> Sep 30 05:36:43 srv505 [<c1226d42>] cfq completed request+0x26/0x433
> Sep 30 05:36:43 srv505 *pdpt = 00000000320ec001
> Sep 30 05:36:43 srv505 *pde = 0000000000000000
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 Oops: 0000 [#2]
> Sep 30 05:36:43 srv505 SMP
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 last sysfs file: /sys/devices/platform/coretemp.3/temp1 input
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 Pid: 0, comm: swapper Tainted: G      D 2.6.38.7-vs2.3.0.37-rc15
#2
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 Supermicro X7SBi
> Sep 30 05:36:43 srv505 /
> Sep 30 05:36:43 srv505 X7SBi
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 EIP: 0060:[<c1226d42>] EFLAGS: 00010096 CPU: 0
> Sep 30 05:36:43 srv505 EIP is at cfq completed request+0x26/0x433
> Sep 30 05:36:43 srv505 EAX: 00000001 EBX: f36a5760 ECX: c1226d1c EDX: f36a5760
> Sep 30 05:36:43 srv505 ESI: f356bd84 EDI: 00000000 EBP: a356d4ec ESP: f340bf28
> Sep 30 05:36:43 srv505 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> Sep 30 05:36:43 srv505 Process swapper (pid: 0, ti=f340a000 task=c1676320 task.ti=c1658000)
> Sep 30 05:36:43 srv505 Stack:
> Sep 30 05:36:43 srv505 00000202
> Sep 30 05:36:43 srv505 c128bf0d
> Sep 30 05:36:43 srv505 00000000
> Sep 30 05:36:43 srv505 00000002
> Sep 30 05:36:43 srv505 00000004
> Sep 30 05:36:43 srv505 f2f71980
> Sep 30 05:36:43 srv505 00000202
> Sep 30 05:36:43 srv505 c128bfe9
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 00000001
> Sep 30 05:36:43 srv505 f36a4b30
> Sep 30 05:36:43 srv505 f36a5760
> Sep 30 05:36:43 srv505 f36a4b30
> Sep 30 05:36:43 srv505 f36a4b30
> Sep 30 05:36:43 srv505 c1219425
> Sep 30 05:36:43 srv505 f36a5760
> Sep 30 05:36:43 srv505 c121af09
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 00000246
> Sep 30 05:36:43 srv505 f36a5760
> Sep 30 05:36:43 srv505 00000000
> Sep 30 05:36:43 srv505 c121b34e
> Sep 30 05:36:43 srv505 f21dc0c0
> Sep 30 05:36:43 srv505 00000000
> Sep 30 05:36:43 srv505 f36a5760
> Sep 30 05:36:43 srv505 f36a5760
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 Call Trace:
> Sep 30 05:36:43 srv505 [<c128bf0d>] ? credit entropy bits+0x6a/0x7d
> Sep 30 05:36:43 srv505 [<c128bfe9>] ? add timer randomness+0xc9/0xd0
> Sep 30 05:36:43 srv505 [<c1219425>] ? elv completed request+0x3d/0x3f
> Sep 30 05:36:43 srv505 [<c121af09>] ?   blk put request+0x27/0x95
> Sep 30 05:36:43 srv505 [<c121b34e>] ? blk end bidi request+0x31/0x47
> Sep 30 05:36:43 srv505 [<c121b393>] ? blk end request+0x7/0x9
> Sep 30 05:36:43 srv505 [<c12be01a>] ? scsi io completion+0x15d/0x380
> Sep 30 05:36:43 srv505 [<c12b9628>] ? scsi finish command+0x72/0x8a
> Sep 30 05:36:43 srv505 [<c121f183>] ? blk done softirq+0x47/0x53
> Sep 30 05:36:43 srv505 [<c105372e>] ?   do softirq+0x6a/0xed
> Sep 30 05:36:43 srv505 [<c10536c4>] ?   do softirq+0x0/0xed
> Sep 30 05:36:43 srv505 <IRQ>
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 [<c14b0eae>] ? call function single interrupt+0x2a/0x30
> Sep 30 05:36:43 srv505 [<c102a026>] ? mwait idle+0x51/0x56
> Sep 30 05:36:43 srv505 [<c10244b4>] ? cpu idle+0x37/0x4f
> Sep 30 05:36:43 srv505 [<c16b2951>] ? start kernel+0x2bd/0x2c0
> Sep 30 05:36:43 srv505 Code:
> Sep 30 05:36:43 srv505 5b
> Sep 30 05:36:43 srv505 5e
> Sep 30 05:36:43 srv505 5f
> Sep 30 05:36:43 srv505 5d
> Sep 30 05:36:43 srv505 c3
> Sep 30 05:36:43 srv505 55
> Sep 30 05:36:43 srv505 57
> Sep 30 05:36:43 srv505 56
> Sep 30 05:36:43 srv505 53
> Sep 30 05:36:43 srv505 89
> Sep 30 05:36:43 srv505 d3
> Sep 30 05:36:43 srv505 83
> Sep 30 05:36:43 srv505 ec
> Sep 30 05:36:43 srv505 24
> Sep 30 05:36:43 srv505 8b
> Sep 30 05:36:43 srv505 72
> Sep 30 05:36:43 srv505 5c
> Sep 30 05:36:43 srv505 8b
> Sep 30 05:36:43 srv505 42
> Sep 30 05:36:43 srv505 20
> Sep 30 05:36:43 srv505 8b
> Sep 30 05:36:43 srv505 7e
> Sep 30 05:36:43 srv505 08
> Sep 30 05:36:43 srv505 83
> Sep 30 05:36:43 srv505 e0
> Sep 30 05:36:43 srv505 11
> Sep 30 05:36:43 srv505 8b
> Sep 30 05:36:43 srv505 2d
> Sep 30 05:36:43 srv505 40
> Sep 30 05:36:43 srv505 da
> Sep 30 05:36:43 srv505 65
> Sep 30 05:36:43 srv505 c1
> Sep 30 05:36:43 srv505 48
> Sep 30 05:36:43 srv505 0f
> Sep 30 05:36:43 srv505 95
> Sep 30 05:36:43 srv505 c0
> Sep 30 05:36:43 srv505 0f
> Sep 30 05:36:43 srv505 b6
> Sep 30 05:36:43 srv505 c0
> Sep 30 05:36:43 srv505 89
> Sep 30 05:36:43 srv505 44
> Sep 30 05:36:43 srv505 24
> Sep 30 05:36:43 srv505 20
> Sep 30 05:36:43 srv505 syslog-ng[3301]: Error processing log message: <8b>
> Sep 30 05:36:43 srv505 87
> Sep 30 05:36:43 srv505 9c
> Sep 30 05:36:43 srv505 02
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 8b
> Sep 30 05:36:43 srv505 97
> Sep 30 05:36:43 srv505 e4
> Sep 30 05:36:43 srv505 02
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 3b
> Sep 30 05:36:43 srv505 87
> Sep 30 05:36:43 srv505 b0
> Sep 30 05:36:43 srv505 02
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 00
> Sep 30 05:36:43 srv505 7e
> Sep 30 05:36:43 srv505 06
> Sep 30 05:36:43 srv505 89
> Sep 30 05:36:43 srv505
> Sep 30 05:36:43 srv505 EIP: [<c1226d42>]
> Sep 30 05:36:43 srv505 cfq completed request+0x26/0x433
> Sep 30 05:36:43 srv505 SS:ESP 0068:f340bf28
> Sep 30 05:36:43 srv505 CR2: 000000000000029c
> Sep 30 05:36:43 srv505 ---[ end trace ab3174360ff1a69e ]---