Oops in mac80211 with 2.6.26-rc3 triggered playing a video

Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Justin Madru]

Hi,

I've been getting kernel crashes at random when a video file just starts 
to play (using VLC).
As soon as the first frame shows, the system locks up hard (sometimes 
not even alt+sysrq+b works).

Just recently, when it crashed it was able to print an oops to the 
syslog. The weird thing is that it says that it's a bug in mac80211? But 
I only have the crash the instant a video file starts to play. (I have 
an Intel 3945 wireles, and Intel i945 graphic card)

BUG: unable to handle kernel NULL pointer dereference at 00000090
IP: [<f89e721f>] :mac80211:ieee80211_associate+0x24f/0x610
*pde = 00000000
Oops: 0000 [#1] PREEMPT SMP
Modules linked in: i915 acpi_cpufreq cpufreq_powersave cpufreq_stats 
cpufreq_userspace cpufreq_conservative container sbs sbshc ext3 jbd 
mbcache arc4 ecb crypto_blkcipher rtc dcdbas cryptomgr crypto_algapi 
psmouse evdev snd_hda_intel snd_pcm_oss snd_mixer_oss snd_pcm iwl3945 
mac80211 snd_timer crc32 snd_page_alloc video backlight output ac button 
battery intel_agp reiserfs sr_mod cdrom sg ata_piix ehci_hcd uhci_hcd 
usbcore thermal processor fan

Pid: 1899, comm: iwl3945 Not tainted (2.6.26-rc3-git #1)
EIP: 0060:[<f89e721f>] EFLAGS: 00010246 CPU: 1
EIP is at ieee80211_associate+0x24f/0x610 [mac80211]
EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: f7b85e38
ESI: f7b85e84 EDI: ecc7122e EBP: f7bbdd34 ESP: f7bbdcc0
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
Process iwl3945 (pid: 1899, ti=f7bbd000 task=f718d390 task.ti=f7bbd000)
Stack: f7b85e84 00000000 f7bbdd14 00000202 f7b85e38 f7b85800 f7f65f00 
00000018
       f7bbdcfa 00000000 00000421 00000003 00000006 00000052 f7bbdd0c 
ecc7122c
       f71593a4 00000000 f7bbde15 f7bbdd3c c0295679 303a3030 33623a66 
3a31613a
Call Trace:
 [_format_mac_addr+0x79/0x90] ? _format_mac_addr+0x79/0x90
 [sched_debug_show+0x9c6/0xcb0] ? sched_debug_show+0x9c6/0xcb0
 [<f89e7610>] ? ieee80211_auth_completed+0x30/0x40 [mac80211]
 [<f89e7a73>] ? ieee80211_rx_mgmt_auth+0x303/0x4b0 [mac80211]
 [hrtimer_start+0xc2/0x150] ? hrtimer_start+0xc2/0x150
 [hrtick_set+0x85/0x100] ? hrtick_set+0x85/0x100
 [jbd:schedule+0x364/0x8c0] ? schedule+0x364/0x870
 [<f89e7da7>] ? ieee80211_sta_rx_queued_mgmt+0x187/0xcb0 [mac80211]
 [ext3:preempt_schedule+0x33/0x100] ? preempt_schedule+0x33/0x50
 [mac80211:dev_queue_xmit+0xa6/0x1f20] ? dev_queue_xmit+0xa6/0x330
 [mac80211:_spin_unlock_bh+0x18/0xb0] ? _spin_unlock_bh+0x18/0x20
 [<f89e33b7>] ? ieee80211_rx_bss_get+0xa7/0xc0 [mac80211]
 [mac80211:skb_dequeue+0x4d/0x360] ? skb_dequeue+0x4d/0x70
 [<f89e960f>] ? ieee80211_sta_work+0x8f/0x760 [mac80211]
 [hrtick_set+0xa7/0x100] ? hrtick_set+0xa7/0x100
 [jbd:schedule+0x364/0x8c0] ? schedule+0x364/0x870
 [run_workqueue+0x80/0x120] ? run_workqueue+0x80/0x120
 [<f89e9580>] ? ieee80211_sta_work+0x0/0x760 [mac80211]
 [worker_thread+0x88/0xe0] ? worker_thread+0x88/0xe0
 [<c013ba80>] ? autoremove_wake_function+0x0/0x40
 [worker_thread+0x0/0xe0] ? worker_thread+0x0/0xe0
 [kthread+0x42/0x70] ? kthread+0x42/0x70
 [kthread+0x0/0x70] ? kthread+0x0/0x70
 [kernel_thread_helper+0x7/0x18] ? kernel_thread_helper+0x7/0x18
 =======================
Code: c6 00 00 8b 55 9c 8b 4d c8 8b 42 70 88 41 01 8b 42 70 8b 7d c8 89 
c1 c1 e9 02 83 c7 02 f3 a5 89 c1 83 e1 03 74 02 f3 a4 8b 5d d0 <8b> 9b 
90 00 00 00 85 db 89 5d d8 0f 84 6d 03 00 00 8b 7d cc 8b
EIP: [<f89e721f>] ieee80211_associate+0x24f/0x610 [mac80211] SS:ESP 
0068:f7bbdcc0
---[ end trace 7afccad6600bfa21 ]---

Justin Madru

Re: Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Vegard Nossum]

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

Hi,

On Mon, May 26, 2008 at 6:41 AM, Justin Madru <jdm64@gawab.com> wrote:
> Hi,
>
> I've been getting kernel crashes at random when a video file just starts to
> play (using VLC).
> As soon as the first frame shows, the system locks up hard (sometimes not
> even alt+sysrq+b works).
>
> Just recently, when it crashed it was able to print an oops to the syslog.
> The weird thing is that it says that it's a bug in mac80211? But I only have
> the crash the instant a video file starts to play. (I have an Intel 3945
> wireles, and Intel i945 graphic card)
>
> BUG: unable to handle kernel NULL pointer dereference at 00000090
> IP: [<f89e721f>] :mac80211:ieee80211_associate+0x24f/0x610
> *pde = 00000000
> Oops: 0000 [#1] PREEMPT SMP
> Modules linked in: i915 acpi_cpufreq cpufreq_powersave cpufreq_stats
> cpufreq_userspace cpufreq_conservative container sbs sbshc ext3 jbd mbcache
> arc4 ecb crypto_blkcipher rtc dcdbas cryptomgr crypto_algapi psmouse evdev
> snd_hda_intel snd_pcm_oss snd_mixer_oss snd_pcm iwl3945 mac80211 snd_timer
> crc32 snd_page_alloc video backlight output ac button battery intel_agp
> reiserfs sr_mod cdrom sg ata_piix ehci_hcd uhci_hcd usbcore thermal
> processor fan
>
> Pid: 1899, comm: iwl3945 Not tainted (2.6.26-rc3-git #1)
> EIP: 0060:[<f89e721f>] EFLAGS: 00010246 CPU: 1
> EIP is at ieee80211_associate+0x24f/0x610 [mac80211]
> EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: f7b85e38
> ESI: f7b85e84 EDI: ecc7122e EBP: f7bbdd34 ESP: f7bbdcc0
> DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> Process iwl3945 (pid: 1899, ti=f7bbd000 task=f718d390 task.ti=f7bbd000)
> Stack: f7b85e84 00000000 f7bbdd14 00000202 f7b85e38 f7b85800 f7f65f00
> 00000018
>      f7bbdcfa 00000000 00000421 00000003 00000006 00000052 f7bbdd0c ecc7122c
>      f71593a4 00000000 f7bbde15 f7bbdd3c c0295679 303a3030 33623a66 3a31613a
> Call Trace:
> [_format_mac_addr+0x79/0x90] ? _format_mac_addr+0x79/0x90
> [sched_debug_show+0x9c6/0xcb0] ? sched_debug_show+0x9c6/0xcb0
> [<f89e7610>] ? ieee80211_auth_completed+0x30/0x40 [mac80211]
> [<f89e7a73>] ? ieee80211_rx_mgmt_auth+0x303/0x4b0 [mac80211]
> [hrtimer_start+0xc2/0x150] ? hrtimer_start+0xc2/0x150
> [hrtick_set+0x85/0x100] ? hrtick_set+0x85/0x100
> [jbd:schedule+0x364/0x8c0] ? schedule+0x364/0x870
> [<f89e7da7>] ? ieee80211_sta_rx_queued_mgmt+0x187/0xcb0 [mac80211]
> [ext3:preempt_schedule+0x33/0x100] ? preempt_schedule+0x33/0x50
> [mac80211:dev_queue_xmit+0xa6/0x1f20] ? dev_queue_xmit+0xa6/0x330
> [mac80211:_spin_unlock_bh+0x18/0xb0] ? _spin_unlock_bh+0x18/0x20
> [<f89e33b7>] ? ieee80211_rx_bss_get+0xa7/0xc0 [mac80211]
> [mac80211:skb_dequeue+0x4d/0x360] ? skb_dequeue+0x4d/0x70
> [<f89e960f>] ? ieee80211_sta_work+0x8f/0x760 [mac80211]
> [hrtick_set+0xa7/0x100] ? hrtick_set+0xa7/0x100
> [jbd:schedule+0x364/0x8c0] ? schedule+0x364/0x870
> [run_workqueue+0x80/0x120] ? run_workqueue+0x80/0x120
> [<f89e9580>] ? ieee80211_sta_work+0x0/0x760 [mac80211]
> [worker_thread+0x88/0xe0] ? worker_thread+0x88/0xe0
> [<c013ba80>] ? autoremove_wake_function+0x0/0x40
> [worker_thread+0x0/0xe0] ? worker_thread+0x0/0xe0
> [kthread+0x42/0x70] ? kthread+0x42/0x70
> [kthread+0x0/0x70] ? kthread+0x0/0x70
> [kernel_thread_helper+0x7/0x18] ? kernel_thread_helper+0x7/0x18
> =======================
> Code: c6 00 00 8b 55 9c 8b 4d c8 8b 42 70 88 41 01 8b 42 70 8b 7d c8 89 c1
> c1 e9 02 83 c7 02 f3 a5 89 c1 83 e1 03 74 02 f3 a4 8b 5d d0 <8b> 9b 90 00 00
> 00 85 db 89 5d d8 0f 84 6d 03 00 00 8b 7d cc 8b
> EIP: [<f89e721f>] ieee80211_associate+0x24f/0x610 [mac80211] SS:ESP
> 0068:f7bbdcc0
> ---[ end trace 7afccad6600bfa21 ]---

The code decodes to:

  1d:   f3 a5                   rep movsl %ds:(%esi),%es:(%edi)
  1f:   89 c1                   mov    %eax,%ecx
  21:   83 e1 03                and    $0x3,%ecx
  24:   74 02                   je     0x28
  26:   f3 a4                   rep movsb %ds:(%esi),%es:(%edi)
  28:   8b 5d d0                mov    -0x30(%ebp),%ebx
   0:   8b 9b 90 00 00 00       mov    0x90(%ebx),%ebx <---- BAM!
   6:   85 db                   test   %ebx,%ebx
   8:   89 5d d8                mov    %ebx,-0x28(%ebp)
   b:   0f 84 6d 03 00 00       je     0x37e
  11:   8b 7d cc                mov    -0x34(%ebp),%edi
  14:   8b                      .byte 0x8b

Recompiling net/mac80211/mlme.c gives me that this happens on line 675.

ieee80211_compatible_rates net/mac80211/mlme.c:675
ieee80211_send_assoc net/mac80211/mlme.c:767
ieee80211_associate net/mac80211/mlme.c:955

So it is in fact compatible_rates() that crashes (but hidden in your
Oops because of heavy inlining).

So looking at the latest changelog in linus/master, we have this change:

commit 0d580a774b3682b8b2b5c89ab9b813d149ef28e7
Author: Helmut Schaa <hschaa@suse.de>
Date:   Tue May 20 09:56:37 2008 +0200

    mac80211: fix NULL pointer dereference in ieee80211_compatible_rates

    Fix a possible NULL pointer dereference in ieee80211_compatible_rates
    introduced in the patch "mac80211: fix association with some APs". If no bss
    is available just use all supported rates in the association request.

    Signed-off-by: Helmut Schaa <hschaa@suse.de>
    Signed-off-by: John W. Linville <linville@tuxdriver.com>

So does applying/cherry-picking that fix your problem? (Patch
attached, but not inlined.)


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: mlme.patch --]
[-- Type: text/x-patch; name=mlme.patch, Size: 1741 bytes --]

commit 0d580a774b3682b8b2b5c89ab9b813d149ef28e7
Author: Helmut Schaa <hschaa@suse.de>
Date:   Tue May 20 09:56:37 2008 +0200

    mac80211: fix NULL pointer dereference in ieee80211_compatible_rates
    
    Fix a possible NULL pointer dereference in ieee80211_compatible_rates
    introduced in the patch "mac80211: fix association with some APs". If no bss
    is available just use all supported rates in the association request.
    
    Signed-off-by: Helmut Schaa <hschaa@suse.de>
    Signed-off-by: John W. Linville <linville@tuxdriver.com>

diff --git a/net/mac80211/mlme.c b/net/mac80211/mlme.c
index e470bf1..7cfd12e 100644
--- a/net/mac80211/mlme.c
+++ b/net/mac80211/mlme.c
@@ -730,7 +730,17 @@ static void ieee80211_send_assoc(struct net_device *dev,
 		if (bss->wmm_ie) {
 			wmm = 1;
 		}
+
+		/* get all rates supported by the device and the AP as
+		 * some APs don't like getting a superset of their rates
+		 * in the association request (e.g. D-Link DAP 1353 in
+		 * b-only mode) */
+		rates_len = ieee80211_compatible_rates(bss, sband, &rates);
+
 		ieee80211_rx_bss_put(dev, bss);
+	} else {
+		rates = ~0;
+		rates_len = sband->n_bitrates;
 	}
 
 	mgmt = (struct ieee80211_mgmt *) skb_put(skb, 24);
@@ -761,10 +771,7 @@ static void ieee80211_send_assoc(struct net_device *dev,
 	*pos++ = ifsta->ssid_len;
 	memcpy(pos, ifsta->ssid, ifsta->ssid_len);
 
-	/* all supported rates should be added here but some APs
-	 * (e.g. D-Link DAP 1353 in b-only mode) don't like that
-	 * Therefore only add rates the AP supports */
-	rates_len = ieee80211_compatible_rates(bss, sband, &rates);
+	/* add all rates which were marked to be used above */
 	supp_rates_len = rates_len;
 	if (supp_rates_len > 8)
 		supp_rates_len = 8;

Re: Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Justin Madru]

Vegard Nossum wrote:
> The code decodes to:
>
>   1d:   f3 a5                   rep movsl %ds:(%esi),%es:(%edi)
>   1f:   89 c1                   mov    %eax,%ecx
>   21:   83 e1 03                and    $0x3,%ecx
>   24:   74 02                   je     0x28
>   26:   f3 a4                   rep movsb %ds:(%esi),%es:(%edi)
>   28:   8b 5d d0                mov    -0x30(%ebp),%ebx
>    0:   8b 9b 90 00 00 00       mov    0x90(%ebx),%ebx <---- BAM!
>    6:   85 db                   test   %ebx,%ebx
>    8:   89 5d d8                mov    %ebx,-0x28(%ebp)
>    b:   0f 84 6d 03 00 00       je     0x37e
>   11:   8b 7d cc                mov    -0x34(%ebp),%edi
>   14:   8b                      .byte 0x8b
>
> Recompiling net/mac80211/mlme.c gives me that this happens on line 675.
>
> ieee80211_compatible_rates net/mac80211/mlme.c:675
> ieee80211_send_assoc net/mac80211/mlme.c:767
> ieee80211_associate net/mac80211/mlme.c:955
>
> So it is in fact compatible_rates() that crashes (but hidden in your
> Oops because of heavy inlining).
>
> So looking at the latest changelog in linus/master, we have this change:
>
> commit 0d580a774b3682b8b2b5c89ab9b813d149ef28e7
> Author: Helmut Schaa <hschaa@suse.de>
> Date:   Tue May 20 09:56:37 2008 +0200
>
>     mac80211: fix NULL pointer dereference in ieee80211_compatible_rates
>
>     Fix a possible NULL pointer dereference in ieee80211_compatible_rates
>     introduced in the patch "mac80211: fix association with some APs". If no bss
>     is available just use all supported rates in the association request.
>
>     Signed-off-by: Helmut Schaa <hschaa@suse.de>
>     Signed-off-by: John W. Linville <linville@tuxdriver.com>
>
> So does applying/cherry-picking that fix your problem? (Patch
> attached, but not inlined.)
>
> Vegard
I'll try that patch (probably just doing a git pull). But since the oops 
is hard to trigger, it will take a while to test, and make sure that 
fixed the problem.

How did you "decode" the oops and find what file and line number that 
had the problem?
I tried to follow Documentation/oops-tracing.txt but I didn't know where 
to start.

Justin Madru

Re: Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Vegard Nossum]

Hi,

On Mon, May 26, 2008 at 7:01 PM, Justin Madru <jdm64@gawab.com> wrote:
> Vegard Nossum wrote:
>>
>> commit 0d580a774b3682b8b2b5c89ab9b813d149ef28e7
>> Author: Helmut Schaa <hschaa@suse.de>
>> Date:   Tue May 20 09:56:37 2008 +0200
>>
>>    mac80211: fix NULL pointer dereference in ieee80211_compatible_rates
>>
>>    Fix a possible NULL pointer dereference in ieee80211_compatible_rates
>>    introduced in the patch "mac80211: fix association with some APs". If
>> no bss
>>    is available just use all supported rates in the association request.
>>
>>    Signed-off-by: Helmut Schaa <hschaa@suse.de>
>>    Signed-off-by: John W. Linville <linville@tuxdriver.com>
>>
>> So does applying/cherry-picking that fix your problem? (Patch
>> attached, but not inlined.)
>
> I'll try that patch (probably just doing a git pull). But since the oops is
> hard to trigger, it will take a while to test, and make sure that fixed the
> problem.
>

Btw, I don't really see what access point association has to do with
playing a movie, so I'm inclined to believe the patch actually won't
fix your problem. But that's what the oops was. Perhaps you were
unlucky and hit a combination of two different issues... We'll see.

> How did you "decode" the oops and find what file and line number that had
> the problem?
> I tried to follow Documentation/oops-tracing.txt but I didn't know where to
> start.

To this, I will simply re-post an answer that I gave earlier today (in private):

--------
On Mon, May 26, 2008 at 2:56 PM, Carlos R. Mafra <> wrote:
> How did you do that?
>
> I see that among the number in Code: there is the sequence f3 a5 89 etc,
> but how do you know the first column (1d: 1f: 21: etc) and the assembly
> code from that?
>

There is a script scripts/decodecode to be found in the Linux source code.

I simply type

    echo 'Code: c6 00 00 ...' | bash scripts/decodecode

and it gives the full disassembly listing. Check out the script source
if you want to know exactly how it works, though yeah, you got the
general idea correct :-)

> And what is the reason for the "<---BAM!"? What exactly is the problem
> in doing that mov 0x90(%ebx), %ebx ?
>

:-) This was just my comment to say exactly where the fault happened.
If you look at the Code: line you will notice that one instruction has
<> around it, in this case "... 5d d0 <8b> 9b 90 ...". This is the EIP
address that triggered the Page Fault in the first place (this is
saved on the stack when the processor calls the page fault handler).

> Did you compile the same code and did a objdump and grep'ed for those
> strings? Is that how you do it?
>

Yes. I first find out which file the function belongs to using grep
(ieee80211_associate belongs to net/mac80211/mlme.c).

Then I initialise a default configuration, i.e. 'make defconfig' and
compile the file in question, i.e. 'make net/mac80211/mlme.o' (notice
the .o suffix).

There are some hints you can use. From the original report:
> > > EIP is at ieee80211_associate+0x24f/0x610 [mac80211]

The meaning of this +m/n syntax is: n is the size of the function (in
bytes) and m is at which offset from the beginning of the function
that the fault occurred. So from this you can deduce about where the
fault occurred in the newly compiled file (it is good to check that
the size of your newly compiled function roughly matches the size of
the crashing code). And you can look for similarities, but this cannot
be automated very well because the registers and structure may be
different, etc. A good clue is looking for constant offset movs, since
these typically mean the dereferencing of some struct, e.g. in this
case:

> > mov    0x90(%ebx),%ebx

Which probably means that %ebx was a pointer to a struct and 0x90 was
the offset of a particular member from the beginning of that struct.
(And structs tend to be semi-stable even over different configs. But
this is not always the case.)

There are cases where the newly generated assembly code is completely
different from what was in the Oops. You should at least have the same
kernel version as in the report (git makes checking out older
revisions very easy), but having the same config and gcc will probably
help a lot as well (in this case, I had neither his config nor his gcc
version, but I was lucky :-)).

If you can find the equivalent instruction that is faulting, you can
take the address that is shown by objdump (I used 'objdump -d
net/mac80211/mlme.o') and feed this to the addr2line program, such as:
'addr2line -e net/mac80211/mlme.o -i 203a', which will give you the
file/line information output that I posted in my previous e-mail.
--------

Hope this answers your question, please do ask if anything is still unclear :)


Vegard

PS: Some similar oops decoding was previously demonstrated on LKML
(Rusty Russell? I don't remember.). I couldn't find it with Google,
but maybe somebody else can give a pointer?

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Carlos R. Mafra]

 
> PS: Some similar oops decoding was previously demonstrated on LKML
> (Rusty Russell? I don't remember.). I couldn't find it with Google,
> but maybe somebody else can give a pointer?

Heh, I did some more research and found this example by Linus himself:

http://lkml.org/lkml/2008/1/7/406

Re: Oops in mac80211 with 2.6.26-rc3 triggered playing a video

[Justin Madru]

I've been testing .26-rc4 and I haven't had it lock up - yet. It seems 
like rc4 is more stable than rc3. It seems to fix some other problems I 
was having.

Vegard Nossum wrote:
> Btw, I don't really see what access point association has to do with
> playing a movie, so I'm inclined to believe the patch actually won't
> fix your problem. But that's what the oops was. Perhaps you were
> unlucky and hit a combination of two different issues... We'll see.
>   
Yeah, I thought the same thing. Why would a network related oops be 
triggered by video playback. It was probably just a coincidence - 
hitting two bugs at once! And I think the video playback lockup was due 
to something that got fixed in rc4 that Linus mentioned.

Linus Torvalds wrote:
> But most of the changes, as usual, are in drivers, at 60%, with some DRI 
> changes leading the way (fixing a number of other regressions, mainly by 
> reverting the under-cooked vblank update).

Justin Madru