softmac: Fix deadlock of wx_set_essid with assoc work

The essid wireless extension does deadlock against the assoc mutex, as we don't unlock the assoc mutex when flushing the workqueue, which also holds the lock.

This patch is queued for inclusion in the wireless-2.6 tree.

Index: bu3sch-wireless-dev/net/ieee80211/softmac/ieee80211softmac_wx.c
===================================================================
@@ -74,8 +74,8 @@ ieee80211softmac_wx_set_essid(struct net
 	struct ieee80211softmac_auth_queue_item *authptr;
 	int length = 0;
 
+check_assoc_again:
 	mutex_lock(&sm->associnfo.mutex);
-
 	/* Check if we're already associating to this or another network
 	 * If it's another network, cancel and start over with our new network
 	 * If it's our network, ignore the change, we're already doing it!

@@ -98,13 +98,18 @@ ieee80211softmac_wx_set_essid(struct net
 				cancel_delayed_work(&authptr->work);
 			sm->associnfo.bssvalid = 0;
 			sm->associnfo.bssfixed = 0;
-			flush_scheduled_work();
 			sm->associnfo.associating = 0;
 			sm->associnfo.associated = 0;
+			/* We must unlock to avoid deadlocks with the assoc workqueue
+			 * on the associnfo.mutex */
+			mutex_unlock(&sm->associnfo.mutex);
+			flush_scheduled_work();
+			/* Avoid race! Check assoc status again. Maybe someone started an
+			 * association while we flushed. */
+			goto check_assoc_again;
 		}
 	}
 
-
 	sm->associnfo.static_essid = 0;
 	sm->associnfo.assoc_wait = 0;
 

-------------------------------------------------------

FYI, my workqueue lockdep patches (in -mm as workqueue-something) say this about it:

[  361.440737] =======================================================
[  361.440753] [ INFO: possible circular locking dependency detected ]
[  361.440761] 2.6.23-rc1-g05ff0970-dirty #244
[  361.440766] -------------------------------------------------------
[  361.440773] iwconfig/5551 is trying to acquire lock:
[  361.440778]  (events){--..}, at: [<c00000000006170c>] .flush_workqueue+0x44/0xf0
[  361.440807] 
[  361.440808] but task is already holding lock:
[  361.440814]  (&softmac->associnfo.mutex){--..}, at: [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  361.440837] 
[  361.440839] which lock already depends on the new lock.
[  361.440841] 
[  361.440847] 
[  361.440848] the existing dependency chain (in reverse order) is:
[  361.440854] 
[  361.440856] -> #3 (&softmac->associnfo.mutex){--..}:
[  361.440869]        [<c000000000073e58>] .__lock_acquire+0xce8/0xf20
[  361.440896]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  361.440922]        [<c0000000003b96cc>] .__mutex_lock_slowpath+0x138/0x3f0
[  361.440950]        [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  361.440977]        [<d0000000004c3cb4>] .ieee80211softmac_wx_set_essid+0x48/0x204 [ieee80211softmac]
[  361.441019]        [<c0000000003b5a8c>] .ioctl_standard_call+0x298/0x3bc
[  361.441047]        [<c0000000003b5d38>] .wext_handle_ioctl+0x188/0x4b4
[  361.441074]        [<c000000000330d54>] .dev_ioctl+0x584/0x5e0
[  361.441102]        [<c000000000320514>] .sock_ioctl+0x2fc/0x33c
[  361.441130]        [<c0000000000d9568>] .do_ioctl+0x5c/0xf8
[  361.441159]        [<c0000000000d9a5c>] .vfs_ioctl+0x458/0x490
[  361.441186]        [<c0000000000d9af0>] .sys_ioctl+0x5c/0xa4
[  361.441212]        [<c000000000110d88>] .do_wireless_ioctl+0x1d0/0x224
[  361.441241]        [<c00000000010c5ec>] .compat_sys_ioctl+0x3e0/0x470
[  361.441268]        [<c0000000000086d0>] syscall_exit+0x0/0x40
[  361.441296] 
[  361.441298] -> #2 (rtnl_mutex){--..}:
[  361.441311]        [<c000000000073e58>] .__lock_acquire+0xce8/0xf20
[  361.441337]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  361.441363]        [<c0000000003b96cc>] .__mutex_lock_slowpath+0x138/0x3f0
[  361.441392]        [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  361.441419]        [<c00000000033b85c>] .rtnl_lock+0x28/0x44
[  361.441446]        [<c00000000033d8ac>] .linkwatch_event+0x20/0x6c
[  361.441474]        [<c000000000060720>] .run_workqueue+0x16c/0x290
[  361.441501]        [<c000000000061d2c>] .worker_thread+0x13c/0x16c
[  361.441528]        [<c000000000066b98>] .kthread+0x84/0xd4
[  361.441554]        [<c000000000022734>] .kernel_thread+0x4c/0x68
[  361.441582] 
[  361.441584] -> #1 ((linkwatch_work).work){--..}:
[  361.441597]        [<c000000000073e58>] .__lock_acquire+0xce8/0xf20
[  361.441623]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  361.441648]        [<c000000000060700>] .run_workqueue+0x14c/0x290
[  361.441675]        [<c000000000061d2c>] .worker_thread+0x13c/0x16c
[  361.441702]        [<c000000000066b98>] .kthread+0x84/0xd4
[  361.441727]        [<c000000000022734>] .kernel_thread+0x4c/0x68
[  361.441755] 
[  361.441756] -> #0 (events){--..}:
[  361.441769]        [<c000000000073d50>] .__lock_acquire+0xbe0/0xf20
[  361.441795]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  361.441821]        [<c00000000006173c>] .flush_workqueue+0x74/0xf0
[  361.441859]        [<c0000000000617e0>] .flush_scheduled_work+0x28/0x40
[  361.441888]        [<d0000000004c3dac>] .ieee80211softmac_wx_set_essid+0x140/0x204 [ieee80211softmac]
[  361.441924]        [<c0000000003b5a8c>] .ioctl_standard_call+0x298/0x3bc
[  361.442017]        [<c0000000003b5d38>] .wext_handle_ioctl+0x188/0x4b4
[  361.442104]        [<c000000000330d54>] .dev_ioctl+0x584/0x5e0
[  361.442189]        [<c000000000320514>] .sock_ioctl+0x2fc/0x33c
[  361.442260]        [<c0000000000d9568>] .do_ioctl+0x5c/0xf8
[  361.442341]        [<c0000000000d9a5c>] .vfs_ioctl+0x458/0x490
[  361.442416]        [<c0000000000d9af0>] .sys_ioctl+0x5c/0xa4
[  361.442495]        [<c000000000110d88>] .do_wireless_ioctl+0x1d0/0x224
[  361.442577]        [<c00000000010c5ec>] .compat_sys_ioctl+0x3e0/0x470
[  361.442654]        [<c0000000000086d0>] syscall_exit+0x0/0x40
[  361.442737] 
[  361.442739] other info that might help us debug this:
[  361.442742] 
[  361.442752] 2 locks held by iwconfig/5551:
[  361.442763]  #0:  (rtnl_mutex){--..}, at: [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  361.442818]  #1:  (&softmac->associnfo.mutex){--..}, at: [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  361.442843] 
[  361.442845] stack backtrace:
[  361.442850] Call Trace:
[  361.442855] [c000000078eab100] [c00000000000f2e4] .show_stack+0x78/0x1a4 (unreliable)
[  361.442887] [c000000078eab1b0] [c00000000000f430] .dump_stack+0x20/0x34
[  361.442917] [c000000078eab230] [c00000000007141c] .print_circular_bug_tail+0x88/0xac
[  361.442953] [c000000078eab300] [c000000000073d50] .__lock_acquire+0xbe0/0xf20
[  361.442981] [c000000078eab3f0] [c000000000074160] .lock_acquire+0xd0/0x11c
[  361.443009] [c000000078eab4b0] [c00000000006173c] .flush_workqueue+0x74/0xf0
[  361.443039] [c000000078eab550] [c0000000000617e0] .flush_scheduled_work+0x28/0x40
[  361.443073] [c000000078eab5d0] [d0000000004c3dac] .ieee80211softmac_wx_set_essid+0x140/0x204 [ieee80211softmac]
[  361.443109] [c000000078eab680] [c0000000003b5a8c] .ioctl_standard_call+0x298/0x3bc
[  361.443139] [c000000078eab790] [c0000000003b5d38] .wext_handle_ioctl+0x188/0x4b4
[  361.443172] [c000000078eab870] [c000000000330d54] .dev_ioctl+0x584/0x5e0
[  361.443203] [c000000078eab990] [c000000000320514] .sock_ioctl+0x2fc/0x33c
[  361.443232] [c000000078eaba40] [c0000000000d9568] .do_ioctl+0x5c/0xf8
[  361.443265] [c000000078eabae0] [c0000000000d9a5c] .vfs_ioctl+0x458/0x490
[  361.443296] [c000000078eabb90] [c0000000000d9af0] .sys_ioctl+0x5c/0xa4
[  361.443330] [c000000078eabc50] [c000000000110d88] .do_wireless_ioctl+0x1d0/0x224
[  361.443363] [c000000078eabd30] [c00000000010c5ec] .compat_sys_ioctl+0x3e0/0x470
[  361.443396] [c000000078eabe30] [c0000000000086d0] syscall_exit+0x0/0x40

We really need to get lockdep ported to ppc32...

johannes

Adding to my previous mail, this fix is not enough. As you can see below, it is never safe to call flush_scheduled_work() under rtnl because some other things running *from* the global events workqueue acquire the rtnl and hence it we could deadlock against them.

I think the fix would be to use cancel_delayed_work_sync() here instead of a combination of cancel_delayed_work() and flush_workqueue().

[  130.612315] =======================================================
[  130.612331] [ INFO: possible circular locking dependency detected ]
[  130.612338] 2.6.23-rc1-g05ff0970-dirty #244
[  130.612343] -------------------------------------------------------
[  130.612350] iwconfig/4443 is trying to acquire lock:
[  130.612356]  (events){--..}, at: [<c00000000006170c>] .flush_workqueue+0x44/0xf0
[  130.612384] 
[  130.612385] but task is already holding lock:
[  130.612391]  (rtnl_mutex){--..}, at: [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  130.612414] 
[  130.612415] which lock already depends on the new lock.
[  130.612418] 
[  130.612423] 
[  130.612424] the existing dependency chain (in reverse order) is:
[  130.612430] 
[  130.612432] -> #2 (rtnl_mutex){--..}:
[  130.612445]        [<c000000000073e58>] .__lock_acquire+0xce8/0xf20
[  130.612472]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  130.612498]        [<c0000000003b96cc>] .__mutex_lock_slowpath+0x138/0x3f0
[  130.612526]        [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  130.612553]        [<c00000000033b85c>] .rtnl_lock+0x28/0x44
[  130.612582]        [<c00000000033d8ac>] .linkwatch_event+0x20/0x6c
[  130.612609]        [<c000000000060720>] .run_workqueue+0x16c/0x290
[  130.612636]        [<c000000000061d2c>] .worker_thread+0x13c/0x16c
[  130.612664]        [<c000000000066b98>] .kthread+0x84/0xd4
[  130.612690]        [<c000000000022734>] .kernel_thread+0x4c/0x68
[  130.612721] 
[  130.612723] -> #1 ((linkwatch_work).work){--..}:
[  130.612737]        [<c000000000073e58>] .__lock_acquire+0xce8/0xf20
[  130.612774]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  130.612801]        [<c000000000060700>] .run_workqueue+0x14c/0x290
[  130.612821]        [<c000000000061d2c>] .worker_thread+0x13c/0x16c
[  130.612886]        [<c000000000066b98>] .kthread+0x84/0xd4
[  130.612961]        [<c000000000022734>] .kernel_thread+0x4c/0x68
[  130.613038] 
[  130.613040] -> #0 (events){--..}:
[  130.613074]        [<c000000000073d50>] .__lock_acquire+0xbe0/0xf20
[  130.613149]        [<c000000000074160>] .lock_acquire+0xd0/0x11c
[  130.613224]        [<c00000000006173c>] .flush_workqueue+0x74/0xf0
[  130.613303]        [<c0000000000617e0>] .flush_scheduled_work+0x28/0x40
[  130.613377]        [<d0000000004c8dd4>] .ieee80211softmac_wx_set_essid+0x168/0x234 [ieee80211softmac]
[  130.613473]        [<c0000000003b5a8c>] .ioctl_standard_call+0x298/0x3bc
[  130.613553]        [<c0000000003b5d38>] .wext_handle_ioctl+0x188/0x4b4
[  130.613625]        [<c000000000330d54>] .dev_ioctl+0x584/0x5e0
[  130.613697]        [<c000000000320514>] .sock_ioctl+0x2fc/0x33c
[  130.613751]        [<c0000000000d9568>] .do_ioctl+0x5c/0xf8
[  130.613827]        [<c0000000000d9a5c>] .vfs_ioctl+0x458/0x490
[  130.613905]        [<c0000000000d9af0>] .sys_ioctl+0x5c/0xa4
[  130.613982]        [<c000000000110d88>] .do_wireless_ioctl+0x1d0/0x224
[  130.614059]        [<c00000000010c5ec>] .compat_sys_ioctl+0x3e0/0x470
[  130.614137]        [<c0000000000086d0>] syscall_exit+0x0/0x40
[  130.614217] 
[  130.614219] other info that might help us debug this:
[  130.614221] 
[  130.614232] 1 lock held by iwconfig/4443:
[  130.614242]  #0:  (rtnl_mutex){--..}, at: [<c0000000003b99c0>] .mutex_lock+0x3c/0x58
[  130.614295] 
[  130.614297] stack backtrace:
[  130.614307] Call Trace:
[  130.614318] [c00000010c58f0e0] [c00000000000f2e4] .show_stack+0x78/0x1a4 (unreliable)
[  130.614358] [c00000010c58f190] [c00000000000f430] .dump_stack+0x20/0x34
[  130.614388] [c00000010c58f210] [c00000000007141c] .print_circular_bug_tail+0x88/0xac
[  130.614421] [c00000010c58f2e0] [c000000000073d50] .__lock_acquire+0xbe0/0xf20
[  130.614450] [c00000010c58f3d0] [c000000000074160] .lock_acquire+0xd0/0x11c
[  130.614478] [c00000010c58f490] [c00000000006173c] .flush_workqueue+0x74/0xf0
[  130.614505] [c00000010c58f530] [c0000000000617e0] .flush_scheduled_work+0x28/0x40
[  130.614533] [c00000010c58f5b0] [d0000000004c8dd4] .ieee80211softmac_wx_set_essid+0x168/0x234 [ieee80211softmac]
[  130.614573] [c00000010c58f680] [c0000000003b5a8c] .ioctl_standard_call+0x298/0x3bc
[  130.614606] [c00000010c58f790] [c0000000003b5d38] .wext_handle_ioctl+0x188/0x4b4
[  130.614640] [c00000010c58f870] [c000000000330d54] .dev_ioctl+0x584/0x5e0
[  130.614669] [c00000010c58f990] [c000000000320514] .sock_ioctl+0x2fc/0x33c
[  130.614695] [c00000010c58fa40] [c0000000000d9568] .do_ioctl+0x5c/0xf8
[  130.614722] [c00000010c58fae0] [c0000000000d9a5c] .vfs_ioctl+0x458/0x490
[  130.614752] [c00000010c58fb90] [c0000000000d9af0] .sys_ioctl+0x5c/0xa4
[  130.614782] [c00000010c58fc50] [c000000000110d88] .do_wireless_ioctl+0x1d0/0x224
[  130.614811] [c00000010c58fd30] [c00000000010c5ec] .compat_sys_ioctl+0x3e0/0x470
[  130.614840] [c00000010c58fe30] [c0000000000086d0] syscall_exit+0x0/0x40

Ah, Ok. I didn't see that rtnl is locked there, too. cancel_delayed_work_sync could probably work. Care to test that?

Greetings Michael.

Well, it's a wireless extensions call...

I can give it a try next week.

johannes

It's harder than thought, runs into the next use of flush_scheduled_work under rtnl. I think the only solution is to go with your patch and then add an own single-threaded workqueue to softmac again and use that everywhere instead of the global one; at least that way the rtnl doesn't get into the way.

johannes

Yep, but this patch turns the bug from a
"It will 100% deadlock all the time"
into a
"It might possibly deadlock, although unlikely"
So it's a win for that crap softmac code.

Greetings Michael.

Agreed, let's go with the patch you just sent. It's rather unlikely that it will deadlock against the link watch event, and hopefully we can delete softmac in 2.6.24 with Larry's bcm4301 and zd1211-mac80211 shaping up.

johannes