Date:	Thu, 16 Sep 2010 17:31:38 -0400
From:	Nick Bowler <nbowler@...iptictech.com>
To:	linux-kernel@...r.kernel.org
Subject: Regression, bisected: WARNING spam with ipsec since 2.6.35

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@...unet.com>
  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@...unet.com>
      Signed-off-by: Eric Dumazet <eric.dumazet@...il.com>
      Signed-off-by: David S. Miller <davem@...emloft.net>
  
  :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

-- 
Nick Bowler, Elliptic Technologies (http://www.elliptictech.com/)

View attachment "ipsec-trace.log" of type "text/plain" (43658 bytes)

Powered by blists - more mailing lists