Problems with ipw3945 on my new laptop

I’ll use this blog entry to collect all information which could be helpful in debugging the ipw3945 issue I’m having on my new laptop (Sony VAIO VGN-FZ15).

I opened a bug report at bughost.org.

uname -a says:
Linux wang 2.6.22-gentoo-r2 #8 SMP Mon Aug 6 09:20:59 CST 2007 i686 Intel(R) Core(TM)2 Duo CPU T7100 @ 1.80GHz GenuineIntel GNU/Linux

lspci says:
00:00.0 Host bridge: Intel Corporation Mobile Memory Controller Hub (rev 0c)
00:01.0 PCI bridge: Intel Corporation Mobile PCI Express Root Port (rev 0c)
00:1a.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Contoller #4 (rev 03)
00:1a.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #5 (rev 03)
00:1a.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #2 (rev 03)
00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio Controller (rev 03)
00:1c.0 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 1 (rev 03)
00:1c.1 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 2 (rev 03)
00:1c.2 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 3 (rev 03)
00:1c.4 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 5 (rev 03)
00:1d.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #1 (rev 03)
00:1d.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #2 (rev 03)
00:1d.2 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #3 (rev 03)
00:1d.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #1 (rev 03)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev f3)
00:1f.0 ISA bridge: Intel Corporation Mobile LPC Interface Controller (rev 03)
00:1f.1 IDE interface: Intel Corporation Mobile IDE Controller (rev 03)
00:1f.2 SATA controller: Intel Corporation Mobile SATA AHCI Controller (rev 03)
00:1f.3 SMBus: Intel Corporation 82801H (ICH8 Family) SMBus Controller (rev 03)
01:00.0 VGA compatible controller: nVidia Corporation Unknown device 0426 (rev a1)
06:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG Network Connection (rev 02)
08:00.0 Ethernet controller: Marvell Technology Group Ltd. 88E8036 PCI-E Fast Ethernet Controller (rev 16)
09:03.0 CardBus bridge: Texas Instruments PCIxx12 Cardbus Controller
09:03.1 FireWire (IEEE 1394): Texas Instruments PCIxx12 OHCI Compliant IEEE 1394 Host Controller
09:03.2 Mass storage controller: Texas Instruments 5-in-1 Multimedia Card Reader (SD/MMC/MS/MS PRO/xD)

pcitweak -l says:
PCI: 06:00:0: chip 8086,4222 card 8086,1052 rev 02 class 02,80,00 hdr 00

This is a Gentoo system – eix ipw3945 says:
[I] net-wireless/ipw3945
Available versions: 1.0.5 1.2.0 [M](~)1.2.1 {debug kernel_linux}
Installed versions: 1.2.0(11:16:15 08/05/07)(-debug kernel_linux)
Homepage: http://ipw3945.sourceforge.net/
Description: Driver for the Intel PRO/Wireless 3945ABG miniPCI express adapter

[I] net-wireless/ipw3945-ucode
Available versions: 1.13 1.14.2
Installed versions: 1.14.2(10:35:35 08/02/07)
Homepage: http://www.bughost.org/ipw3945/
Description: Microcode for the Intel PRO/Wireless 3945ABG miniPCI express adapter

[I] net-wireless/ipw3945d
Available versions: 1.7.18 1.7.22-r4
Installed versions: 1.7.22-r4(10:35:22 08/02/07)
Homepage: http://www.bughost.org/ipw3945/
Description: Regulatory daemon for the Intel PRO/Wireless 3945ABG miniPCI express adapter

/var/log/everything/… just before a total system lockup / freeze:

Aug 8 06:53:11 [kernel] ipw3945: Error sending cmd #07 to daemon: time out after 500ms.
Aug 8 06:53:13 [kernel] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Aug 8 06:53:13 [kernel] ipw3945: Error sending cmd #08 to daemon: time out after 500ms.
Aug 8 06:53:14 [kernel] ipw3945: Error sending ADD_STA: time out after 500ms.
Aug 8 06:53:14 [wpa_cli] interface wlan DISCONNECTED
Aug 8 06:53:14 [kernel] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Aug 8 06:53:15 [rc-scripts] WARNING: you are stopping a boot service.
Aug 8 06:53:17 [dhcpcd] wlan: received SIGTERM, stopping
Aug 8 06:53:17 [dhcpcd] wlan: removing default route via 192.168.178.1 metric 2000
Aug 8 06:53:17 [dhcpcd] wlan: deleting IP address 192.168.178.25/24
Aug 8 06:53:17 [dhcpcd] wlan: exiting

Sometimes the system is locked up only for a couple of seconds,
and then recovers, for example once it looked like this in dmesg:

ipw3945: Error sending LEDS_CMD: time out after 500ms.
ipw3945: Error sending cmd #07 to daemon: time out after 500ms.
ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
ipw3945: Error sending cmd #08 to daemon: time out after 500ms.
ipw3945: Error sending ADD_STA: time out after 500ms.
ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
ipw3945: Error sending LEDS_CMD: time out after 500ms.
ipw3945: Error sending LEDS_CMD: time out after 500ms.
ipw3945: Detected geography ABG (13 802.11bg channels, 4 802.11a channels)
ipw3945: Error sending LEDS_CMD: time out after 500ms.

And another one:
Aug 16 21:03:04 [kernel] ipw3945: Error sending cmd #07 to daemon: time out after 500ms.
Aug 16 21:03:06 [kernel] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Aug 16 21:03:07 [kernel] ipw3945: Error sending cmd #08 to daemon: time out after 500ms.
Aug 16 21:03:07 [kernel] ipw3945: Error sending ADD_STA: time out after 500ms.
Aug 16 21:03:07 [wpa_cli] interface wlan DISCONNECTED
Aug 16 21:03:07 [rc-scripts] WARNING: you are stopping a boot service.
Aug 16 21:03:08 [kernel] ipw3945: Error sending SCAN_ABORT_CMD: time out after 500ms.
Aug 16 21:03:08 [dhcpcd] wlan: received SIGTERM, stopping
Aug 16 21:03:08 [dhcpcd] wlan: removing default route via 192.168.0.4 metric 2000
Aug 16 21:03:08 [dhcpcd] wlan: deleting IP address 192.168.0.21/24
Aug 16 21:03:08 [dhcpcd] wlan: exiting
Aug 16 21:03:24 [kernel] BUG: unable to handle kernel NULL pointer dereference at virtual address 00000012
Aug 16 21:03:24 [kernel] printing eip:
Aug 16 21:03:24 [kernel] c011e1f0
Aug 16 21:03:24 [kernel] *pde = 00000000
Aug 16 21:03:24 [kernel] Modules linked in: truecrypt rfcomm l2cap snd_pcm_oss snd_mixer_oss snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device ipv6 ieee80211_crypt_ccmp af_packet bridge llc iptable_mangle iptable_nat nf_nat ipt_REJECT xt_tcpudp nf_conntrack_ipv4 xt_state iptable_filter ip_tables x_tables aes dm_crypt dm_mod vboxdrv nf_conntrack_ftp nf_conntrack tifm_7xx1 tifm_sd mmc_core tifm_core coretemp cpufreq_ondemand acpi_cpufreq freq_table thermal processor fan button battery ac usbhid usb_storage hci_usb nvidia(P) ipw3945 ieee80211 ieee80211_crypt firmware_class snd_hda_intel snd_pcm snd_timer snd soundcore snd_page_alloc ehci_hcd yenta_socket rsrc_nonstatic pcmcia_core uhci_hcd usbcore intel_agp agpgart ohci1394
Aug 16 21:04:07 [kernel] ipw3945: Error sending LEDS_CMD: time out after 500ms.
- Last output repeated twice -
Aug 16 21:04:10 [kernel] ipw3945: Detected geography ABG (13 802.11bg channels, 4 802.11a channels)
Aug 16 21:04:12 [wpa_cli] interface wlan CONNECTED
Aug 16 21:04:13 [dhcpcd] wlan: dhcpcd 3.1.4 starting
Aug 16 21:04:13 [dhcpcd] wlan: hardware address = 00:1b:77:...
Aug 16 21:04:13 [dhcpcd] wlan: DUID = 00:01:00:01:0e:39:...
Aug 16 21:04:13 [dhcpcd] wlan: broadcasting for a lease
Aug 16 21:04:29 [dhcpcd] wlan: offered 192.168.0.21 from 192.168.0.4
Aug 16 21:04:29 [dhcpcd] wlan: checking 192.168.0.21 is available on attached networks
Aug 16 21:04:30 [dhcpcd] wlan: leased 192.168.0.21 for 864000 seconds
Aug 16 21:04:30 [dhcpcd] wlan: adding IP address 192.168.0.21/24
Aug 16 21:04:30 [dhcpcd] wlan: adding route to 192.168.0.0/24 metric 2000
Aug 16 21:04:30 [dhcpcd] wlan: removing route to 192.168.0.0/24 metric 0
Aug 16 21:04:30 [dhcpcd] wlan: adding default route via 192.168.0.4 metric 2000
Aug 16 21:04:30 [wpa_cli] interface wlan DISCONNECTED
Aug 16 21:04:30 [rc-scripts] WARNING: you are stopping a boot service.
Aug 16 21:04:31 [dhcpcd] wlan: received SIGTERM, stopping
Aug 16 21:04:31 [dhcpcd] wlan: removing default route via 192.168.0.4 metric 2000
Aug 16 21:04:31 [dhcpcd] wlan: deleting IP address 192.168.0.21/24
Aug 16 21:04:31 [dhcpcd] wlan: exiting
Aug 16 21:04:31 [wpa_cli] interface wlan CONNECTED
Aug 16 21:04:32 [dhcpcd] wlan: dhcpcd 3.1.4 starting
Aug 16 21:04:32 [dhcpcd] wlan: hardware address = 00:1b:77:...
Aug 16 21:04:32 [dhcpcd] wlan: DUID = 00:01:00:01:0e:39:...
Aug 16 21:04:32 [dhcpcd] wlan: broadcasting for a lease
Aug 16 21:04:33 [dhcpcd] wlan: offered 192.168.0.21 from 192.168.0.4
Aug 16 21:04:33 [dhcpcd] wlan: checking 192.168.0.21 is available on attached networks
Aug 16 21:04:34 [dhcpcd] wlan: leased 192.168.0.21 for 864000 seconds
Aug 16 21:04:34 [dhcpcd] wlan: adding IP address 192.168.0.21/24
Aug 16 21:04:34 [dhcpcd] wlan: adding route to 192.168.0.0/24 metric 2000
Aug 16 21:04:34 [dhcpcd] wlan: removing route to 192.168.0.0/24 metric 0
Aug 16 21:04:34 [dhcpcd] wlan: adding default route via 192.168.0.4 metric 2000

And again – this time with debugging switched on (echo 0x00043FFF >/sys/bus/pci/drivers/ipw3945/debug_level). The log has 270KB, you can get it here:

IPW3945 temporary freeze debug log (2007-08-21)

And there is nothing more refreshing than a freezing computer while reading the news in the morning and having a cup of coffee 😉

IPW3945 permanent freeze debug log – probably not complete, because unwritten log data got lost (2007-08-21)

VMware –> VirtualBox

Because of ongoing problems with VMware Workstation 5.5.x’s kernel module that can’t be used with Linux 2.6.22, because of the fact that VMware is asking me to pay $99 to upgrade to VMware Workstation 6.0 (after I paid quite a sum for VMware Workstation 5.0 some time ago) and because of some other reasons (problems with GTK, only supporting OSS for sound output, …) that accumulated over time, I decided to give VirtualBox a try. And so far it looks really great. The fact that it has been completely open sourced, and it has been created by a company just some kilometres away from my home town are also a bonus 😉 The only thing I’m missing so far, is the “Team” stuff of VMware Workstation – which is great for building a small – completely virtual – test network, without having to fiddle with tun/tap on the host machine.

Great job, innotek! Thanks a lot!