[bug] xfrm_state_lock: possible circular locking dependency detected

[bug] xfrm_state_lock: possible circular locking dependency detected

[Ingo Molnar]

DaveJ's Fedora 8 rpm for 2.6.24 works petty well, except for the 
neworking related lockdep assert attached below, which happened while 
starting up ipsec. Let me know if you need any more info - it's a pretty 
stock setup.

	Ingo

=======================================================
[ INFO: possible circular locking dependency detected ]
2.6.24-0.39.rc3.git1.fc9 #1
-------------------------------------------------------
ip/25091 is trying to acquire lock:
 (&x->lock){-+..}, at: [<c06330d6>] copy_to_user_state_extra+0x1a/0x156

but task is already holding lock:
 (xfrm_state_lock){-+..}, at: [<c06308d2>] xfrm_state_walk+0x1e/0xb9

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (xfrm_state_lock){-+..}:
       [<c044dc17>] __lock_acquire+0xa7c/0xc4d
       [<c044e262>] lock_acquire+0x7b/0x9e
       [<c064147d>] _spin_lock_bh+0x33/0x5d
       [<c062eabf>] xfrm_state_lookup+0x1e/0x45
       [<c06317c0>] xfrm_alloc_spi+0xbc/0x17c
       [<c063505d>] xfrm_alloc_userspi+0xe5/0x168
       [<c0633de7>] xfrm_user_rcv_msg+0xba/0xcd
       [<c05ee161>] netlink_rcv_skb+0x30/0x82
       [<c06338d7>] xfrm_netlink_rcv+0x1e/0x2b
       [<c05edf35>] netlink_unicast+0x19f/0x208
       [<c05ee762>] netlink_sendmsg+0x279/0x285
       [<c05cd303>] sock_aio_write+0xe8/0xf4
       [<c049360e>] do_sync_write+0xc5/0x102
       [<c0493e2a>] vfs_write+0xbc/0x15c
       [<c049447d>] sys_write+0x3d/0x61
       [<c0405252>] syscall_call+0x7/0xb
       [<ffffffff>] 0xffffffff

-> #0 (&x->lock){-+..}:
       [<c044db07>] __lock_acquire+0x96c/0xc4d
       [<c044e262>] lock_acquire+0x7b/0x9e
       [<c064147d>] _spin_lock_bh+0x33/0x5d
       [<c06330d6>] copy_to_user_state_extra+0x1a/0x156
       [<c06337c4>] dump_one_state+0xb9/0x138
       [<c063090d>] xfrm_state_walk+0x59/0xb9
       [<c0633bbf>] xfrm_dump_sa+0x3f/0x4f
       [<c05ed306>] netlink_dump+0x52/0x16a
       [<c05ef1ae>] netlink_dump_start+0x104/0x141
       [<c0633d99>] xfrm_user_rcv_msg+0x6c/0xcd
       [<c05ee161>] netlink_rcv_skb+0x30/0x82
       [<c06338d7>] xfrm_netlink_rcv+0x1e/0x2b
       [<c05edf35>] netlink_unicast+0x19f/0x208
       [<c05ee762>] netlink_sendmsg+0x279/0x285
       [<c05cda10>] sock_sendmsg+0xe0/0xfd
       [<c05ce34b>] sys_sendto+0xcc/0xec
       [<c05ceb98>] sys_socketcall+0x16b/0x241
       [<c0405252>] syscall_call+0x7/0xb
       [<ffffffff>] 0xffffffff

other info that might help us debug this:

3 locks held by ip/25091:
 #0:  (xfrm_cfg_mutex){--..}, at: [<c06338cb>] xfrm_netlink_rcv+0x12/0x2b
 #1:  (nlk->cb_mutex){--..}, at: [<c05ed2ee>] netlink_dump+0x3a/0x16a
 #2:  (xfrm_state_lock){-+..}, at: [<c06308d2>] xfrm_state_walk+0x1e/0xb9

stack backtrace:
 [<c040649a>] show_trace_log_lvl+0x1a/0x2f
 [<c0406d46>] show_trace+0x12/0x14
 [<c0406e51>] dump_stack+0x16/0x18
 [<c044c069>] print_circular_bug_tail+0x5f/0x68
 [<c044db07>] __lock_acquire+0x96c/0xc4d
 [<c044e262>] lock_acquire+0x7b/0x9e
 [<c064147d>] _spin_lock_bh+0x33/0x5d
 [<c06330d6>] copy_to_user_state_extra+0x1a/0x156
 [<c06337c4>] dump_one_state+0xb9/0x138
 [<c063090d>] xfrm_state_walk+0x59/0xb9
 [<c0633bbf>] xfrm_dump_sa+0x3f/0x4f
 [<c05ed306>] netlink_dump+0x52/0x16a
 [<c05ef1ae>] netlink_dump_start+0x104/0x141
 [<c0633d99>] xfrm_user_rcv_msg+0x6c/0xcd
 [<c05ee161>] netlink_rcv_skb+0x30/0x82
 [<c06338d7>] xfrm_netlink_rcv+0x1e/0x2b
 [<c05edf35>] netlink_unicast+0x19f/0x208
 [<c05ee762>] netlink_sendmsg+0x279/0x285
 [<c05cda10>] sock_sendmsg+0xe0/0xfd
 [<c05ce34b>] sys_sendto+0xcc/0xec
 [<c05ceb98>] sys_socketcall+0x16b/0x241
 [<c0405252>] syscall_call+0x7/0xb
 =======================
NET: Unregistered protocol family 15
NET: Registered protocol family 15

Re: [bug] xfrm_state_lock: possible circular locking dependency detected

[Herbert Xu]

On Fri, Nov 23, 2007 at 04:38:51PM +0100, Ingo Molnar wrote:
> 
> DaveJ's Fedora 8 rpm for 2.6.24 works petty well, except for the 
> neworking related lockdep assert attached below, which happened while 
> starting up ipsec. Let me know if you need any more info - it's a pretty 
> stock setup.

Thanks for the report Ingo!

This is indeed a regression caused by:

commit 050f009e16f908932070313c1745d09dc69fd62b
Author: Herbert Xu <herbert@gondor.apana.org.au>
Date:   Tue Oct 9 13:31:47 2007 -0700

    [IPSEC]: Lock state when copying non-atomic fields to user-space

For 2.6.24 I'm simply going to revert this change since that
just puts us back to the same state we've been for the last
few years.

For 2.6.25 I'll do a proper fix by making sure that every xfrm
state user obeys the rule that if x->lock is to be taken with
xfrm_state_lock then it must be done from within.

Cheers,
-- 
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: [bug] xfrm_state_lock: possible circular locking dependency detected

[Ingo Molnar]

* Herbert Xu <herbert@gondor.apana.org.au> wrote:

> On Fri, Nov 23, 2007 at 04:38:51PM +0100, Ingo Molnar wrote:
> > 
> > DaveJ's Fedora 8 rpm for 2.6.24 works petty well, except for the 
> > neworking related lockdep assert attached below, which happened while 
> > starting up ipsec. Let me know if you need any more info - it's a pretty 
> > stock setup.
> 
> Thanks for the report Ingo!
> 
> This is indeed a regression caused by:
> 
> commit 050f009e16f908932070313c1745d09dc69fd62b
> Author: Herbert Xu <herbert@gondor.apana.org.au>
> Date:   Tue Oct 9 13:31:47 2007 -0700
> 
>     [IPSEC]: Lock state when copying non-atomic fields to user-space
> 
> For 2.6.24 I'm simply going to revert this change since that just puts 
> us back to the same state we've been for the last few years.
> 
> For 2.6.25 I'll do a proper fix by making sure that every xfrm state 
> user obeys the rule that if x->lock is to be taken with 
> xfrm_state_lock then it must be done from within.

ok, great. I cannot test the revert because i only run distro kernels on 
this box so i can only confirm that the bug is gone once your revert is 
upstream and DaveJ has built a new Fedora kernel for it (which is 1-2 
days after the commit goes upstream). So consider it fixed once you do 
the revert and i'll re-report it if i see any similar assert on a kernel 
that has this commit reverted.

	Ingo