[vserver] Re: Kernel Panic

From: Romain Riviere <romain.riviere_at_gmail.com>
Date: Tue 18 Oct 2011 - 14:10:42 BST
Message-Id: <0AD8B15A-EDC0-4D6D-85DE-EC37BFC2A791@gmail.com>

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 ]---
Received on Tue Oct 18 14:15:03 2011
[Next/Previous Months] [Main vserver Project Homepage] [Howto Subscribe/Unsubscribe] [Paul Sladen's vserver stuff]
Generated on Tue 18 Oct 2011 - 14:15:04 BST by hypermail 2.1.8