(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

On Tue, 17 Aug 2010 20:05:55 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> https://bugzilla.kernel.org/show_bug.cgi?id=16617
> 
>            Summary: inconsistent lock state at boot
>            Product: Memory Management
>            Version: 2.5
>     Kernel Version: 2.6.36-rc1
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: Other
>         AssignedTo: akpm@linux-foundation.org
>         ReportedBy: casteyde.christian@free.fr
>         Regression: Yes
> 
> 
> Kernel 2.6.36-rc1
> Athlon64 X2 4200 in 64bit mode
> Slackware64 13.1
> 1 GB RAM
> 
> Since 2.6.36-rc1 with debug options activated (lock validation, kmemcheck,
> etc.), I get the following error at boot:
> 
> ADDRCONF(NETDEV_UP): eth0: link is not ready
> uli526x: eth0 NIC Link is Up 100 Mbps Full duplex
> ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
> 
> =================================
> [ INFO: inconsistent lock state ]
> 2.6.36-rc1 #2
> ---------------------------------
> inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
> iptables/1915 [HC0[0]:SC0[0]:HE1:SE1] takes:
>  (&(&lock->lock)->rlock){+.?...}, at: [<ffffffff814d7c01>]
> get_counters+0x111/0x1c0
> {IN-SOFTIRQ-W} state was registered at:
>   [<ffffffff81074e66>] __lock_acquire+0xb96/0x1c10
>   [<ffffffff81075f3a>] lock_acquire+0x5a/0x70
>   [<ffffffff81595996>] _raw_spin_lock+0x36/0x50
>   [<ffffffff8152bfc8>] ip6t_do_table+0x88/0x4e0
>   [<ffffffff8152e437>] ip6table_filter_hook+0x17/0x20
>   [<ffffffff8147ef54>] nf_iterate+0x64/0xa0
>   [<ffffffff8147f034>] nf_hook_slow+0xa4/0x150
>   [<ffffffff815196ab>] mld_sendpack+0x28b/0x4d0
>   [<ffffffff8151a10b>] mld_ifc_timer_expire+0x27b/0x310
>   [<ffffffff8104fade>] run_timer_softirq+0x1ae/0x2e0
>   [<ffffffff810499a0>] __do_softirq+0xc0/0x160
>   [<ffffffff8100324c>] call_softirq+0x1c/0x30
>   [<ffffffff81005585>] do_softirq+0x75/0xb0
>   [<ffffffff810494d5>] irq_exit+0x95/0xa0
>   [<ffffffff8101f5fa>] smp_apic_timer_interrupt+0x6a/0xa0
>   [<ffffffff81002d13>] apic_timer_interrupt+0x13/0x20
>   [<ffffffff81165c1d>] ext4_lookup+0x9d/0x110
>   [<ffffffff810d8f1b>] do_lookup+0x1db/0x270
>   [<ffffffff810db135>] link_path_walk+0x445/0xbe0
>   [<ffffffff810dba40>] path_walk+0x60/0xe0
>   [<ffffffff810dbbc3>] do_path_lookup+0x53/0x60
>   [<ffffffff810dc803>] user_path_at+0x53/0xa0
>   [<ffffffff810d2ed7>] vfs_fstatat+0x37/0x70
>   [<ffffffff810d2f46>] vfs_stat+0x16/0x20
>   [<ffffffff810d311f>] sys_newstat+0x1f/0x50
>   [<ffffffff810023ab>] system_call_fastpath+0x16/0x1b
> irq event stamp: 73961
> hardirqs last  enabled at (73961): [<ffffffff810497ae>]
> local_bh_enable+0x7e/0x100
> hardirqs last disabled at (73959): [<ffffffff81049761>]
> local_bh_enable+0x31/0x100
> softirqs last  enabled at (73960): [<ffffffff814d7b6b>]
> get_counters+0x7b/0x1c0
> softirqs last disabled at (73914): [<ffffffff814d7b1e>]
> get_counters+0x2e/0x1c0
> 
> other info that might help us debug this:
> 2 locks held by iptables/1915:
>  #0:  (sk_lock-AF_INET){+.+.+.}, at: [<ffffffff8149c35a>]
> ip_getsockopt+0x6a/0xb0
>  #1:  (&xt[i].mutex){+.+.+.}, at: [<ffffffff8148ac4e>]
> xt_find_table_lock+0x3e/0x120
> 
> stack backtrace:
> Pid: 1915, comm: iptables Not tainted 2.6.36-rc1 #2
> Call Trace:
>  [<ffffffff81072371>] print_usage_bug+0x181/0x1d0
>  [<ffffffff810727d9>] mark_lock+0x419/0x630
>  [<ffffffff81074edc>] __lock_acquire+0xc0c/0x1c10
>  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
>  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
>  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
>  [<ffffffff81075f3a>] lock_acquire+0x5a/0x70
>  [<ffffffff814d7c01>] ? get_counters+0x111/0x1c0
>  [<ffffffff81072d2d>] ? trace_hardirqs_on_caller+0x13d/0x180
>  [<ffffffff81595996>] _raw_spin_lock+0x36/0x50
>  [<ffffffff814d7c01>] ? get_counters+0x111/0x1c0
>  [<ffffffff810497ae>] ? local_bh_enable+0x7e/0x100
>  [<ffffffff814d7c01>] get_counters+0x111/0x1c0
>  [<ffffffff814d7cde>] alloc_counters+0x2e/0x50
>  [<ffffffff814d94cd>] ? do_ipt_get_ctl+0xfd/0x3a0
>  [<ffffffff814d95b1>] do_ipt_get_ctl+0x1e1/0x3a0
>  [<ffffffff81072d7d>] ? trace_hardirqs_on+0xd/0x10
>  [<ffffffff814808b0>] nf_sockopt+0x90/0xa0
>  [<ffffffff814808d3>] nf_getsockopt+0x13/0x20
>  [<ffffffff8149c370>] ip_getsockopt+0x80/0xb0
>  [<ffffffff814ba391>] raw_getsockopt+0x11/0x30
>  [<ffffffff8145242f>] sock_common_getsockopt+0xf/0x20
>  [<ffffffff8144f3d0>] sys_getsockopt+0x60/0xc0
>  [<ffffffff810023ab>] system_call_fastpath+0x16/0x1b
> 
> I haven't managed to find the faulty module.
>

Le lundi 23 août 2010 à 12:18 -0700, Andrew Morton a écrit :
> (switched to email.  Please respond via emailed reply-to-all, not via the
> bugzilla web interface).
> 
> On Tue, 17 Aug 2010 20:05:55 GMT
> bugzilla-daemon@bugzilla.kernel.org wrote:
> 
> > https://bugzilla.kernel.org/show_bug.cgi?id=16617
> > 
> >            Summary: inconsistent lock state at boot
> >            Product: Memory Management
> >            Version: 2.5
> >     Kernel Version: 2.6.36-rc1
> >           Platform: All
> >         OS/Version: Linux
> >               Tree: Mainline
> >             Status: NEW
> >           Severity: normal
> >           Priority: P1
> >          Component: Other
> >         AssignedTo: akpm@linux-foundation.org
> >         ReportedBy: casteyde.christian@free.fr
> >         Regression: Yes
> > 
> > 
> > Kernel 2.6.36-rc1
> > Athlon64 X2 4200 in 64bit mode
> > Slackware64 13.1
> > 1 GB RAM
> > 
> > Since 2.6.36-rc1 with debug options activated (lock validation, kmemcheck,
> > etc.), I get the following error at boot:
> > 
> > ADDRCONF(NETDEV_UP): eth0: link is not ready
> > uli526x: eth0 NIC Link is Up 100 Mbps Full duplex
> > ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
> > 
> > =================================
> > [ INFO: inconsistent lock state ]
> > 2.6.36-rc1 #2
> > ---------------------------------
> > inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
> > iptables/1915 [HC0[0]:SC0[0]:HE1:SE1] takes:
> >  (&(&lock->lock)->rlock){+.?...}, at: [<ffffffff814d7c01>]
> > get_counters+0x111/0x1c0
> > {IN-SOFTIRQ-W} state was registered at:
> >   [<ffffffff81074e66>] __lock_acquire+0xb96/0x1c10
> >   [<ffffffff81075f3a>] lock_acquire+0x5a/0x70
> >   [<ffffffff81595996>] _raw_spin_lock+0x36/0x50
> >   [<ffffffff8152bfc8>] ip6t_do_table+0x88/0x4e0
> >   [<ffffffff8152e437>] ip6table_filter_hook+0x17/0x20
> >   [<ffffffff8147ef54>] nf_iterate+0x64/0xa0
> >   [<ffffffff8147f034>] nf_hook_slow+0xa4/0x150
> >   [<ffffffff815196ab>] mld_sendpack+0x28b/0x4d0
> >   [<ffffffff8151a10b>] mld_ifc_timer_expire+0x27b/0x310
> >   [<ffffffff8104fade>] run_timer_softirq+0x1ae/0x2e0
> >   [<ffffffff810499a0>] __do_softirq+0xc0/0x160
> >   [<ffffffff8100324c>] call_softirq+0x1c/0x30
> >   [<ffffffff81005585>] do_softirq+0x75/0xb0
> >   [<ffffffff810494d5>] irq_exit+0x95/0xa0
> >   [<ffffffff8101f5fa>] smp_apic_timer_interrupt+0x6a/0xa0
> >   [<ffffffff81002d13>] apic_timer_interrupt+0x13/0x20
> >   [<ffffffff81165c1d>] ext4_lookup+0x9d/0x110
> >   [<ffffffff810d8f1b>] do_lookup+0x1db/0x270
> >   [<ffffffff810db135>] link_path_walk+0x445/0xbe0
> >   [<ffffffff810dba40>] path_walk+0x60/0xe0
> >   [<ffffffff810dbbc3>] do_path_lookup+0x53/0x60
> >   [<ffffffff810dc803>] user_path_at+0x53/0xa0
> >   [<ffffffff810d2ed7>] vfs_fstatat+0x37/0x70
> >   [<ffffffff810d2f46>] vfs_stat+0x16/0x20
> >   [<ffffffff810d311f>] sys_newstat+0x1f/0x50
> >   [<ffffffff810023ab>] system_call_fastpath+0x16/0x1b
> > irq event stamp: 73961
> > hardirqs last  enabled at (73961): [<ffffffff810497ae>]
> > local_bh_enable+0x7e/0x100
> > hardirqs last disabled at (73959): [<ffffffff81049761>]
> > local_bh_enable+0x31/0x100
> > softirqs last  enabled at (73960): [<ffffffff814d7b6b>]
> get_counters+0x7b/0x1c0
> > softirqs last disabled at (73914): [<ffffffff814d7b1e>]
> get_counters+0x2e/0x1c0
> > 
> > other info that might help us debug this:
> > 2 locks held by iptables/1915:
> >  #0:  (sk_lock-AF_INET){+.+.+.}, at: [<ffffffff8149c35a>]
> > ip_getsockopt+0x6a/0xb0
> >  #1:  (&xt[i].mutex){+.+.+.}, at: [<ffffffff8148ac4e>]
> > xt_find_table_lock+0x3e/0x120
> > 
> > stack backtrace:
> > Pid: 1915, comm: iptables Not tainted 2.6.36-rc1 #2
> > Call Trace:
> >  [<ffffffff81072371>] print_usage_bug+0x181/0x1d0
> >  [<ffffffff810727d9>] mark_lock+0x419/0x630
> >  [<ffffffff81074edc>] __lock_acquire+0xc0c/0x1c10
> >  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
> >  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
> >  [<ffffffff815957b8>] ? trace_hardirqs_off_thunk+0x3a/0x3c
> >  [<ffffffff81075f3a>] lock_acquire+0x5a/0x70
> >  [<ffffffff814d7c01>] ? get_counters+0x111/0x1c0
> >  [<ffffffff81072d2d>] ? trace_hardirqs_on_caller+0x13d/0x180
> >  [<ffffffff81595996>] _raw_spin_lock+0x36/0x50
> >  [<ffffffff814d7c01>] ? get_counters+0x111/0x1c0
> >  [<ffffffff810497ae>] ? local_bh_enable+0x7e/0x100
> >  [<ffffffff814d7c01>] get_counters+0x111/0x1c0
> >  [<ffffffff814d7cde>] alloc_counters+0x2e/0x50
> >  [<ffffffff814d94cd>] ? do_ipt_get_ctl+0xfd/0x3a0
> >  [<ffffffff814d95b1>] do_ipt_get_ctl+0x1e1/0x3a0
> >  [<ffffffff81072d7d>] ? trace_hardirqs_on+0xd/0x10
> >  [<ffffffff814808b0>] nf_sockopt+0x90/0xa0
> >  [<ffffffff814808d3>] nf_getsockopt+0x13/0x20
> >  [<ffffffff8149c370>] ip_getsockopt+0x80/0xb0
> >  [<ffffffff814ba391>] raw_getsockopt+0x11/0x30
> >  [<ffffffff8145242f>] sock_common_getsockopt+0xf/0x20
> >  [<ffffffff8144f3d0>] sys_getsockopt+0x60/0xc0
> >  [<ffffffff810023ab>] system_call_fastpath+0x16/0x1b
> > 
> > I haven't managed to find the faulty module.
> > 

Already fixed in Linus tree

commit 001389b9581c13fe5fc357a0f89234f85af4215d
Author: Eric Dumazet <eric.dumazet@gmail.com>
Date:   Mon Aug 16 10:22:10 2010 +0000

    netfilter: {ip,ip6,arp}_tables: avoid lockdep false positive
    
    After commit 24b36f019 (netfilter: {ip,ip6,arp}_tables: dont block
    bottom half more than necessary), lockdep can raise a warning
    because we attempt to lock a spinlock with BH enabled, while
    the same lock is usually locked by another cpu in a softirq context.
    
    Disable again BH to avoid these lockdep warnings.
    
    Reported-by: Linus Torvalds <torvalds@linux-foundation.org>
    Diagnosed-by: David S. Miller <davem@davemloft.net>
    Signed-off-by: Eric Dumazet <eric.dumazet@gmail.com>
    Signed-off-by: David S. Miller <davem@davemloft.net>