Re: Kernel panic: Route cache, RCU, possibly FIB trie.

From: Jesper Dangaard Brouer
Date: Tue Mar 21 2006 - 05:29:37 EST


On Tue, 21 Mar 2006, Dipankar Sarma wrote:

On Mon, Mar 20, 2006 at 10:44:21PM +0100, Jesper Dangaard Brouer wrote:

Kernel panic report.

Have experienced some kernel panic's on a production Linux box acting
as a router for a large number of customers.

I have tried to track down the problem, and I think I have narrowed it
a bit down. My theory is that it is related to the route cache
(ip_dst_cache) or FIB, which cannot dealloacate route cache slab
elements (maybe RCU related). (I have seen my route cache increase to
around 520k entries using rtstat, before dying).

I'm using the FIB trie system/algorithm (CONFIG_IP_FIB_TRIE). Think
that the error might be cause by the "fib_trie" code. See the syslog,
output below.

Below are some kernel panic outputs from the console and some
interesting errors found in syslog.

Kernel panic#1
--------------
EIP is at _stext+0x3feffd68/0x49
c03f7380
Call Trace:
[<c0103cc7>] show_stack+0x80/0x96
[<c0103e60>] show_registers+0x161/0x1c5
[<c0104057>] die+0x107/0x186
[<c0116c5f>] do_page_fault+0x2c6/0x57d
[<c0103997>] error_code+0x4f/0x54
[<c012fe7b>] __rcu_process_callbacks+0xaa/0xd3
[<c012feff>] rcu_process_callbacks+0x5b/0x65
[<c0124578>] tasklet_action+0x77/0xc9
[<c01241f1>] __do_softirq+0xc1/0xd6
[<c0124251>] do_softirq+0x4b/0x4d
[<c012433b>] irq_exit+0x47/0x49
[<c010533b>] do_IRQ+0x2b/0x3b
[<c010383e>] common_interrupt+0x1a/0x20
Code: Bad EIP value.
<0>Kernel panic - not syncing: Fatal exception in interrupt

Bad eip in processing rcu callback often indicates that the object
that embeds the rcu_head has already been freed. Can you enable
slab debugging and see if this can be detected there in a different
path ?

I have enabled slab debugging (CONFIG_DEBUG_SLAB=y) on my kernel with the KDB patch applied (and all of the other debugging options I could find).

If you look (in my original mail and below) on the output from "Kernel panic#3", there is a different code path which also fail. Related to route cache flushing.


Do you have an explaination of the syslog listing, showing yet another code path sleeping/failing??. In the fib_trie code. (I have recorded 12 of these).

Hilsen
Jesper Brouer

--
-------------------------------------------------------------------
Cand. scient datalog
Dept. of Computer Science, University of Copenhagen
-------------------------------------------------------------------


Syslog#1 (indicating a problem with the fib trie)
--------
Mar 20 18:00:04 hostname kernel: Debug: sleeping function called from invalid context at mm/slab.c:2472
Mar 20 18:00:04 hostname kernel: in_atomic():1, irqs_disabled():0
Mar 20 18:00:04 hostname kernel: [<c0103d9f>] dump_stack+0x1e/0x22
Mar 20 18:00:04 hostname kernel: [<c011cbe1>] __might_sleep+0xa6/0xae
Mar 20 18:00:04 hostname kernel: [<c014f3e9>] __kmalloc+0xd9/0xf3
Mar 20 18:00:04 hostname kernel: [<c014f5a4>] kzalloc+0x23/0x50
Mar 20 18:00:04 hostname kernel: [<c030ecd1>] tnode_alloc+0x3c/0x82
Mar 20 18:00:04 hostname kernel: [<c030edf6>] tnode_new+0x26/0x91
Mar 20 18:00:04 hostname kernel: [<c030f757>] halve+0x43/0x31d
Mar 20 18:00:04 hostname kernel: [<c030f090>] resize+0x118/0x27e
Mar 20 18:00:04 hostname kernel: [<c030fca1>] trie_rebalance+0x90/0x115
Mar 20 18:00:04 hostname kernel: [<c0310a58>] trie_leaf_remove+0x123/0x1c7
Mar 20 18:00:04 hostname kernel: [<c031101d>] fn_trie_flush+0x5c/0x84
Mar 20 18:00:04 hostname kernel: [<c030bb06>] fib_flush+0x2a/0x4c
Mar 20 18:00:04 hostname kernel: [<c030c905>] fib_disable_ip+0x47/0x49
Mar 20 18:00:04 hostname kernel: [<c030c9fb>] fib_netdev_event+0x87/0x94
Mar 20 18:00:04 hostname kernel: [<c012d15a>] notifier_call_chain+0x27/0x3f
Mar 20 18:00:04 hostname kernel: [<c02c02f2>] dev_close+0x6f/0x8d
Mar 20 18:00:04 hostname kernel: [<c02c19e0>] dev_change_flags+0x56/0x127
Mar 20 18:00:04 hostname kernel: [<f8b60806>] vlan_device_event+0x16b/0x16d [8021q]
Mar 20 18:00:04 hostname kernel: [<c012d15a>] notifier_call_chain+0x27/0x3f
Mar 20 18:00:04 hostname kernel: [<c02c02f2>] dev_close+0x6f/0x8d
Mar 20 18:00:04 hostname kernel: [<c02c19e0>] dev_change_flags+0x56/0x127
Mar 20 18:00:04 hostname kernel: [<c0304b95>] devinet_ioctl+0x232/0x5a2
Mar 20 18:00:04 hostname kernel: [<c0306e75>] inet_ioctl+0x5a/0x97
Mar 20 18:00:04 hostname kernel: [<c02b6c4f>] sock_ioctl+0xb0/0x236
Mar 20 18:00:04 hostname kernel: [<c0178473>] do_ioctl+0x7b/0x8b
Mar 20 18:00:04 hostname kernel: [<c017861d>] vfs_ioctl+0x62/0x1c1
Mar 20 18:00:04 hostname kernel: [<c01787bd>] sys_ioctl+0x41/0x64
Mar 20 18:00:04 hostname kernel: [<c0102ef9>] syscall_call+0x7/0xb



Kernel panic#3 with KDB
--------------
[<c01171eb>] do_page_fault+0x300/0x59c
[<c0103a1f>] error_code+0x4f/0x54
[<c02d8d07>] rt_cache_flush+0xf5/0xfe
[<c02d8d2b>] rt_secret_rebuild+0x1b/0x38
[<c0129344>] run_timer_softirq+0xd4/0x1c2
[<c0125115>] __do_softirq+0xc1/0xd6
[<c0125175>] do_softirq+0x4b/0x4d
[<c012525f>] irq_exit+0x47/0x49
[<c01139cc>] smp_apic_timer_interrupt+0x6f/0xee
[<c0103954>] apic_timer_interrupt+0x1c/0x24
[<c0100e10>] cpu_idle+0x89/0x9f
[<c01002dd>] _stext+0x45/0x49
[<c041aa3c>] start_kernel+0x1b5/0x1f6
[<c0100210>] 0xc0100210
Code: 01 f0 e8 40 de 04 00 a1 2c 3b 49 c0 8b 1c b8 85 db 74 07 c7 04 b8 00 00 00
00 03 35 28 3b 49 c0 89 f0 e8 d8 e1 04 00 85 db 74 37 <0f> b7 83 92 00 00 00 8b
33 8b 04 85 50 58 49 c0 85 c0 74 0d 8b

Entering kdb (current=0xc0392ba0, pid 0) on processor 0 Oops: Oops
due to oops @ 0xc02d8bc6
eax = 0xd8b62f84 ebx = 0xd9d75f04 ecx = 0x00000100 edx = 0xc02dda2e
esi = 0xd9d75f04 edi = 0x000077fc esp = 0xc0419e94 eip = 0xc02d8bc6
ebp = 0xc0419ea8 xss = 0xc02b0068 xcs = 0x00000060 eflags = 0x00010282
xds = 0xc02d007b xes = 0xc010007b origeax = 0xffffffff &regs = 0xc0419e60
[0]kdb>


[0]kdb> bt

Stack traceback for pid 0
0xc0392ba0 0 0 1 0 R 0xc0392d80 *swapper
EBP EIP Function (args)
0xc0419ea8 0xc02d8bc6 rt_run_flush+0x6b (0x0, 0xc0394ce4, 0x0, 0xc42ee, 0x102)
0xc0419ec8 0xc02d8d07 rt_cache_flush+0xf5 (0x0, 0xc0326d81, 0x0)
0xc0419edc 0xc02d8d2b rt_secret_rebuild+0x1b (0x0, 0xc1c0c520, 0x0, 0xc42ee, 0xc0419f00)
0xc0419f18 0xc0129344 run_timer_softirq+0xd4 (0xc040f308, 0x0, 0xa, 0xc1c0b2e0,0x46)
0xc0419f38 0xc0125115 __do_softirq+0xc1 (0xc1c0b2e0, 0x0)
0xc0419f48 0xc0125175 do_softirq+0x4b (0xc044d98c)
0xc0419f54 0xc012525f irq_exit+0x47 (0x0, 0xc0419f7c, 0xc044d988, 0xc0100d19, 0xc0418000)
0xc0419f74 0xc01139cc smp_apic_timer_interrupt+0x6f (0xc0100d19, 0x1, 0xc0418000, 0xc0418000, 0xc044d380)
0xc0419fb0 0xc0103954 apic_timer_interrupt+0x1c (0x602080b, 0x9f300, 0xc040c800)
0xc0100e10 cpu_idle+0x89
0xc0419fd8 0xc01002dd _stext+0x45


-
To unsubscribe from this list: send the line "unsubscribe linux-net" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html