neigh_lookup lockdep bug.

neigh_lookup lockdep bug.

[Dave Jones]

2.6.18rc2-gitSomething on my firewall box just triggered this..

		Dave

[515613.791771] =======================================================
[515613.841467] [ INFO: possible circular locking dependency detected ]
[515613.873284] -------------------------------------------------------
[515613.904945] swapper/0 is trying to acquire lock:
[515613.931489]  (&tbl->lock){-+-+}, at: [<c05b5d63>] neigh_lookup+0x50/0xaf
[515613.964369] 
[515613.964373] but task is already holding lock:
[515614.006550]  (&skb_queue_lock_key){-+..}, at: [<c05b741c>] neigh_proxy_process+0x20/0xc2
[515614.043225] 
[515614.043228] which lock already depends on the new lock.
[515614.043234] 
[515614.103456] 
[515614.103459] the existing dependency chain (in reverse order) is:
[515614.148752] 
[515614.148755] -> #2 (&skb_queue_lock_key){-+..}:
[515614.188880]        [<c043bf43>] lock_acquire+0x4b/0x6c
[515614.215554]        [<c06089a7>] _spin_lock_irqsave+0x22/0x32
[515614.243606]        [<c05ac2e3>] skb_dequeue+0x12/0x43
[515614.269657]        [<c05acffe>] skb_queue_purge+0x14/0x1b
[515614.296565]        [<c05b673e>] neigh_update+0x317/0x353
[515614.323004]        [<c05e8a0b>] arp_process+0x4aa/0x4e4
[515614.349004]        [<c05e8b19>] arp_rcv+0xd4/0xf1
[515614.373209]        [<c05b1210>] netif_receive_skb+0x204/0x271
[515614.400405]        [<c05b2b73>] process_backlog+0x99/0xfa
[515614.426351]        [<c05b2d56>] net_rx_action+0x9d/0x196
[515614.451856]        [<c04293d5>] __do_softirq+0x78/0xf2
[515614.476660]        [<c040662f>] do_softirq+0x5a/0xbe
[515614.500737] 
[515614.500741] -> #1 (&n->lock){-+-+}:
[515614.532763]        [<c043bf43>] lock_acquire+0x4b/0x6c
[515614.556814]        [<c06086d0>] _write_lock+0x19/0x28
[515614.580398]        [<c05b7a0e>] neigh_periodic_timer+0x98/0x13c
[515614.606447]        [<c042db48>] run_timer_softirq+0x108/0x167
[515614.631798]        [<c04293d5>] __do_softirq+0x78/0xf2
[515614.655122]        [<c040662f>] do_softirq+0x5a/0xbe
[515614.677721] 
[515614.677724] -> #0 (&tbl->lock){-+-+}:
[515614.707327]        [<c043bf43>] lock_acquire+0x4b/0x6c
[515614.729897]        [<c060878a>] _read_lock_bh+0x1e/0x2d
[515614.752546]        [<c05b5d63>] neigh_lookup+0x50/0xaf
[515614.774754]        [<c05b6e5e>] neigh_event_ns+0x2c/0x77
[515614.797271]        [<c05e88c7>] arp_process+0x366/0x4e4
[515614.819349]        [<c05e8b3e>] parp_redo+0x8/0xa
[515614.839660]        [<c05b7462>] neigh_proxy_process+0x66/0xc2
[515614.862931]        [<c042db48>] run_timer_softirq+0x108/0x167
[515614.886048]        [<c04293d5>] __do_softirq+0x78/0xf2
[515614.907136]        [<c040662f>] do_softirq+0x5a/0xbe
[515614.927553] 
[515614.927557] other info that might help us debug this:
[515614.927563] 
[515614.966774] 1 lock held by swapper/0:
[515614.982693]  #0:  (&skb_queue_lock_key){-+..}, at: [<c05b741c>] neigh_proxy_process+0x20/0xc2
[515615.013575] 
[515615.013578] stack backtrace:
[515615.037414]  [<c04051ea>] show_trace_log_lvl+0x54/0xfd
[515615.057910]  [<c04057a6>] show_trace+0xd/0x10
[515615.075934]  [<c04058bf>] dump_stack+0x19/0x1b
[515615.094167]  [<c043b030>] print_circular_bug_tail+0x59/0x64
[515615.116172]  [<c043b843>] __lock_acquire+0x808/0x997
[515615.136514]  [<c043bf43>] lock_acquire+0x4b/0x6c
[515615.155699]  [<c060878a>] _read_lock_bh+0x1e/0x2d
[515615.175098]  [<c05b5d63>] neigh_lookup+0x50/0xaf
[515615.197276]  [<c05b6e5e>] neigh_event_ns+0x2c/0x77
[515615.220267]  [<c05e88c7>] arp_process+0x366/0x4e4
[515615.243248]  [<c05e8b3e>] parp_redo+0x8/0xa
[515615.264645]  [<c05b7462>] neigh_proxy_process+0x66/0xc2
[515615.288899]  [<c042db48>] run_timer_softirq+0x108/0x167
[515615.309972]  [<c04293d5>] __do_softirq+0x78/0xf2
[515615.328940]  [<c040662f>] do_softirq+0x5a/0xbe
[515615.347150]  [<c042927e>] irq_exit+0x3d/0x3f
[515615.365067]  [<c0417cbb>] smp_apic_timer_interrupt+0x79/0x7e
[515615.387057]  [<c0404b0a>] apic_timer_interrupt+0x2a/0x30


-- 
http://www.codemonkey.org.uk

Re: neigh_lookup lockdep bug.

[David Miller]

From: Dave Jones <davej@redhat.com>
Date: Mon, 31 Jul 2006 16:50:04 -0400

> 2.6.18rc2-gitSomething on my firewall box just triggered this..

Lockdep is perhaps confused.

> [515613.904945] swapper/0 is trying to acquire lock:
> [515613.931489]  (&tbl->lock){-+-+}, at: [<c05b5d63>] neigh_lookup+0x50/0xaf
> [515613.964369] 
> [515613.964373] but task is already holding lock:
> [515614.006550]  (&skb_queue_lock_key){-+..}, at: [<c05b741c>] neigh_proxy_process+0x20/0xc2

The skb_queue_lock in question is &tbl->proxy_queue.lock

> [515614.103459] the existing dependency chain (in reverse order) is:
> [515614.148752] 
> [515614.148755] -> #2 (&skb_queue_lock_key){-+..}:
> [515614.188880]        [<c043bf43>] lock_acquire+0x4b/0x6c
> [515614.215554]        [<c06089a7>] _spin_lock_irqsave+0x22/0x32
> [515614.243606]        [<c05ac2e3>] skb_dequeue+0x12/0x43
> [515614.269657]        [<c05acffe>] skb_queue_purge+0x14/0x1b
> [515614.296565]        [<c05b673e>] neigh_update+0x317/0x353

This is a different queue lock, namely &neigh->arp_queue.lock

Like the ipv6 trace we got yesterday from Matt Domsche, lockdep
is aparently confusing two instances of the skb_queue_lock_key

> [515614.677724] -> #0 (&tbl->lock){-+-+}:
> [515614.707327]        [<c043bf43>] lock_acquire+0x4b/0x6c
> [515614.729897]        [<c060878a>] _read_lock_bh+0x1e/0x2d
> [515614.752546]        [<c05b5d63>] neigh_lookup+0x50/0xaf
> [515614.774754]        [<c05b6e5e>] neigh_event_ns+0x2c/0x77
> [515614.797271]        [<c05e88c7>] arp_process+0x366/0x4e4
> [515614.819349]        [<c05e8b3e>] parp_redo+0x8/0xa
> [515614.839660]        [<c05b7462>] neigh_proxy_process+0x66/0xc2
> [515614.862931]        [<c042db48>] run_timer_softirq+0x108/0x167
> [515614.886048]        [<c04293d5>] __do_softirq+0x78/0xf2
> [515614.907136]        [<c040662f>] do_softirq+0x5a/0xbe
> [515614.927553] 

And this path takes &neigh->proxy_queue.lock, then &tbl->lock

I don't see the problem.

Re: neigh_lookup lockdep bug.

[Arjan van de Ven]

On Mon, 2006-07-31 at 14:02 -0700, David Miller wrote:
> From: Dave Jones <davej@redhat.com>
> Date: Mon, 31 Jul 2006 16:50:04 -0400
> 
> > 2.6.18rc2-gitSomething on my firewall box just triggered this..
> 
> Lockdep is perhaps confused.
> 
> > [515613.904945] swapper/0 is trying to acquire lock:
> > [515613.931489]  (&tbl->lock){-+-+}, at: [<c05b5d63>] neigh_lookup+0x50/0xaf
> > [515613.964369] 
> > [515613.964373] but task is already holding lock:
> > [515614.006550]  (&skb_queue_lock_key){-+..}, at: [<c05b741c>] neigh_proxy_process+0x20/0xc2
> 
> The skb_queue_lock in question is &tbl->proxy_queue.lock
> 
> > [515614.103459] the existing dependency chain (in reverse order) is:
> > [515614.148752] 
> > [515614.148755] -> #2 (&skb_queue_lock_key){-+..}:
> > [515614.188880]        [<c043bf43>] lock_acquire+0x4b/0x6c
> > [515614.215554]        [<c06089a7>] _spin_lock_irqsave+0x22/0x32
> > [515614.243606]        [<c05ac2e3>] skb_dequeue+0x12/0x43
> > [515614.269657]        [<c05acffe>] skb_queue_purge+0x14/0x1b
> > [515614.296565]        [<c05b673e>] neigh_update+0x317/0x353
> 
> This is a different queue lock, namely &neigh->arp_queue.lock
> 
> Like the ipv6 trace we got yesterday from Matt Domsche, lockdep
> is aparently confusing two instances of the skb_queue_lock_key

we fixed lockdep to have this lock key to be per skb queue ... didn't
you put that patch in rawhide Dave (J) ?

Re: neigh_lookup lockdep bug.

[Herbert Xu]

Arjan van de Ven <arjan@infradead.org> wrote:
> 
> we fixed lockdep to have this lock key to be per skb queue ... didn't
> you put that patch in rawhide Dave (J) ?

I've only briefly looked at the lockdep_set_class code so I might be
way off here.

It seems that for lockdep_set_class to work its second argument should
be distinct for each class of locks that you wish to distinguish.  So
shouldn't we be putting the key into struct sk_buff_head rather than
having one key (skb_queue_lock_key) for all sk_buff_head's?

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: neigh_lookup lockdep bug.

[Arjan van de Ven]

On Tue, 2006-08-01 at 23:19 +1000, Herbert Xu wrote:
> 
> I've only briefly looked at the lockdep_set_class code so I might be
> way off here.

your reading of the code is right, and in fact this is what the code in
-mm does, and is waiting for the networking guys or Andrew to send it to
Linus (hint hint)


Greetings,
   Arjan van de Ven

-- 
if you want to mail me at work (you don't), use arjan (at) linux.intel.com

Re: neigh_lookup lockdep bug.

[Arjan van de Ven]

On Tue, 2006-08-01 at 23:19 +1000, Herbert Xu wrote:
> Arjan van de Ven <arjan@infradead.org> wrote:
> > 
> > we fixed lockdep to have this lock key to be per skb queue ... didn't
> > you put that patch in rawhide Dave (J) ?
> 
> I've only briefly looked at the lockdep_set_class code so I might be
> way off here.
> 
> It seems that for lockdep_set_class to work its second argument should
> be distinct for each class of locks that you wish to distinguish.  So
> shouldn't we be putting the key into struct sk_buff_head rather than
> having one key (skb_queue_lock_key) for all sk_buff_head's?
> 

fwiw the patch is at
http://www.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.18-rc2/2.6.18-rc2-mm1/broken-out/lockdep-split-the-skb_queue_head_init-lock-class.patch
and a followup cleanup at
http://www.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.18-rc2/2.6.18-rc2-mm1/broken-out/lockdep-split-the-skb_queue_head_init-lock-class-tidy.patch

Re: neigh_lookup lockdep bug.

[David Miller]

From: Arjan van de Ven <arjan@infradead.org>
Date: Wed, 02 Aug 2006 04:26:49 +0200

> fwiw the patch is at
> http://www.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.18-rc2/2.6.18-rc2-mm1/broken-out/lockdep-split-the-skb_queue_head_init-lock-class.patch
> and a followup cleanup at
> http://www.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.18-rc2/2.6.18-rc2-mm1/broken-out/lockdep-split-the-skb_queue_head_init-lock-class-tidy.patch

Both applied, thanks.