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 😉