[Openswan dev] 2.6 crasher with pfkey and openswan

[Paul Wouters]

I tried to figure out why my test setup connection seemed to come back up
even when I told it to go down. I was looking to see if the Delete SA 
actually triggered the Fedora box to start a new exchange, so I did a few
quick "up"s and "down"s on the SA when the whole thing blew up in my face. 
This happened twice.

This is on kernel 2.6.1-1.65 (i586 rpm) using openswan-2 cvs (HEAD). It also
happened on 2.6.1-1.52. I have not tried a vanilla 2.6 kernel tree so far.

If I can further help to find this error, drop me a line.

Paul


[root at fw-500me openswan-2]# ipsec auto --down fedoratest
003 "fedoratest" #11: PLUTO_NEXT_HOP is '193.110.157.17'
[root at fw-500me openswan-2]# 
Feb 10 00:59:03 fw-500me pluto[1239]: "fedoratest": terminating SAs using this connection
Feb 10 00:59:03 fw-500me pluto[1239]: "fedoratest" #11: deleting state (STATE_QUICK_I2)
Feb 10 00:59:03 fw-500me pluto[1239]: "fedoratest" #11: PLUTO_NEXT_HOP is '193.110.157.17'
Feb 10 00:59:03 fw-500me pluto[1239]: "fedoratest" #10: deleting state (STATE_MAIN_I4)
Feb 10 00:59:03 fw-500me pluto[1239]: packet from 193.110.157.17:500: Informational Exchange is for an unknown (expired?) SA
[root at fw-500me openswan-2]# 
Feb 10 00:59:03 fw-500me pluto[1239]: packet from 193.110.157.17:500: Informational Exchange is for an unknown (expired?) SA
Feb 10 00:59:46 fw-500me pluto[1239]: "fedoratest" #12: responding to Main Mode
Feb 10 00:59:46 fw-500me pluto[1239]: "fedoratest" #12: transition from state (null) to state STATE_MAIN_R1
Feb 10 00:59:46 fw-500me pluto[1239]: "fedoratest" #12: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Feb 10 00:59:46 fw-500me pluto[1239]: "fedoratest" #12: Peer ID is ID_IPV4_ADDR: '193.110.157.17'
Feb 10 00:59:47 fw-500me pluto[1239]: "fedoratest" #12: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Feb 10 00:59:47 fw-500me pluto[1239]: "fedoratest" #12: sent MR3, ISAKMP SA established
Feb 10 00:59:47 fw-500me pluto[1239]: "fedoratest" #13: responding to Quick Mode
bad: scheduling while atomic!
Call Trace:
 [<c012207f>] schedule+0x6bf/0x6d0
 [<c02e8285>] xfrm_lookup+0x345/0x460
 [<c0122090>] default_wake_function+0x0/0x10
 [<c0122090>] default_wake_function+0x0/0x10
 [<c02e74a0>] xfrm_policy_lookup+0x50/0x310
 [<c02ac57d>] ip_route_output_key+0x2d/0x30
 [<c02d4523>] icmp_reply+0x153/0x240
 [<c02e84f3>] __xfrm_policy_check+0x113/0x6f0
 [<c02e7450>] xfrm_policy_lookup+0x0/0x310
 [<c02d4e2a>] icmp_echo+0x4a/0x50
 [<c02d517e>] icmp_rcv+0x14e/0x190
 [<c02d50dc>] icmp_rcv+0xac/0x190
 [<c02ade24>] ip_local_deliver+0xe4/0x1f0
 [<c02ae24d>] ip_rcv+0x31d/0x450
 [<c0294044>] netif_receive_skb+0x174/0x1e0
 [<c0294122>] process_backlog+0x72/0x110
 [<c029421f>] net_rx_action+0x5f/0xf0
 [<c012c2d4>] do_softirq+0x94/0xa0
 [<c010e0d8>] do_IRQ+0x1e8/0x2e0
 [<c010c338>] common_interrupt+0x18/0x20
 [<c0109054>] default_idle+0x24/0x30
 [<c011b6dc>] apm_cpu_idle+0x8c/0x150
 [<c0105000>] _stext+0x0/0x20
 [<c01090c5>] cpu_idle+0x25/0x40
 [<c03b265d>] start_kernel+0x15d/0x190
                                                                                                                                                                 
Unable to handle kernel NULL pointer dereference at virtual address 00000000
 printing eip:
c0121b13
*pde = 00000000
Oops: 0000 [#1]
CPU:    0
EIP:    0060:[<c0121b13>]    Not tainted
EFLAGS: 00010082
EIP is at schedule+0x153/0x6d0
eax: c0336c00   ebx: 00000000   ecx: c0336c20   edx: c0336df0
esi: c0336c00   edi: c03b1d64   ebp: c03b1d24   esp: c03b1cf0
ds: 007b   es: 007b   ss: 0068
Process swapper (pid: 0, threadinfo=c03b0000 task=c0336c00)
Stack: 00000002 c03b1e24 c03b1e20 00000000 ffffffff 3ccbf700 b9361898 00000293
       c0336c00 c0336df0 c03b1d70 c4ff5d4c c03b1d64 c4bb0084 c02e8285 c03b0000
       00000002 00020000 0000000e fffffff5 00000000 c03b1e18 c03b1dc4 00000000
Call Trace:
 [<c02e8285>] xfrm_lookup+0x345/0x460
 [<c0122090>] default_wake_function+0x0/0x10
 [<c0122090>] default_wake_function+0x0/0x10
 [<c02e74a0>] xfrm_policy_lookup+0x50/0x310
 [<c02ac57d>] ip_route_output_key+0x2d/0x30
 [<c02d4523>] icmp_reply+0x153/0x240
 [<c02e84f3>] __xfrm_policy_check+0x113/0x6f0
 [<c02e7450>] xfrm_policy_lookup+0x0/0x310
 [<c02d4e2a>] icmp_echo+0x4a/0x50
 [<c02d517e>] icmp_rcv+0x14e/0x190
 [<c02d50dc>] icmp_rcv+0xac/0x190
 [<c02ade24>] ip_local_deliver+0xe4/0x1f0
 [<c02ae24d>] ip_rcv+0x31d/0x450
 [<c0294044>] netif_receive_skb+0x174/0x1e0
 [<c0294122>] process_backlog+0x72/0x110
 [<c029421f>] net_rx_action+0x5f/0xf0
 [<c012c2d4>] do_softirq+0x94/0xa0
 [<c010e0d8>] do_IRQ+0x1e8/0x2e0
 [<c010c338>] common_interrupt+0x18/0x20
 [<c0109054>] default_idle+0x24/0x30
 [<c011b6dc>] apm_cpu_idle+0x8c/0x150
 [<c0105000>] _stext+0x0/0x20
 [<c01090c5>] cpu_idle+0x25/0x40
 [<c03b265d>] start_kernel+0x15d/0x190
                                                                                                                                                                 
Code: 8b 13 4a 89 13 8b 75 ec 8b 51 04 8b 46 20 89 02 c7 46 20 00
 kernel/sched.c:291: spin_lock(kernel/sched.c:c03ef7e0) already locked by kernel/sched.c/1634
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:1799: spin_lock(kernel/printk.c:c0338fc0) already locked by kernel/sched.c/1799
kernel/sched.c:291: spin_lock(kernel/sched.c:c03ef7e0) already locked by kernel/sched.c/1634
kernel/sched.c:291: spin_lock(kernel/sched.c:c03ef7e0) already locked by kernel/sched.c/1634
kernel/sched.c:291: spin_lock(kernel/sched.c:c03ef7e0) already locked by kernel/sched.c/1634
kernel/sched.c:291: spin_lock(kernel/sched.c:c03ef7e0) already locked by kernel/sched.c/1634
Kernel panic: Fatal exception in interrupt
In interrupt handler - not syncing
 <0>Rebooting in 50 seconds..