Bug 15761

Summary: Warning in ath9k after update from 2.6.33.1 to 2.6.33.2
Product: Drivers Reporter: Maciej Rutecki (maciej.rutecki)
Component: network-wirelessAssignee: Greg Kroah-Hartman (greg)
Status: CLOSED CODE_FIX    
Severity: normal CC: caravena, florian, greg, linville, maciej.rutecki, rjw, sw, thomas, tom.leiming
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.33.2 Subsystem:
Regression: Yes Bisected commit-id:
Bug Depends on:    
Bug Blocks: 14885    

Description Maciej Rutecki 2010-04-11 14:05:36 UTC
Subject    : Warning in ath9k after update from 2.6.33.1 to 2.6.33.2
Submitter  : Thomas Bächler <thomas@archlinux.org>
Date       : 2010-04-09 17:21
Message-ID : 4BBF6206.2070103@archlinux.org
References : http://marc.info/?l=linux-kernel&m=127083430918613&w=2

This entry is being used for tracking a regression from 2.6.32.  Please don't
close it until the problem is fixed in the mainline.
Comment 1 John W. Linville 2010-04-12 13:12:36 UTC
*** Bug 15763 has been marked as a duplicate of this bug. ***
Comment 2 John W. Linville 2010-04-12 13:20:01 UTC
So this one might not be right for stable afterall (or might require different backporting)...

commit 0524bcfa80f1fffb4e1fe18a0a28900869a58a7c
Author: Ming Lei <tom.leiming@gmail.com>
Date:   Sun Feb 28 00:56:24 2010 +0800

    ath9k: fix lockdep warning when unloading module
    
    commit a9f042cbe5284f34ccff15f3084477e11b39b17b upstream.
    
    Since txq->axq_lock may be hold in softirq context, it must be
    acquired with spin_lock_bh() instead of spin_lock() if softieq is
    enabled.
    
    The patch fixes the lockdep warning below when unloading ath9k modules.
    
    =================================
    [ INFO: inconsistent lock state ]
    2.6.33-wl #12
    ---------------------------------
    inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
    rmmod/3642 [HC0[0]:SC0[0]:HE1:SE1] takes:
     (&(&txq->axq_lock)->rlock){+.?...}, at: [<ffffffffa03568c3>] ath_tx_node_cl
    {IN-SOFTIRQ-W} state was registered at:
      [<ffffffff8107577d>] __lock_acquire+0x2f6/0xd35
      [<ffffffff81076289>] lock_acquire+0xcd/0xf1
      [<ffffffff813a7486>] _raw_spin_lock_bh+0x3b/0x6e
      [<ffffffffa0356b49>] spin_lock_bh+0xe/0x10 [ath9k]
      [<ffffffffa0358ec7>] ath_tx_tasklet+0xcd/0x391 [ath9k]
      [<ffffffffa0354f5f>] ath9k_tasklet+0x70/0xc8 [ath9k]
      [<ffffffff8104e601>] tasklet_action+0x8c/0xf4
      [<ffffffff8104f459>] __do_softirq+0xf8/0x1cd
      [<ffffffff8100ab1c>] call_softirq+0x1c/0x30
      [<ffffffff8100c2cf>] do_softirq+0x4b/0xa3
      [<ffffffff8104f045>] irq_exit+0x4a/0x8c
      [<ffffffff813acccc>] do_IRQ+0xac/0xc3
      [<ffffffff813a7d53>] ret_from_intr+0x0/0x16
      [<ffffffff81302d52>] cpuidle_idle_call+0x9e/0xf8
      [<ffffffff81008be7>] cpu_idle+0x62/0x9d
      [<ffffffff81391c1a>] rest_init+0x7e/0x80
      [<ffffffff818bbd38>] start_kernel+0x3e8/0x3f3
      [<ffffffff818bb2bc>] x86_64_start_reservations+0xa7/0xab
      [<ffffffff818bb3b8>] x86_64_start_kernel+0xf8/0x107
    irq event stamp: 42037
    hardirqs last  enabled at (42037): [<ffffffff813a7b21>] _raw_spin_unlock_irq
    hardirqs last disabled at (42036): [<ffffffff813a72f4>] _raw_spin_lock_irqsa
    softirqs last  enabled at (42000): [<ffffffffa0353ea6>] spin_unlock_bh+0xe/0
    softirqs last disabled at (41998): [<ffffffff813a7463>] _raw_spin_lock_bh+0x
    
    other info that might help us debug this:
    4 locks held by rmmod/3642:
     #0:  (rtnl_mutex){+.+.+.}, at: [<ffffffff8132c10d>] rtnl_lock+0x17/0x19
     #1:  (&wdev->mtx){+.+.+.}, at: [<ffffffffa01e53f2>] cfg80211_netdev_notifie
     #2:  (&ifmgd->mtx){+.+.+.}, at: [<ffffffffa0260834>] ieee80211_mgd_deauth+0
     #3:  (&local->sta_mtx){+.+.+.}, at: [<ffffffffa025a381>] sta_info_destroy_a
    
    stack backtrace:
    Pid: 3642, comm: rmmod Not tainted 2.6.33-wl #12
    Call Trace:
     [<ffffffff81074469>] valid_state+0x178/0x18b
     [<ffffffff81014f94>] ? save_stack_trace+0x2f/0x4c
     [<ffffffff81074e08>] ? check_usage_backwards+0x0/0x88
     [<ffffffff8107458f>] mark_lock+0x113/0x230
     [<ffffffff810757f1>] __lock_acquire+0x36a/0xd35
     [<ffffffff8101018d>] ? native_sched_clock+0x2d/0x5f
     [<ffffffffa03568c3>] ? ath_tx_node_cleanup+0x62/0x180 [ath9k]
     [<ffffffff81076289>] lock_acquire+0xcd/0xf1
     [<ffffffffa03568c3>] ? ath_tx_node_cleanup+0x62/0x180 [ath9k]
     [<ffffffff810732eb>] ? trace_hardirqs_off+0xd/0xf
     [<ffffffff813a7193>] _raw_spin_lock+0x36/0x69
     [<ffffffffa03568c3>] ? ath_tx_node_cleanup+0x62/0x180 [ath9k]
     [<ffffffffa03568c3>] ath_tx_node_cleanup+0x62/0x180 [ath9k]
     [<ffffffff810749ed>] ? trace_hardirqs_on+0xd/0xf
     [<ffffffffa0353950>] ath9k_sta_remove+0x22/0x26 [ath9k]
     [<ffffffffa025a08f>] __sta_info_destroy+0x1ad/0x38c [mac80211]
     [<ffffffffa025a394>] sta_info_destroy_addr+0x3e/0x5e [mac80211]
     [<ffffffffa02605d6>] ieee80211_set_disassoc+0x175/0x180 [mac80211]
     [<ffffffffa026084d>] ieee80211_mgd_deauth+0x58/0x17e [mac80211]
     [<ffffffff813a60c1>] ? __mutex_lock_common+0x37f/0x3a4
     [<ffffffffa01e53f2>] ? cfg80211_netdev_notifier_call+0x28d/0x46d [cfg80211]
     [<ffffffffa026786e>] ieee80211_deauth+0x1e/0x20 [mac80211]
     [<ffffffffa01f47f9>] __cfg80211_mlme_deauth+0x130/0x13f [cfg80211]
     [<ffffffffa01e53f2>] ? cfg80211_netdev_notifier_call+0x28d/0x46d [cfg80211]
     [<ffffffff810732eb>] ? trace_hardirqs_off+0xd/0xf
     [<ffffffffa01f7eee>] __cfg80211_disconnect+0x111/0x189 [cfg80211]
     [<ffffffffa01e5433>] cfg80211_netdev_notifier_call+0x2ce/0x46d [cfg80211]
     [<ffffffff813aa9ea>] notifier_call_chain+0x37/0x63
     [<ffffffff81068c98>] raw_notifier_call_chain+0x14/0x16
     [<ffffffff81322e97>] call_netdevice_notifiers+0x1b/0x1d
     [<ffffffff8132386d>] dev_close+0x6a/0xa6
     [<ffffffff8132395f>] rollback_registered_many+0xb6/0x2f4
     [<ffffffff81323bb8>] unregister_netdevice_many+0x1b/0x66
     [<ffffffffa026494f>] ieee80211_remove_interfaces+0xc5/0xd0 [mac80211]
     [<ffffffffa02580a2>] ieee80211_unregister_hw+0x47/0xe8 [mac80211]
     [<ffffffffa035290e>] ath9k_deinit_device+0x7a/0x9b [ath9k]
     [<ffffffffa035bc26>] ath_pci_remove+0x38/0x76 [ath9k]
     [<ffffffff8120940a>] pci_device_remove+0x2d/0x51
     [<ffffffff8129d797>] __device_release_driver+0x7b/0xd1
     [<ffffffff8129d885>] driver_detach+0x98/0xbe
     [<ffffffff8129ca7a>] bus_remove_driver+0x94/0xb7
     [<ffffffff8129ddd6>] driver_unregister+0x6c/0x74
     [<ffffffff812096d2>] pci_unregister_driver+0x46/0xad
     [<ffffffffa035bae1>] ath_pci_exit+0x15/0x17 [ath9k]
     [<ffffffffa035e1a2>] ath9k_exit+0xe/0x2f [ath9k]
     [<ffffffff8108050a>] sys_delete_module+0x1c7/0x236
     [<ffffffff813a7df5>] ? retint_swapgs+0x13/0x1b
     [<ffffffff810749b5>] ? trace_hardirqs_on_caller+0x119/0x144
     [<ffffffff8109b9f6>] ? audit_syscall_entry+0x11e/0x14a
     [<ffffffff81009bb2>] system_call_fastpath+0x16/0x1b
    wlan1: deauthenticating from 00:23:cd:e1:f9:b2 by local choice (reason=3)
    PM: Removing info for No Bus:wlan1
    cfg80211: Calling CRDA to update world regulatory domain
    PM: Removing info for No Bus:rfkill2
    PM: Removing info for No Bus:phy1
    ath9k 0000:16:00.0: PCI INT A disabled
    
    Signed-off-by: Ming Lei <tom.leiming@gmail.com>
    Signed-off-by: John W. Linville <linville@tuxdriver.com>
    Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
Comment 3 Lei Ming 2010-04-12 13:44:14 UTC
johannes has commented it already, please see 
         http://marc.info/?l=linux-wireless&m=127088247304187&w=2

Seems there is still some fix not merged to stable tree.


Thanks,
Comment 4 John W. Linville 2010-04-28 14:38:15 UTC
Actually, I think the conclusion is that the patch from comment 2 should be not have been backported to stable (and should now be reverted there).
Comment 5 John W. Linville 2010-04-28 14:38:58 UTC
*** Bug 15839 has been marked as a duplicate of this bug. ***
Comment 6 Sascha Wessel 2010-05-01 08:40:31 UTC
With lockdep enabled, I get the following inconsistent lock state info:



[  638.589551] ------------[ cut here ]------------

[  638.592049] WARNING: at kernel/softirq.c:143 _local_bh_enable_ip+0x35/0x97()

[  638.592049] Modules linked in: tun pppoe pppox ppp_generic ipt_MASQUERADE iptable_nat nf_nat xt_TCPMSS ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables xt_tcpudp nf_conntrack_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables x_tables geodewdt arc4 ath9k ath9k_common mac80211 ohci_hcd ath9k_hw ath ehci_hcd ecb aes_i586 hisax cfg80211 crc_ccitt aes_generic rfkill geode_aes usbcore isdn serio_raw geode_rng cs5535_mfgpt nls_base led_class cs5535_gpio slhc via_rhine rng_core mii ext3 jbd mbcache ide_gd_mod ata_generic pata_amd libata scsi_mod cs5536 ide_core

[  638.592049] Pid: 1271, comm: hostapd Not tainted 2.6.33.3-net5501-ath9k-lockdep #3

[  638.592049] Call Trace:

[  638.592049]  [<c1024842>] warn_slowpath_common+0x65/0x7c

[  638.592049]  [<c1029235>] ? _local_bh_enable_ip+0x35/0x97

[  638.592049]  [<e0df15d1>] ? spin_unlock_bh+0x8/0xa [ath9k]

[  638.592049]  [<c1024866>] warn_slowpath_null+0xd/0x10

[  638.592049]  [<c1029235>] _local_bh_enable_ip+0x35/0x97

[  638.592049]  [<c102929f>] local_bh_enable_ip+0x8/0xa

[  638.592049]  [<c1236b14>] _raw_spin_unlock_bh+0x25/0x28

[  638.592049]  [<e0df15d1>] spin_unlock_bh+0x8/0xa [ath9k]

[  638.592049]  [<e0df16df>] ath_tx_node_cleanup+0x10c/0x124 [ath9k]

[  638.592049]  [<e0ded275>] ath9k_sta_notify+0x74/0x78 [ath9k]

[  638.592049]  [<e0d9d595>] __sta_info_unlink+0x124/0x153 [mac80211]

[  638.592049]  [<e0ded201>] ? ath9k_sta_notify+0x0/0x78 [ath9k]

[  638.592049]  [<e0d9d5e7>] sta_info_unlink+0x23/0x31 [mac80211]

[  638.592049]  [<e0da8743>] ? ieee80211_del_station+0x0/0x68 [mac80211]

[  638.592049]  [<e0da878a>] ieee80211_del_station+0x47/0x68 [mac80211]

[  638.592049]  [<e0b7f9ae>] nl80211_del_station+0x6b/0x8c [cfg80211]

[  638.592049]  [<c11c9a09>] genl_rcv_msg+0x17f/0x19c

[  638.592049]  [<c11c988a>] ? genl_rcv_msg+0x0/0x19c

[  638.592049]  [<c11c951c>] netlink_rcv_skb+0x30/0x76

[  638.592049]  [<c11c9883>] genl_rcv+0x1b/0x22

[  638.592049]  [<c11c935a>] netlink_unicast+0xe6/0x143

[  638.592049]  [<c11c9778>] netlink_sendmsg+0x216/0x223

[  638.592049]  [<c11a63b8>] __sock_sendmsg+0x45/0x4e

[  638.592049]  [<c11a665c>] sock_sendmsg+0x92/0xa6

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c0b2>] ? might_fault+0x5e/0x63

[  638.592049]  [<c11ae440>] ? copy_from_user+0x8/0xa

[  638.592049]  [<c11ae735>] ? verify_iovec+0x3e/0x6d

[  638.592049]  [<c11a6882>] sys_sendmsg+0x187/0x1eb

[  638.592049]  [<c1044d2f>] ? register_lock_class+0x17/0x282

[  638.592049]  [<c104586e>] ? mark_lock+0x1e/0x1cd

[  638.592049]  [<c1045224>] ? trace_hardirqs_off+0xb/0xd

[  638.592049]  [<c10a142f>] ? kmem_cache_free+0x9d/0xcd

[  638.592049]  [<c1045c8d>] ? trace_hardirqs_on_caller+0xfe/0x11f

[  638.592049]  [<c1047216>] ? lock_release_non_nested+0x86/0x1d8

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c0b2>] ? might_fault+0x5e/0x63

[  638.592049]  [<c11a80fd>] sys_socketcall+0x15e/0x1a5

[  638.592049]  [<c112536c>] ? trace_hardirqs_on_thunk+0xc/0x10

[  638.592049]  [<c1236ca8>] syscall_call+0x7/0xb

[  638.592049]  [<c1230000>] ? klist_next+0x21/0x93

[  638.592049] ---[ end trace 691758086edb426a ]---

[  638.592049] 

[  638.592049] =================================

[  638.592049] [ INFO: inconsistent lock state ]

[  638.592049] 2.6.33.3-net5501-ath9k-lockdep #3

[  638.592049] ---------------------------------

[  638.592049] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.

[  638.592049] hostapd/1271 [HC0[0]:SC0[0]:HE1:SE1] takes:

[  638.592049]  (&(&local->sta_lock)->rlock){+.?...}, at: [<e0d9d5de>] sta_info_unlink+0x1a/0x31 [mac80211]

[  638.592049] {IN-SOFTIRQ-W} state was registered at:

[  638.592049]   [<c104671a>] __lock_acquire+0x25c/0xb34

[  638.592049]   [<c104707a>] lock_acquire+0x88/0xa1

[  638.592049]   [<c1236772>] _raw_spin_lock_irqsave+0x24/0x34

[  638.592049]   [<e0dad00c>] ieee80211_beacon_get_tim+0xe5/0x1be [mac80211]

[  638.592049]   [<e0dec8ce>] ath_beacon_tasklet+0x1a7/0x3bf [ath9k]

[  638.592049]   [<c1028c2d>] tasklet_action+0x4b/0x7d

[  638.592049]   [<c102901c>] __do_softirq+0x98/0x147

[  638.592049]   [<c10290f5>] do_softirq+0x2a/0x42

[  638.592049]   [<c10291d1>] irq_exit+0x33/0x62

[  638.592049]   [<c1003de9>] do_IRQ+0x74/0x87

[  638.592049]   [<c1002e55>] common_interrupt+0x35/0x3c

[  638.592049]   [<c12366d4>] _raw_spin_lock+0x1b/0x2a

[  638.592049]   [<c108c345>] spin_lock+0x8/0xa

[  638.592049]   [<c108e3ab>] handle_mm_fault+0x650/0x702

[  638.592049]   [<c10185fc>] do_page_fault+0x255/0x26b

[  638.592049]   [<c12370f0>] error_code+0x70/0x78

[  638.592049] irq event stamp: 29700

[  638.592049] hardirqs last  enabled at (29697): [<c1235aa5>] __mutex_unlock_slowpath+0xd5/0xdc

[  638.592049] hardirqs last disabled at (29698): [<c123675d>] _raw_spin_lock_irqsave+0xf/0x34

[  638.592049] softirqs last  enabled at (29700): [<e0df15d1>] spin_unlock_bh+0x8/0xa [ath9k]

[  638.592049] softirqs last disabled at (29699): [<c1236837>] _raw_spin_lock_bh+0xb/0x2f

[  638.592049] 

[  638.592049] other info that might help us debug this:

[  638.592049] 5 locks held by hostapd/1271:

[  638.592049]  #0:  (genl_mutex){+.+.+.}, at: [<c11c9857>] genl_lock+0xf/0x11

[  638.592049]  #1:  (rtnl_mutex){+.+.+.}, at: [<c11bb9a6>] rtnl_lock+0xf/0x11

[  638.592049]  #2:  (&rdev->mtx){+.+.+.}, at: [<e0b7ac13>] cfg80211_get_dev_from_ifindex+0x4f/0x65 [cfg80211]

[  638.592049]  #3:  (rcu_read_lock){.+.+..}, at: [<e0da818b>] rcu_read_lock+0x0/0x21 [mac80211]

[  638.592049]  #4:  (&(&local->sta_lock)->rlock){+.?...}, at: [<e0d9d5de>] sta_info_unlink+0x1a/0x31 [mac80211]

[  638.592049] 

[  638.592049] stack backtrace:

[  638.592049] Pid: 1271, comm: hostapd Tainted: G        W  2.6.33.3-net5501-ath9k-lockdep #3

[  638.592049] Call Trace:

[  638.592049]  [<c1235093>] ? printk+0xf/0x14

[  638.592049]  [<c104583d>] valid_state+0x12a/0x13d

[  638.592049]  [<c1045935>] mark_lock+0xe5/0x1cd

[  638.592049]  [<c1045fbe>] ? check_usage_backwards+0x0/0x68

[  638.592049]  [<c1045a60>] mark_held_locks+0x43/0x5b

[  638.592049]  [<c1029293>] ? _local_bh_enable_ip+0x93/0x97

[  638.592049]  [<c1045c8d>] trace_hardirqs_on_caller+0xfe/0x11f

[  638.592049]  [<e0df15d1>] ? spin_unlock_bh+0x8/0xa [ath9k]

[  638.592049]  [<c1045cb9>] trace_hardirqs_on+0xb/0xd

[  638.592049]  [<c1029293>] _local_bh_enable_ip+0x93/0x97

[  638.592049]  [<c102929f>] local_bh_enable_ip+0x8/0xa

[  638.592049]  [<c1236b14>] _raw_spin_unlock_bh+0x25/0x28

[  638.592049]  [<e0df15d1>] spin_unlock_bh+0x8/0xa [ath9k]

[  638.592049]  [<e0df16df>] ath_tx_node_cleanup+0x10c/0x124 [ath9k]

[  638.592049]  [<e0ded275>] ath9k_sta_notify+0x74/0x78 [ath9k]

[  638.592049]  [<e0d9d595>] __sta_info_unlink+0x124/0x153 [mac80211]

[  638.592049]  [<e0ded201>] ? ath9k_sta_notify+0x0/0x78 [ath9k]

[  638.592049]  [<e0d9d5e7>] sta_info_unlink+0x23/0x31 [mac80211]

[  638.592049]  [<e0da8743>] ? ieee80211_del_station+0x0/0x68 [mac80211]

[  638.592049]  [<e0da878a>] ieee80211_del_station+0x47/0x68 [mac80211]

[  638.592049]  [<e0b7f9ae>] nl80211_del_station+0x6b/0x8c [cfg80211]

[  638.592049]  [<c11c9a09>] genl_rcv_msg+0x17f/0x19c

[  638.592049]  [<c11c988a>] ? genl_rcv_msg+0x0/0x19c

[  638.592049]  [<c11c951c>] netlink_rcv_skb+0x30/0x76

[  638.592049]  [<c11c9883>] genl_rcv+0x1b/0x22

[  638.592049]  [<c11c935a>] netlink_unicast+0xe6/0x143

[  638.592049]  [<c11c9778>] netlink_sendmsg+0x216/0x223

[  638.592049]  [<c11a63b8>] __sock_sendmsg+0x45/0x4e

[  638.592049]  [<c11a665c>] sock_sendmsg+0x92/0xa6

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c0b2>] ? might_fault+0x5e/0x63

[  638.592049]  [<c11ae440>] ? copy_from_user+0x8/0xa

[  638.592049]  [<c11ae735>] ? verify_iovec+0x3e/0x6d

[  638.592049]  [<c11a6882>] sys_sendmsg+0x187/0x1eb

[  638.592049]  [<c1044d2f>] ? register_lock_class+0x17/0x282

[  638.592049]  [<c104586e>] ? mark_lock+0x1e/0x1cd

[  638.592049]  [<c1045224>] ? trace_hardirqs_off+0xb/0xd

[  638.592049]  [<c10a142f>] ? kmem_cache_free+0x9d/0xcd

[  638.592049]  [<c1045c8d>] ? trace_hardirqs_on_caller+0xfe/0x11f

[  638.592049]  [<c1047216>] ? lock_release_non_nested+0x86/0x1d8

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c07d>] ? might_fault+0x29/0x63

[  638.592049]  [<c108c0b2>] ? might_fault+0x5e/0x63

[  638.592049]  [<c11a80fd>] sys_socketcall+0x15e/0x1a5

[  638.592049]  [<c112536c>] ? trace_hardirqs_on_thunk+0xc/0x10

[  638.592049]  [<c1236ca8>] syscall_call+0x7/0xb

[  638.592049]  [<c1230000>] ? klist_next+0x21/0x93
Comment 7 John W. Linville 2010-05-01 11:03:37 UTC
Did you revert the patch from comment 2?
Comment 8 Sascha Wessel 2010-05-01 12:34:36 UTC
This looks good. I reverted 0524bcfa80f1fffb4e1fe18a0a28900869a58a7c and the warning is gone.
Comment 9 Florian Mickler 2010-12-08 08:43:57 UTC
Fixed in git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-2.6.33.y.git by 
commit 0afe7e4c1136dda6486587be78c5d277f7aac999
Author: Luis R. Rodriguez <lrodriguez@atheros.com>
Date:   Wed May 19 17:33:49 2010 -0400

    Revert "ath9k: fix lockdep warning when unloading module" on stable kernels