Re: Regression, bisected: WARNING spam with ipsec since 2.6.35

From: Eric Dumazet
Date: Thu Sep 16 2010 - 18:28:00 EST


Le jeudi 16 septembre 2010 Ã 17:31 -0400, Nick Bowler a Ãcrit :
> Attempting to use IPSec since 2.6.35 has resulted in WARNINGs (one of
> them is included further down) being spammed to the kernel log. The
> packets seem to be transmitted fine, but the constant printk's degrade
> performance to the point of uselessness (there are about a half dozen
> call traces for every packet transmitted). I've attached the full log
> after booting the kernel, running the setkey script, and sending a
> single ping.
>
> This is the setkey script I used to produce the issue:
>
> add 192.168.0.1 192.168.0.2 esp 0x6B8B4567 -f seq-pad
> -E rijndael-cbc 0x643C98696633487374B0DC5119495CFF
> -A null;
>
> add 192.168.0.2 192.168.0.1 esp 0x327B23C6 -f seq-pad
> -E rijndael-cbc 0x3D1B58BA507ED7AB2EB141F241B71EFB
> -A null;
>
> spdadd 192.168.0.2 192.168.0.1 any -P out ipsec
> esp/transport//require;
> spdadd 192.168.0.1 192.168.0.2 any -P in ipsec
> esp/transport//require;
>
> and here's the first warning:
>
> ------------[ cut here ]------------
> WARNING: at include/linux/skbuff.h:472 xfrm_output_resume+0x4b8/0x50d()
> Hardware name:
> Modules linked in: authenc esp4 deflate zlib_deflate ctr aes_generic des_generic cbc sha256_generic sha1_generic md5 crypto_null af_key autofs4 sunrpc iptable_filter ip_tables ip6t_REJECT xt_tcpudp nf_conntrack_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables x_tables ipv6 loop parport_pc sg psmouse parport evdev skge rng_core button ext4 mbcache jbd2 crc16 sr_mod sd_mod cdrom ata_piix libata ehci_hcd uhci_hcd scsi_mod usbcore dm_mod [last unloaded: scsi_wait_scan]
> Pid: 2391, comm: ping Not tainted 2.6.35 #3
> Call Trace:
> [<c102e21f>] warn_slowpath_common+0x65/0x7a
> [<c127ee2e>] ? xfrm_output_resume+0x4b8/0x50d
> [<c102e243>] warn_slowpath_null+0xf/0x13
> [<c127ee2e>] xfrm_output_resume+0x4b8/0x50d
> [<c127ee90>] xfrm_output2+0xd/0xf
> [<c127ef57>] xfrm_output+0xc5/0xce
> [<c1277f55>] xfrm4_output_finish+0xa1/0xa4
> [<c1277fe0>] xfrm4_output+0x88/0x8f
> [<c124ce58>] ip_local_out+0x50/0x53
> [<c124d0c4>] ip_push_pending_frames+0x269/0x2b2
> [<c126578f>] raw_sendmsg+0x614/0x691
> [<c1051c01>] ? trace_hardirqs_on_caller+0x1e/0x121
> [<c126d46c>] inet_sendmsg+0xbd/0xc6
> [<c1223f62>] sock_sendmsg+0xa5/0xbb
> [<c108deb6>] ? might_fault+0x6e/0x88
> [<c108deb6>] ? might_fault+0x6e/0x88
> [<c122bd43>] ? verify_iovec+0x3e/0x6b
> [<c1224368>] sys_sendmsg+0x149/0x196
> [<c1023c2b>] ? get_parent_ip+0xb/0x31
> [<c107e377>] ? unlock_page+0x3b/0x3e
> [<c108f99a>] ? handle_mm_fault+0x219/0x49b
> [<c1053d13>] ? lock_release_non_nested+0x86/0x221
> [<c108deb6>] ? might_fault+0x6e/0x88
> [<c108deb6>] ? might_fault+0x6e/0x88
> [<c12255ba>] sys_socketcall+0x146/0x18b
> [<c110b4b4>] ? trace_hardirqs_on_thunk+0xc/0x10
> [<c1002690>] sysenter_do_call+0x12/0x36
> ---[ end trace c8ae605bd7809dcc ]---
>
> Bisection implicates the following commit:
>
> 8764ab2ca7ab5055e1ca80f9cfa4970c34acb804 is the first bad commit
> commit 8764ab2ca7ab5055e1ca80f9cfa4970c34acb804
> Author: Steffen Klassert <steffen.klassert@xxxxxxxxxxx>
> Date: Fri Jun 4 01:57:38 2010 +0000
>
> net: check for refcount if pop a stacked dst_entry
>
> xfrm triggers a warning if dst_pop() drops a refcount
> on a noref dst. This patch changes dst_pop() to
> skb_dst_pop(). skb_dst_pop() drops the refcnt only
> on a refcounted dst. Also we don't clone the child
> dst_entry, so it is not refcounted and we can use
> skb_dst_set_noref() in xfrm_output_one().
>
> Signed-off-by: Steffen Klassert <steffen.klassert@xxxxxxxxxxx>
> Signed-off-by: Eric Dumazet <eric.dumazet@xxxxxxxxx>
> Signed-off-by: David S. Miller <davem@xxxxxxxxxxxxx>
>
> :040000 040000 3f0e1574919d0e581b3e9537a4d59ce397a926f1 f272ab5b895c46b3166d321a2da759c2a6e08ae0 M include
> :040000 040000 a4fbff22e9ae9f57f4f8c5416f5a7be186635cab eb04849588cbe4b2b99030c2aa59e3433187c6df M net
>
> git bisect start
> # bad: [9c03f1622af051004416dd3e24d8a0fa31e34178] Merge ssh://master.kernel.org/home/hpa/tree/sec
> git bisect bad 9c03f1622af051004416dd3e24d8a0fa31e34178
> # bad: [9fe6206f400646a2322096b56c59891d530e8d51] Linux 2.6.35
> git bisect bad 9fe6206f400646a2322096b56c59891d530e8d51
> # good: [e40152ee1e1c7a63f4777791863215e3faa37a86] Linus 2.6.34
> git bisect good e40152ee1e1c7a63f4777791863215e3faa37a86
> # good: [e0bc5d4a54938eedcde14005210e6c08aa9727e4] Merge branch 'i2c-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jdelvare/staging
> git bisect good e0bc5d4a54938eedcde14005210e6c08aa9727e4
> # good: [d30fda355188272430d3865db2ff9e24b4135ae3] posix-cpu-timers: avoid "task->signal != NULL" checks
> git bisect good d30fda355188272430d3865db2ff9e24b4135ae3
> # good: [9a9620db07b27700a4de9e86985735fffb78e2f8] Merge branch 'linux_next' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/i7core
> git bisect good 9a9620db07b27700a4de9e86985735fffb78e2f8
> # bad: [985b823b919273fe1327d56d2196b4f92e5d0fae] drm/i915: fix hibernation since i915 self-reclaim fixes
> git bisect bad 985b823b919273fe1327d56d2196b4f92e5d0fae
> # bad: [b5edfefc65526b34960bbff3477ded477b0328f6] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jmorris/security-testing-2.6
> git bisect bad b5edfefc65526b34960bbff3477ded477b0328f6
> # bad: [fcdcddbcbbd39a3363bd48414bfe44553b6d698a] microblaze: Fix sg_dma_len() regression
> git bisect bad fcdcddbcbbd39a3363bd48414bfe44553b6d698a
> # bad: [ed7dc1dfbcef301407a1e3138a49dc94e5a19d0a] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6
> git bisect bad ed7dc1dfbcef301407a1e3138a49dc94e5a19d0a
> # good: [90ec7819737d42a0ad1c2df1ff56016facae3c6e] Merge git://git.kernel.org/pub/scm/linux/kernel/git/rusty/linux-2.6-for-linus
> git bisect good 90ec7819737d42a0ad1c2df1ff56016facae3c6e
> # good: [a1868dc2878e61778b9d6d8c61d5368e51d68a29] ixgbe: return IXGBE_ERR_RAR_INDEX when out of range
> git bisect good a1868dc2878e61778b9d6d8c61d5368e51d68a29
> # good: [7926e0bfbbc5ff81ddad0fda831eef7060e40997] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/ryusuke/nilfs2
> git bisect good 7926e0bfbbc5ff81ddad0fda831eef7060e40997
> # bad: [ca739481662137b8f717bc21f16719cda3c33d6b] ixgbe: only check pfc bits in hang logic if pfc is enabled
> git bisect bad ca739481662137b8f717bc21f16719cda3c33d6b
> # good: [51a0d38de26226f2779912d92f155b93d539da9a] mac80211: fix dialog token allocator
> git bisect good 51a0d38de26226f2779912d92f155b93d539da9a
> # bad: [8764ab2ca7ab5055e1ca80f9cfa4970c34acb804] net: check for refcount if pop a stacked dst_entry
> git bisect bad 8764ab2ca7ab5055e1ca80f9cfa4970c34acb804
> # good: [4f4aeb7fd0f7e6ca008bb2147ba36cee13876595] Merge branch 'master' of git://git.kernel.org/pub/scm/linux/kernel/git/linville/wireless-2.6
> git bisect good 4f4aeb7fd0f7e6ca008bb2147ba36cee13876595
>

Thanks Nick !

CC netdev

ip_local_out() is called with rcu_read_lock() from ip_queue_xmit()
but not from other call sites.

I suspect following patch is needed, before further changes.


[PATCH] xfrm: dont assume rcu_read_lock in xfrm_output_one()

ip_local_out() is called with rcu_read_lock() held from ip_queue_xmit()
but not from other call sites.

Reported-and-bisected-by: Nick Bowler <nbowler@xxxxxxxxxxxxxxxx>
Signed-off-by: Eric Dumazet <eric.dumazet@xxxxxxxxx>
---
net/xfrm/xfrm_output.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/net/xfrm/xfrm_output.c b/net/xfrm/xfrm_output.c
index a3cca0a..64f2ae1 100644
--- a/net/xfrm/xfrm_output.c
+++ b/net/xfrm/xfrm_output.c
@@ -101,7 +101,7 @@ resume:
err = -EHOSTUNREACH;
goto error_nolock;
}
- skb_dst_set_noref(skb, dst);
+ skb_dst_set(skb, dst_clone(dst));
x = dst->xfrm;
} while (x && !(x->outer_mode->flags & XFRM_MODE_FLAG_TUNNEL));



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