[Openswan dev] ip xfrm bug
Paul Wouters
paul at xelerance.com
Thu Nov 29 11:41:04 EST 2007
I just encountered an ip xfrm bug.
After I setup an ipsec SA with openswan (on git #testing branch), I
tried to restart it. Pluto was mistakenly trying to delete a KLIPS
eroute, so I was stuck with a policy:
[root at bofh openswan.testing]# ip xfrm policy
src 193.110.157.17/32 dst 193.110.157.141/32
dir out priority 2080 ptype main
tmpl src 193.110.157.17 dst 193.110.157.141
proto esp reqid 16401 mode tunnel
src ::/0 dst ::/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir in priority 0 ptype main
src ::/0 dst ::/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
src 0.0.0.0/0 dst 0.0.0.0/0
dir out priority 0 ptype main
So i ran: ip xfrm policy deleteall
The process never returned:
top - 11:29:42 up 2 days, 17:05, 10 users, load average: 1.08, 0.54, 0.24
Tasks: 161 total, 2 running, 159 sleeping, 0 stopped, 0 zombie
Cpu(s): 4.0%us, 1.3%sy, 0.2%ni, 93.2%id, 1.3%wa, 0.0%hi, 0.1%si, 0.0%st
Mem: 1028676k total, 877556k used, 151120k free, 7916k buffers
Swap: 522104k total, 141984k used, 380120k free, 195988k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4354 root 20 0 5960 328 244 R 94.3 0.0 2:29.87 ip
2484 root 20 0 239m 90m 8832 S 3.9 9.0 60:06.37 X
strace'ing the ip binary shows:
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0%\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0%\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0&\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0&\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\304\0\0\0\23\0\2\0\'\270CJ\2\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 2744
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\'\270CJ\2\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 20
sendto(4, "P\0\0\0\24\0\1\0(\270CJ\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1120, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 1120
sendto(4, "\24\0\0\0\25\0\1\0036\270CJ\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0(\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0(\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0)\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0)\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0*\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0*\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0+\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0+\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0,\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0,\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0-\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0-\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0.\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0.\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0/\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0/\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0000\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0000\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0001\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0001\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0002\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0002\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0003\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0003\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0004\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0004\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0005\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0005\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\304\0\0\0\23\0\2\0006\270CJ\2\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 2744
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0006\270CJ\2\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 20
sendto(4, "P\0\0\0\24\0\1\0007\270CJ\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1120, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 1120
sendto(4, "\24\0\0\0\25\0\1\3E\270CJ\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0007\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0007\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0008\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0008\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0009\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0009\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0:\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0:\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0;\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0;\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0<\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0<\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0=\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0=\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"$\0\0\0\2\0\0\0>\270CJ\2\21\0\0\376\377\377\377P\0\0\0\24\0\1\0>\270CJ"..., 16384}], msg_controllen=0, msg_flags=0}, 0) = 36
While writing this email, it apparently stopped, and deleted the one policy
related to my conn. It left all the 0.0.0.0/0 policies in. Running another
ip xfrm policy deleteall, again is running for a few minutes at 97% cpu.
This is on Fedora 8 x86_64, 2.6.23.1-49.fc8 and iproute-2.6.22-2.fc8
The other end was also a netkey system. The command returned fine there,
but a minute later came me a kernel oops:
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: ------------[ cut here ]------------
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: invalid opcode: 0000 [#1]
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: SMP
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: CPU: 0
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: EIP: 0061:[<c0462772>] Not tainted VLI
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: EFLAGS: 00010046 (2.6.20-1.2933.fc6xen #1)
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: EIP is at free_block+0x46/0xe5
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: esi: 00000027 edi: c7c4c000 ebp: c7af4b00 esp: c0b16f08
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: ds: 007b es: 007b ss: 0069
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: eax: 00000000 ebx: 00000000 ecx: 00000027 edx: c1800000
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: Process events/0 (pid: 5, ti=c0b16000 task=c0b10030 task.ti=c0b16000)
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: Stack: c0730fc0 c52f0800 00000027 00000000 c7c4c020 c7c4c020 00000027 c7c4c000
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: 00000000 c046289b 00000000 00000000 c7af4b00 c79d4704 c79d46e0 c7af4b00
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: 00000000 c11140c0 c0463b33 00000000 00000000 c11140c4 c0afe520 c042aa3a
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: Call Trace:
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c046289b>] drain_array+0x8a/0xb5
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c0463b33>] cache_reap+0x93/0x124
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c042aa3a>] run_workqueue+0x85/0x125
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c061149a>] _spin_lock_irqsave+0x12/0x17
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c0463aa0>] cache_reap+0x0/0x124
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c042b38c>] worker_thread+0xd9/0x105
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c0418c8f>] default_wake_function+0x0/0xc
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c042d9f3>] kthread+0xb0/0xd9
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c042d943>] kthread+0x0/0xd9
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c0405173>] kernel_thread_helper+0x7/0x10
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: =======================
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: Code: 00 00 00 8b 44 24 10 8b 18 8d 93 00 00 00 40 c1 ea 0c c1 e2 05 03 15 84 f6 7d c0 8b 02 f6 c4 40 74 03 8b 52 0c 8b 02 84 c0 78 04 <0f> 0b eb fe 8b 72 1c 8b 54 24 28 89 f0 8b bc 95 94 00 00 00 e8
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: EIP: [<c0462772>] free_block+0x46/0xe5 SS:ESP 0069:c0b16f08
Message from syslogd at debian at Thu Nov 29 17:23:13 2007 ...
debian kernel: [<c042b2b3>] worker_thread+0x0/0x105
and then rebooted itself. the kernel on that machine (a VM) was
2.6.20-1.2933.fc6xen on Debian "lenny/sid".
Paul
--
Building and integrating Virtual Private Networks with Openswan:
http://www.amazon.com/gp/product/1904811256/104-3099591-2946327?n=283155
More information about the Dev
mailing list