scheduling while atomic: iwl3945 in mmotm 2008-09-23-11-27

scheduling while atomic: iwl3945 in mmotm 2008-09-23-11-27

[Jiri Slaby]

Hi,

I got this through suspend/resume cycle on mmotm 2008-09-23-11-27:

BUG: scheduling while atomic: iwl3945/0/1154/0x00000002
Modules linked in: rfcomm bnep l2cap snd_seq snd_seq_device
cpufreq_userspace acpi_cpufreq fuse loop stkwebcam compat_ioctl32 iwl3945
videodev rfkill v4l1_compat usbhid battery usb_storage asus_laptop
Pid: 1154, comm: iwl3945/0 Tainted: G       AW 2.6.27-rc7-mm1 #57
Call Trace:
 [<ffffffff80235b57>] __schedule_bug+0x67/0x70
 [<ffffffff8057f955>] thread_return+0x117/0x5c2
 [<ffffffff8058231f>] ? _read_unlock+0x2f/0x40
 [<ffffffff8035a9b9>] ? rb_insert_color+0x109/0x140
 [<ffffffff8025ca9a>] ? enqueue_hrtimer+0x8a/0x140
 [<ffffffff805802f5>] schedule_timeout+0x95/0xd0
 [<ffffffff802b3365>] ? __slab_free+0x115/0x3f0
 [<ffffffff8025d5f9>] ? ktime_get_ts+0x59/0x60
 [<ffffffff805800c1>] wait_for_common+0xc1/0x1a0
 [<ffffffff8023e940>] ? default_wake_function+0x0/0x10
 [<ffffffff802cf60a>] ? generic_delete_inode+0xea/0x110
 [<ffffffff80580238>] wait_for_completion+0x18/0x20
 [<ffffffff80257315>] synchronize_rcu+0x35/0x40
 [<ffffffff802573d0>] ? wakeme_after_rcu+0x0/0x10
 [<ffffffff80564e96>] __ieee80211_key_todo+0x16/0x2f0
 [<ffffffff805652b5>] ieee80211_key_todo+0x15/0x30
 [<ffffffff80551d17>] sta_info_destroy+0x47/0x110
 [<ffffffff80559156>] ieee80211_set_disassoc+0x146/0x250
 [<ffffffff805593d5>] ieee80211_sta_req_auth+0x85/0x90
 [<ffffffff8055b156>] ieee80211_notify_mac+0x56/0xa0
 [<ffffffffa0054663>] iwl3945_bg_alive_start+0x2f3/0x360 [iwl3945]
 [<ffffffffa0054370>] ? iwl3945_bg_alive_start+0x0/0x360 [iwl3945]
 [<ffffffff80255599>] run_workqueue+0x99/0x170
 [<ffffffff80255877>] worker_thread+0xa7/0x120
 [<ffffffff80259c50>] ? autoremove_wake_function+0x0/0x40
 [<ffffffff802557d0>] ? worker_thread+0x0/0x120
 [<ffffffff80259889>] kthread+0x49/0x90
 [<ffffffff8020d5c9>] child_rip+0xa/0x11
 [<ffffffff80259840>] ? kthread+0x0/0x90
 [<ffffffff8020d5bf>] ? child_rip+0x0/0x11


I don't know who is responsible here. Maybe ieee80211_notify_mac? Citing:
"It is illegal to block while in an RCU read-side critical section." from
rcu_read_lock comments, but synchronize_rcu() in __ieee80211_key_todo()
sleeps and few mutexes are locked and might_sleep() invoked on the path too.

Re: scheduling while atomic: iwl3945 in mmotm 2008-09-23-11-27

[Johannes Berg]

[-- Attachment #1: Type: text/plain, Size: 1205 bytes --]

On Sat, 2008-09-27 at 21:51 +0200, Jiri Slaby wrote:

> BUG: scheduling while atomic: iwl3945/0/1154/0x00000002

>  [<ffffffff80257315>] synchronize_rcu+0x35/0x40

>  [<ffffffff80551d17>] sta_info_destroy+0x47/0x110
>  [<ffffffff80559156>] ieee80211_set_disassoc+0x146/0x250
>  [<ffffffff805593d5>] ieee80211_sta_req_auth+0x85/0x90
>  [<ffffffff8055b156>] ieee80211_notify_mac+0x56/0xa0
>  [<ffffffffa0054663>] iwl3945_bg_alive_start+0x2f3/0x360 [iwl3945]

> I don't know who is responsible here. Maybe ieee80211_notify_mac? Citing:
> "It is illegal to block while in an RCU read-side critical section." from
> rcu_read_lock comments, but synchronize_rcu() in __ieee80211_key_todo()
> sleeps and few mutexes are locked and might_sleep() invoked on the path too.

Yup, for sure.

This is a combination of various things, when ieee80211_notify_mac was
added ieee80211_sta_req_auth didn't destroy the sta info, later they
fixed a different bug that started doing that and we all missed that it
was called from here...

We can fix this by using RTNL locking instead, not sure though that'll
work because I don't know how iwl3945 calls this, I'll let Tomas deal
with it.

johannes

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

Re: scheduling while atomic: iwl3945 in mmotm 2008-09-23-11-27

[Zhu Yi]

On Sun, 2008-09-28 at 01:47 -0600, Johannes Berg wrote:
> On Sat, 2008-09-27 at 21:51 +0200, Jiri Slaby wrote:
> 
> > BUG: scheduling while atomic: iwl3945/0/1154/0x00000002
> 
> >  [<ffffffff80257315>] synchronize_rcu+0x35/0x40
> 
> >  [<ffffffff80551d17>] sta_info_destroy+0x47/0x110
> >  [<ffffffff80559156>] ieee80211_set_disassoc+0x146/0x250
> >  [<ffffffff805593d5>] ieee80211_sta_req_auth+0x85/0x90
> >  [<ffffffff8055b156>] ieee80211_notify_mac+0x56/0xa0
> >  [<ffffffffa0054663>] iwl3945_bg_alive_start+0x2f3/0x360 [iwl3945]
> 
> > I don't know who is responsible here. Maybe ieee80211_notify_mac? Citing:
> > "It is illegal to block while in an RCU read-side critical section." from
> > rcu_read_lock comments, but synchronize_rcu() in __ieee80211_key_todo()
> > sleeps and few mutexes are locked and might_sleep() invoked on the path too.
> 
> Yup, for sure.
> 
> This is a combination of various things, when ieee80211_notify_mac was
> added ieee80211_sta_req_auth didn't destroy the sta info, later they
> fixed a different bug that started doing that and we all missed that it
> was called from here...
> 
> We can fix this by using RTNL locking instead, not sure though that'll
> work because I don't know how iwl3945 calls this, I'll let Tomas deal
> with it.

Johannes, this scheduleing in atomic has nothing to do with the caller.
iwl3945 already calls it in a workqueue. The problem is inside
ieee80211_notify_mac(). Unfortunately, iwl3945/iwlagn turns to be the
only user at this time.

Thanks,
-yi

Re: scheduling while atomic: iwl3945 in mmotm 2008-09-23-11-27

[Johannes Berg]

On Tue, 2008-11-11 at 11:52 +0800, Zhu Yi wrote:

> > >  [<ffffffff80257315>] synchronize_rcu+0x35/0x40
> > 
> > >  [<ffffffff80551d17>] sta_info_destroy+0x47/0x110
> > >  [<ffffffff80559156>] ieee80211_set_disassoc+0x146/0x250
> > >  [<ffffffff805593d5>] ieee80211_sta_req_auth+0x85/0x90
> > >  [<ffffffff8055b156>] ieee80211_notify_mac+0x56/0xa0

> > We can fix this by using RTNL locking instead, not sure though that'll
> > work because I don't know how iwl3945 calls this, I'll let Tomas deal
> > with it.
> 
> Johannes, this scheduleing in atomic has nothing to do with the caller.
> iwl3945 already calls it in a workqueue. The problem is inside
> ieee80211_notify_mac(). Unfortunately, iwl3945/iwlagn turns to be the
> only user at this time.

I see. But the suggestion above is valid nonetheless and works fine if
it's called from a workqueue. I take no blame for this though, you guys
added this function and you also changed ieee80211_set_disassoc() in
ways that made the original implementation wrong :P

John, please apply the patch below.

johannes


From: Johannes Berg <johannes@sipsolutions.net>
Subject: [PATCH] mac80211: fix notify_mac function

The ieee80211_notify_mac() function uses ieee80211_sta_req_auth() which
in turn calls ieee80211_set_disassoc() which calls a few functions that
need to be able to sleep, so ieee80211_notify_mac() cannot use RCU
locking for the interface list and must use rtnl locking instead.

Signed-off-by: Johannes Berg <johannes@sipsolutions.net>
---
 net/mac80211/mlme.c |    6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

--- everything.orig/net/mac80211/mlme.c	2008-11-11 11:23:09.000000000 +0100
+++ everything/net/mac80211/mlme.c	2008-11-11 11:23:24.000000000 +0100
@@ -2596,14 +2596,14 @@ void ieee80211_notify_mac(struct ieee802
 
 	switch (notif_type) {
 	case IEEE80211_NOTIFY_RE_ASSOC:
-		rcu_read_lock();
-		list_for_each_entry_rcu(sdata, &local->interfaces, list) {
+		rtnl_lock();
+		list_for_each_entry(sdata, &local->interfaces, list) {
 			if (sdata->vif.type != NL80211_IFTYPE_STATION)
 				continue;
 
 			ieee80211_sta_req_auth(sdata, &sdata->u.sta);
 		}
-		rcu_read_unlock();
+		rtnl_unlock();
 		break;
 	}
 }