iwl3945: wireless stopped working after resume [jaunty]

[Marius Gedminas]

During the weekend I used a USB 3G modem with pppd directly (better debug output than network-manager), so I right-clicked on network manager's icon and disabled wireless. Today I suspended the laptop, and when I resumed and re-enabled network-manager's wifi support, it failed to see the office network.

I then saw errors about iwl3945 in dmesg. The interesting bits appear to be

[167566.978780] NetworkManager: page allocation failure. order:5, mode:0x8020
[167566.978785] Pid: 3748, comm: NetworkManager Not tainted 2.6.28-11-generic #42-Ubuntu
[167566.978787] Call Trace:
[167566.978796] [<c0500ac6>] ? printk+0x18/0x1a
[167566.978802] [<c0194267>] __alloc_pages_internal+0x387/0x490
[167566.978807] [<c01087d3>] dma_generic_alloc_coherent+0x73/0xe0
[167566.978811] [<c0108760>] ? dma_generic_alloc_coherent+0x0/0xe0
[167566.978828] [<f878ceb3>] iwl3945_tx_queue_init+0x1d3/0x2b0 [iwl3945]
[167566.978837] [<f87975c8>] iwl3945_hw_nic_init+0x3e8/0x470 [iwl3945]
[167566.978845] [<f8790032>] __iwl3945_up+0x92/0x270 [iwl3945]
[167566.978848] [<c0102ab7>] ? __switch_to+0xb7/0x1a0
[167566.978856] [<f87931e0>] iwl3945_mac_start+0x50/0x1c0 [iwl3945]
[167566.978872] [<f86520fa>] ieee80211_open+0x32a/0x830 [mac80211]

ProblemType: Bug
Architecture: i386
DistroRelease: Ubuntu 9.04
HibernationDevice: RESUME=UUID=9f432fcd-a5d0-44c3-8441-9022204fac81
MachineType: LENOVO 646655G
Package: linux-image-2.6.28-11-generic 2.6.28-11.42
ProcCmdLine: root=UUID=34a7bfc5-59dc-4d74-a131-45b6ae4663b1 ro quiet splash vga=872
ProcEnviron:
 LC_CTYPE=lt_LT.UTF-8
 PATH=(custom, user)
 LANG=lt_LT.UTF-8
 SHELL=/bin/bash
ProcVersionSignature: Ubuntu 2.6.28-11.42-generic
SourcePackage: linux

[Marius Gedminas (mgedmin)]

As a workaround I tried modprobe -r iwl3945; modprobe iwl3945. The first time it failed:

[169558.082416] iwl3945 0000:03:00.0: PCI INT A disabled
[169565.981173] cfg80211: Calling CRDA to update world regulatory domain
[169566.015332] iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux, 1.2.26ks
[169566.015340] iwl3945: Copyright(c) 2003-2008 Intel Corporation
[169566.015463] iwl3945 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
[169566.015489] iwl3945 0000:03:00.0: setting latency timer to 64
[169566.015896] iwl3945: Detected Intel Wireless WiFi Link 3945ABG
[169566.023634] iwl3945 0000:03:00.0: irq 2296 for MSI/MSI-X
[169566.066048] iwl3945: Tunable channels: 13 802.11bg, 23 802.11a channels
[169566.073639] phy0: Selected rate control algorithm 'iwl-3945-rs'
[169566.080848] udev: renamed network interface wlan0 to eth1
[169566.210176] cfg80211: World regulatory domain updated:
[169566.210181] (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[169566.210184] (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169566.210186] (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[169566.210189] (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[169566.210191] (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169566.210194] (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169570.857404] iwl3945 0000:03:00.0: firmware: requesting iwlwifi-3945-1.ucode
[169572.937108] iwl3945: Wait for START_ALIVE timeout after 2000ms.
[169575.100056] iwl3945: Wait for START_ALIVE timeout after 2000ms.

The second time it succeeded:

[169701.167113] iwl3945 0000:03:00.0: PCI INT A disabled
[169704.369274] cfg80211: Calling CRDA to update world regulatory domain
[169704.400318] iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux, 1.2.26ks
[169704.400326] iwl3945: Copyright(c) 2003-2008 Intel Corporation
[169704.400446] iwl3945 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
[169704.400473] iwl3945 0000:03:00.0: setting latency timer to 64
[169704.400927] iwl3945: Detected Intel Wireless WiFi Link 3945ABG
[169704.407187] iwl3945 0000:03:00.0: irq 2296 for MSI/MSI-X
[169704.449046] cfg80211: World regulatory domain updated:
[169704.449053] (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[169704.449059] (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169704.449065] (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[169704.449071] (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[169704.449077] (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169704.449083] (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[169704.450460] iwl3945: Tunable channels: 13 802.11bg, 23 802.11a channels
[169704.475281] phy0: Selected rate control algorithm 'iwl-3945-rs'
[169704.481428] udev: renamed network interface wlan0 to eth1
[169708.857110] iwl3945 0000:03:00.0: firmware: requesting iwlwifi-3945-1.ucode
[169708.915259] Registered led device: iwl-phy0:radio
[169708.915303] Registered led device: iwl-phy0:assoc
[169708.915343] Registered led device: iwl-phy0...

[Leann Ogasawara (leannogasawara)]

Hi Marius,

You may want to try installing linux-backports-modules-jaunty as it contains an updated compat-wireless stack. It would be good to know if you are still able to reproduce this after installing linux-backports-modules-jaunty. Please let us know. Thanks.

[Marius Gedminas (mgedmin)]

Looks like my system simply ran out of memory, and I didn't notice (because the page cache was still ~1 GB).

(Well, I did notice that it started using the disk more heavily, and blamed background cron jobs, and then two days later the system suddenly started thrashing so hard I had to reboot. When this happened again today, I noticed that all 3 gigs of swap were full, and that compiz ate 1.6 gigs of VM, and the system was thrashing despite the ~1 GB of page cache.)

[Marius Gedminas (mgedmin)]

Ah, forgot to mention: this morning I saw the same wifi-related page allocation failures. Since I was running out of memory, this is not surprising and not a bug at all. (What is a bug is that memory leak in compiz.)

[Leann Ogasawara (leannogasawara)]

Thanks, closing this report.

[Marius Gedminas (mgedmin)]

Turns out I was wrong in thinking this bug was related to UXA/GEM eating all my system RAM---I've switched to back to EXA, and this bug happened again twice. No USB 3G modems in sight either, the wifi simply croaks on resume about once every two weeks with an order-5 page allocation failure. Last time (today) I was unable to fix the issue with modprobe -r iwl3945; modprobe iwl3945 --- I kept getting the same order-5 allocation failures.

Reopening bug, installing linux-backports-modules-jaunty for testing.

[Eric Miao (eric.y.miao)]

Marius, could you test the this early after bootup to make sure the driver doesn't resume back in a memory scarce situation? And better to attach the result of 'cat /proc/meminfo' both BEFORE and AFTER the resume. Thanks.

[Marius Gedminas (mgedmin)]

I'm not sure I understand what you want me to test. I could reboot, cat /proc/meminfo, suspend, resume, cat /proc/meminfo again, but this would most likely *not* trigger this bug.

Or I could take a /proc/meminfo from a working system (either now -- uptime 11 days -- or after a fresh boot), then wait for the bug to happen again, and take /proc/meminfo after that.

Which would be preferable?

By the way, this bug hasn't reappeared since my last comment. It is possible that installing linux-backports-modules-jaunty got rid of it, or maybe I just haven't waited long enough.

[Marius Gedminas (mgedmin)]

My X just crashed on resume with this in dmesg:

    [432060.801219] Xorg: page allocation failure. order:4, mode:0xc0d0

I'm thinking now that both this (and I've had several Xorg crashes on resume in the last month) and the very similar iwl3945 high-order page allocation failures might have a common cause. Memory fragmentation caused by something, e.g. the Intel GEM module (I do use UXA, so GEM is active)?

I've captured the full contents of dmesg, /proc/meminfo and Xorg.0.log.old, but I'm not sure if I should attach them to this bug report.

[Eric Miao (eric.y.miao)]

Sure, logs are always helpful. The latest lbm-jaunty fixed several things including a rx skb allocation bug (http://intellinuxwireless.org/bugzilla/show_bug.cgi?id=1842 if you are interested). If this iwl3945 problem doesn't show up any more, I'd like to close this. And you may fire another bug for the Xorg crash on resume.

[Eric Miao (eric.y.miao)]

Looks like free memory is still plenty enough but fragmented a lot. I'm not sure if that's caused by GEM, it might be helpful to test the non-GEM version of X11 if possible. I'll close this one first, it can be re-open if same symptom found again. Thanks.