Bug 1834 - Adapter loose network unexpectedly and fails to restart until system reboot
: Adapter loose network unexpectedly and fails to restart until system reboot
Status: RESOLVED FIXED
: iwlwifi
others
: official kernel (2.6.*)
: 3945 (Intel(R) WiFi Link 3945) All
: P2 normal
Assigned To:
:
:
:
:
:
  Show dependency treegraph
 
Reported: 2008-11-24 05:08 by
Modified: 2010-05-20 10:46 (History)


Attachments
"MAC is in deep sleep" patch (4.95 KB, patch)
2009-01-20 10:26, reinette chatre
Details | Diff
Enable stuck queue detection on 3945 (915 bytes, patch)
2010-05-19 15:39, reinette chatre
Details | Diff


Note

You need to log in before you can comment on or make changes to this bug.


Description From 2008-11-24 05:08:33
I'm expecting this problem several times a day.
Adapter has lost network. Dmesg output:
wlan0: No ProbeResp from current AP 00:1a:92:42:29:bc - assume out of range
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_QOS_PARAM: time out after 500ms.
iwl3945: Error sending REPLY_QOS_PARAM: time out after 500ms.
iwl3945: Error sending REPLY_QOS_PARAM: time out after 500ms.
iwl3945: Error sending REPLY_QOS_PARAM: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_ABORT_CMD: time out after 500ms.
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
wlan0: authenticate with AP 00:1a:92:42:29:bc
iwl3945: Error sending REPLY_SCAN_ABORT_CMD: time out after 500ms.
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
wlan0: authenticate with AP 00:1a:92:42:29:bc
wlan0: authenticate with AP 00:1a:92:42:29:bc
wlan0: authenticate with AP 00:1a:92:42:29:bc
wlan0: authentication with AP 00:1a:92:42:29:bc timed out
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.

I tried to restart interface:
iwl3945: Error sending REPLY_SCAN_ABORT_CMD: time out after 500ms.
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
iwl3945: Error sending REPLY_SCAN_ABORT_CMD: time out after 500ms.
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
hda-intel: IRQ timing workaround is activated for card #0. Suggest a bigger
bdl_pos_adj.
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled

I tried to remove/insert iwl3945 module
iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux,
1.2.26ks
iwl3945: Copyright(c) 2003-2008 Intel Corporation
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: Detected Intel Wireless WiFi Link 3945ABG
iwl3945: Error: saturation power is -1, less than minimum expected 40
iwl3945: Invalid power index
iwl3945: initializing regulatory failed: -5
iwl3945: probe of 0000:06:00.0 failed with error -5

Only system reboot helps.

Hardware: Sony Vaio VGN-SZ2XPR laptop
OS: Gentoo Linux
Kernel: gentoo-sources-2.6.27-r3
Driver: iwl3945 from kernel tree

lspci output:
00:00.0 Host bridge: Intel Corporation Mobile 945GM/PM/GMS, 943/940GML and
945GT Express Memory Controller Hub (rev 03)
00:01.0 PCI bridge: Intel Corporation Mobile 945GM/PM/GMS, 943/940GML and 945GT
Express PCI Express Root Port (rev 03)
00:1b.0 Audio device: Intel Corporation 82801G (ICH7 Family) High Definition
Audio Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 1
(rev 02)
00:1c.1 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 2
(rev 02)
00:1c.2 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 3
(rev 02)
00:1c.3 PCI bridge: Intel Corporation 82801G (ICH7 Family) PCI Express Port 4
(rev 02)
00:1d.0 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI
Controller #1 (rev 02)
00:1d.1 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI
Controller #2 (rev 02)
00:1d.2 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI
Controller #3 (rev 02)
00:1d.3 USB Controller: Intel Corporation 82801G (ICH7 Family) USB UHCI
Controller #4 (rev 02)
00:1d.7 USB Controller: Intel Corporation 82801G (ICH7 Family) USB2 EHCI
Controller (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev e2)
00:1f.0 ISA bridge: Intel Corporation 82801GBM (ICH7-M) LPC Interface Bridge
(rev 02)
00:1f.1 IDE interface: Intel Corporation 82801G (ICH7 Family) IDE Controller
(rev 02)
00:1f.2 IDE interface: Intel Corporation 82801GBM/GHM (ICH7 Family) SATA IDE
Controller (rev 02)
00:1f.3 SMBus: Intel Corporation 82801G (ICH7 Family) SMBus Controller (rev 02)
01:00.0 VGA compatible controller: nVidia Corporation G72M [GeForce Go 7400]
(rev a1)
06:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG Network
Connection (rev 02)
07:00.0 Ethernet controller: Marvell Technology Group Ltd. 88E8036 PCI-E Fast
Ethernet Controller (rev 15)
09:04.0 CardBus bridge: Texas Instruments PCIxx12 Cardbus Controller
09:04.1 FireWire (IEEE 1394): Texas Instruments PCIxx12 OHCI Compliant IEEE
1394 Host Controller
09:04.2 Mass storage controller: Texas Instruments 5-in-1 Multimedia Card
Reader (SD/MMC/MS/MS PRO/xD)
0a:00.0 USB Controller: NEC Corporation USB (rev 43)
0a:00.1 USB Controller: NEC Corporation USB (rev 43)
------- Comment #1 From 2008-12-09 16:30:22 -------
Problem is fixed with http://marc.info/?l=linux-wireless&m=122849275528099&w=2
------- Comment #2 From 2008-12-16 12:57:13 -------
This patch is for iwl-4965.c but problem appears on 3945 not 4965 adapter.
------- Comment #3 From 2009-01-20 10:26:19 -------
Created an attachment (id=1797) [details]
"MAC is in deep sleep" patch

Nikolay,

We have created a patch against Linus's tree, which is currently at 2.6.29-rc2.
Could you please try the attached patch?
------- Comment #4 From 2009-01-21 10:59:14 -------
Marking as fixed - waiting for Nikolay's test results.
------- Comment #5 From 2009-01-23 06:35:45 -------
Bug still appears. Not as often as before but appears. And when I'm trying to
remove/insert module after adapter has lost network kernel dumps some
exception. Here is dmesg dump

hda-intel: IRQ timing workaround is activated for card #0. Suggest a bigger
bdl_pos_adj.
wlan0: No ProbeResp from current AP 00:1a:92:42:29:bc - assume out of range
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_RXON_ASSOC: time out after 500ms.
iwl3945: Error setting RXON_ASSOC configuration (-110).
iwl3945: Error sending REPLY_RXON_ASSOC: time out after 500ms.
iwl3945: Error setting RXON_ASSOC configuration (-110).
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
wlan0: direct probe to AP 00:1a:92:42:29:bc try 1
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
iwl3945: Error sending REPLY_RXON: time out after 500ms.
iwl3945: Error setting new configuration (-110).
wlan0: direct probe to AP 00:1a:92:42:29:bc try 1
wlan0: direct probe to AP 00:1a:92:42:29:bc try 2
wlan0: direct probe to AP 00:1a:92:42:29:bc try 3
wlan0: direct probe to AP 00:1a:92:42:29:bc timed out
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.

Restarting wlan0
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out after 500ms.
iwl3945: Error sending REPLY_SCAN_CMD: time out after 500ms.
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_SCAN_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: iwl3945_enqueue_hcmd failed: -28
iwl3945: No space for Tx
iwl3945: Error sending REPLY_RXON: iwl3945_enqueue_hcmd failed: -28
iwl3945: Error setting new configuration (-28).
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945: MAC is in deep sleep!
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: MAC is in deep sleep!
iwl3945: Unable to int nic
iwl3945 0000:06:00.0: PCI INT A disabled

Removing/inserting iwl3945 module
cfg80211: Using static regulatory domain info
cfg80211: Regulatory domain: US
        (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
        (2402000 KHz - 2472000 KHz @ 40000 KHz), (600 mBi, 2700 mBm)
        (5170000 KHz - 5190000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
        (5190000 KHz - 5210000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
        (5210000 KHz - 5230000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
        (5230000 KHz - 5330000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
        (5735000 KHz - 5835000 KHz @ 40000 KHz), (600 mBi, 3000 mBm)
cfg80211: Calling CRDA for country: US
lib80211: common routines for IEEE802.11 drivers
lib80211_crypt: registered algorithm 'NULL'
iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux,
1.2.26kds
iwl3945: Copyright(c) 2003-2008 Intel Corporation
iwl3945 0000:06:00.0: power state changed by ACPI to D0
iwl3945 0000:06:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945: Error: saturation power is -1, less than minimum expected 40
iwl3945: Invalid power index
iwl3945: initializing regulatory failed: -5
BUG: unable to handle kernel NULL pointer dereference at 00000010
IP: [<c01337c7>] wq_cpu_map+0x7/0x14
*pde = 00000000
Oops: 0000 [#1] PREEMPT SMP
last sysfs file:
/sys/devices/LNXSYSTM:00/device:00/PNP0A08:00/device:45/PNP0C09:00/PNP0C0A:00/power_supply/BAT1/energy_full
Modules linked in: iwl3945(+) rfkill mac80211 led_class lib80211 cfg80211
sha1_generic ppp_mppe ppp_async crc_ccitt ipv6 snd_pcm_oss snd_mixer_oss
snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device tun iptable_raw
xt_connmark xt_CONNMARK xt_MARK iptable_mangle ipt_REJECT xt_owner
iptable_filter xt_tcpudp xt_mark iptable_nat nf_nat nf_conntrack_ipv4
nf_conntrack nf_defrag_ipv4 ip_tables x_tables rfcomm hidp l2cap option
usbserial ppp_generic slhc sonypi nvidia(P) arc4 ecb snd_hda_codec_idt
snd_hda_intel snd_hda_codec yenta_socket tifm_7xx1 i2c_i801 snd_pcm
rsrc_nonstatic tifm_core btusb snd_timer pcmcia_core rng_core snd bluetooth
sky2 sony_laptop soundcore backlight evdev thermal processor snd_page_alloc
fuse ext3 jbd dm_snapshot dm_mirror dm_region_hash dm_log scsi_wait_scan sbp2
ohci1394 ieee1394 usbhid ohci_hcd uhci_hcd usb_storage hid ehci_hcd usbcore
scsi_transport_fc sr_mod sg [last unloaded: cfg80211]

Pid: 14063, comm: modprobe Tainted: P           (2.6.29-rc2 #3) VGN-SZ2XRP_C
EIP: 0060:[<c01337c7>] EFLAGS: 00210292 CPU: 0
EIP is at wq_cpu_map+0x7/0x14
EAX: c0426428 EBX: fffffffb ECX: 00200046 EDX: 00000000
ESI: 00000000 EDI: f70ff000 EBP: f0f90dc0 ESP: ef89fd54
 DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process modprobe (pid: 14063, ti=ef89e000 task=f64dbb40 task.ti=ef89e000)
Stack:
 c0133bdc fffffffb ffffffff f70ff000 f904e4b1 f905e23c fffffffb 00000001
 f701c774 c02012a5 c06e63b8 00000000 ef89fdc8 c06e63a8 00000007 f701c774
 00000001 fffffe81 00000000 00000007 f6be05c0 00000001 c02014b0 f6be05c0
Call Trace:
 [<c0133bdc>] destroy_workqueue+0xa/0x7a
 [<f904e4b1>] iwl3945_pci_probe+0x59b/0x1573 [iwl3945]
 [<c02012a5>] idr_get_empty_slot+0xeb/0x273
 [<c02014b0>] ida_get_new_above+0x83/0x17c
 [<c0182c70>] find_inode+0x37/0x61
 [<c01b00cc>] sysfs_ilookup_test+0x0/0xd
 [<c01b069c>] sysfs_addrm_finish+0x3a/0x1c6
 [<c01b111d>] sysfs_do_create_link+0x95/0x11e
 [<c01b069c>] sysfs_addrm_finish+0x3a/0x1c6
 [<c020fea5>] pci_match_device+0x9c/0xad
 [<f904df16>] iwl3945_pci_probe+0x0/0x1573 [iwl3945]
 [<c020fd5d>] local_pci_probe+0xb/0xc
 [<c02105f3>] pci_device_probe+0x51/0x6c
 [<c026eac4>] driver_probe_device+0x73/0x156
 [<c020fea5>] pci_match_device+0x9c/0xad
 [<c026ec0f>] __driver_attach+0x68/0x6a
 [<c026e1ed>] bus_for_each_dev+0x39/0x57
 [<c0210559>] pci_device_remove+0x0/0x36
 [<c026e98a>] driver_attach+0x16/0x1a
 [<c026eba7>] __driver_attach+0x0/0x6a
 [<c026e6b5>] bus_add_driver+0xa9/0x214
 [<c0210559>] pci_device_remove+0x0/0x36
 [<c026ed4e>] driver_register+0x4d/0x110
 [<f85cd000>] iwl3945_init+0x0/0x9d [iwl3945]
 [<c0210811>] __pci_register_driver+0x32/0x61
 [<f85cd000>] iwl3945_init+0x0/0x9d [iwl3945]
 [<f85cd052>] iwl3945_init+0x52/0x9d [iwl3945]
 [<c010110e>] _stext+0x26/0x144
 [<c0147bdd>] sys_init_module+0x7b/0x1ae
 [<c0174442>] sys_read+0x41/0x6a
 [<c0102ff1>] sysenter_do_call+0x12/0x25
Code: f0 ff 0d 30 92 6b c0 ba f4 ff ff ff eb d8 89 5c 24 04 c7 04 24 1c fd 39
c0 e8 87 31 ff ff eb e0 90 90 90 90 89 c2 b8 28 64 42 c0 <8b> 52 10 85 d2 0f 45
05 24 64 42 c0 c3 31 c0 83 3d 2c 64 42 c0
EIP: [<c01337c7>] wq_cpu_map+0x7/0x14 SS:ESP 0068:ef89fd54
---[ end trace 6c071fe381b3fcf4 ]---
------- Comment #6 From 2009-01-26 01:58:53 -------
If you need any other debug info I can gather let me know.
------- Comment #7 From 2009-02-03 04:56:35 -------
I'll join the crowd for this bug/problem.

My hardware is Lenovo T61 4GB ram and I occasionally experience most probably
the same issue - - I think it's most visible if the powertop enables powersave
for wifi driver. 

If there will be a new patch I'll try it.

03:00.0 0280: 8086:4227 (rev 02)
        Subsystem: 8086:1011
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR+ FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort-
<MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 32
        Region 0: Memory at df3ff000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [c8] Power Management version 2
                Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA
PME(D0+,D1-,D2-,D3hot+,D3cold+)
                Status: D0 PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [d0] MSI: Mask- 64bit+ Count=1/1 Enable+
                Address: 00000000fee0300c  Data: 41d9
        Capabilities: [e0] Express (v1) Legacy Endpoint, MSI 00
                DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns,
L1 unlimited
                        ExtTag- AttnBtn- AttnInd- PwrInd- RBE- FLReset-
                DevCtl: Report errors: Correctable- Non-Fatal- Fatal-
Unsupported-
                        RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
                        MaxPayload 128 bytes, MaxReadReq 128 bytes
                DevSta: CorrErr+ UncorrErr+ FatalErr- UnsuppReq+ AuxPwr+
TransPend-
                LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency
L0 <128ns, L1 <64us
                        ClockPM+ Surprise- LLActRep- BwNot-
                LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain-
CommClk+
                        ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+
DLActive- BWMgmt- ABWMgmt-
        Capabilities: [100] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq+ ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES- TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt-
RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP+ Rollover- Timeout- NonFatalErr-
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
                AERCap: First Error Pointer: 14, GenCap- CGenEn- ChkCap- ChkEn-
        Capabilities: [140] Device Serial Number 87-02-03-ff-ff-bf-1c-00
        Kernel driver in use: iwl3945
        Kernel modules: iwl3945




kernel: [ 1920.604151] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
NetworkManager: <info>  (wlan0): supplicant connection state:  completed ->
disconnected
NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected ->
scanning
kernel: [ 1921.104139] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1921.604142] iwl3945: Error sending REPLY_RXON_ASSOC: time out after
500ms.
kernel: [ 1921.604152] iwl3945: Error setting RXON_ASSOC configuration (-110).
kernel: [ 1922.113316] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
NetworkManager: <info>  (wlan0): supplicant connection state:  scanning ->
associating
kernel: [ 1922.613304] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1923.114144] iwl3945: Error sending REPLY_RXON_ASSOC: time out after
500ms.
kernel: [ 1923.114154] iwl3945: Error setting RXON_ASSOC configuration (-110).
kernel: [ 1923.613316] iwl3945: Error sending REPLY_RXON_ASSOC: time out after
500ms.
kernel: [ 1923.613326] iwl3945: Error setting RXON_ASSOC configuration (-110).
kernel: [ 1924.113312] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1924.113321] iwl3945: Error setting new configuration (-110).
kernel: [ 1924.614138] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1924.614148] iwl3945: Error setting new configuration (-110).
kernel: [ 1925.114118] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1925.114127] iwl3945: Error setting new configuration (-110).
NetworkManager: <info>  (wlan0): supplicant connection state:  associating ->
disconnected
NetworkManager: <info>  (wlan0): device state change: 8 -> 3
NetworkManager: <info>  (wlan0): deactivating device (reason: 11).
NetworkManager: <info>  wlan0: canceled DHCP transaction, dhcp client pid 3189
NetworkManager: <info>  Setting system hostname to 'localhost.localdomain' (no
default device)
dnsmasq[2514]: no servers found in /etc/resolv.conf, will retry
NetworkManager: <WARN>  check_one_route(): (wlan0) error -34 returned from
rtnl_route_del(): Sucess#012
NetworkManager: <info>  Activation (wlan0) starting connection 'Auto AP'
NetworkManager: <info>  (wlan0): device state change: 3 -> 4
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
started...
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
complete.
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
starting...
NetworkManager: <info>  (wlan0): device state change: 4 -> 5
NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto AP'
requires no security.  No secrets needed.
NetworkManager: <info>  Config: added 'ssid' value 'AP'
NetworkManager: <info>  Config: added 'scan_ssid' value '1'
NetworkManager: <info>  Config: added 'key_mgmt' value 'NONE'
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
complete.
nm-dispatcher.action: nm_dispatcher_action: Invalid connection: '(null)' /
'connection setting not found' invalid: 1
vpnc[3680]: udp sendto: Invalid argument
NetworkManager: <info>  Config: set interface ap_scan to 1
NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected ->
scanning
kernel: [ 1936.316586] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1936.316591] iwl3945: Error setting new configuration (-110).
kernel: [ 1936.817466] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1936.817476] iwl3945: Error setting new configuration (-110).
NetworkManager: <info>  (wlan0): supplicant connection state:  scanning ->
disconnected
ntpd[2228]: Deleting interface #7 wlan0, 192.168.192.99#123, interface stats:
received=64, sent=64, dropped=0, active_time=1378 secs
vpnc[3680]: udp sendto: Invalid argument
NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected ->
scanning
kernel: [ 1943.616584] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1944.117444] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1949.116675] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1949.617480] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
vpnc[3680]: keepalive sendto: Invalid argument
NetworkManager: <info>  wlan0: link timed out.
vpnc[3680]: udp sendto: Invalid argument
kernel: [ 1954.617476] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1955.116638] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1960.117475] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1960.616593] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
vpnc[3680]: keepalive sendto: Invalid argument
NetworkManager: <info>  Activation (wlan0/wireless): association took too long,
failing activation.
NetworkManager: <info>  (wlan0): device state change: 5 -> 9
NetworkManager: <info>  Activation (wlan0) failed for access point (AP)
NetworkManager: <info>  Marking connection 'Auto AP' invalid.
NetworkManager: <info>  Activation (wlan0) failed.
NetworkManager: <info>  (wlan0): device state change: 9 -> 3
NetworkManager: <info>  (wlan0): deactivating device (reason: 0).
NetworkManager: <info>  Activation (wlan0) starting connection 'AP'
NetworkManager: <info>  (wlan0): device state change: 3 -> 4
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
started...
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
scheduled...
NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare)
complete.
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
starting...
NetworkManager: <info>  (wlan0): device state change: 4 -> 5
NetworkManager: <info>  Activation (wlan0/wireless): connection 'AP' requires
no security.  No secrets needed.
NetworkManager: <info>  Config: added 'ssid' value 'AP'
NetworkManager: <info>  Config: added 'scan_ssid' value '1'
NetworkManager: <info>  Config: added 'key_mgmt' value 'NONE'
NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure)
complete.
NetworkManager: <info>  Config: set interface ap_scan to 1
NetworkManager: <info>  (wlan0): supplicant connection state:  scanning ->
disconnected
kernel: [ 1961.404118] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1961.404128] iwl3945: Error setting new configuration (-110).
kernel: [ 1961.903332] iwl3945: Error sending REPLY_RXON: time out after 500ms.
kernel: [ 1961.903342] iwl3945: Error setting new configuration (-110).
ntpd[2228]: Deleting interface #9 tun0, 10.32.10.56#123, interface stats:
received=17, sent=18, dropped=0, active_time=1206 secs
NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected ->
scanning
kernel: [ 1965.620786] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1966.119981] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1971.119955] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1971.619962] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
NetworkManager: <info>  wlan0: link timed out.
kernel: [ 1976.619951] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1977.119966] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
kernel: [ 1982.119979] iwl3945: Error sending REPLY_SCAN_CMD: time out after
500ms.
kernel: [ 1982.620945] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD: time out
after 500ms.
NetworkManager: <info>  Activation (wlan0/wireless): association took too long,
failing activation.
NetworkManager: <info>  (wlan0): device state change: 5 -> 9
NetworkManager: <info>  Activation (wlan0) failed for access point (AP)
NetworkManager: <info>  Marking connection 'AP' invalid.
NetworkManager: <info>  Activation (wlan0) failed.
NetworkManager: <info>  (wlan0): device state change: 9 -> 3
NetworkManager: <info>  (wlan0): deactivating device (reason: 0).
kernel: [ 1985.909219] iwl3945: No space for Tx
kernel: [ 1985.909233] iwl3945: Error sending REPLY_RXON: iwl3945_enqueue_hcmd
failed: -28
kernel: [ 1985.909239] iwl3945: Error setting new configuration (-28).
kernel: [ 1985.909281] iwl3945: No space for Tx
kernel: [ 1985.909286] iwl3945: Error sending REPLY_RXON: iwl3945_enqueue_hcmd
failed: -28
kernel: [ 1985.909291] iwl3945: Error setting new configuration (-28).
kernel: [ 2040.107171] iwl3945: No space for Tx
kernel: [ 2040.107179] iwl3945: Error sending REPLY_SCAN_CMD:
iwl3945_enqueue_hcmd failed: -28
kernel: [ 2040.107266] iwl3945: No space for Tx
kernel: [ 2040.107268] iwl3945: Error sending REPLY_TX_PWR_TABLE_CMD:
iwl3945_enqueue_hcmd failed: -28
------- Comment #8 From 2009-02-03 08:45:19 -------
Zdenek,

Do you perhaps have details of what powertop does to enable powersave?
------- Comment #9 From 2009-02-03 09:33:32 -------
Well nothing mysterious I guess (btw powertop is developed by @intel.com
developer)

echo 5 > /sys/bus/pci/drivers/iwl3945/0000:03:00.0/power_level

I'm not saying it's direct cause - it's just that it happens more often.
------- Comment #10 From 2009-02-20 21:48:25 -------
I see this on Ubuntu Jaunty with their 2.6.28 kernel on amd64.  It seems like
the trouble is always preceded in dmesg by:

wlan0: No ProbeResp from current AP 00:13:10:e9:e3:fb - assume out of range

Whether that's the cause or result of the hardware locking up, I can't say.
------- Comment #11 From 2009-05-28 15:15:46 -------
We needed to make some changes to the register access locking. These patches
can now be found in wireless-testing. Could you please retest using that
kernel? If you need to use a stable kernel, please test with compat-wireless.
------- Comment #12 From 2009-05-28 15:57:47 -------
Change resolution to NEEDSMOREDATA until we receive results from testing of new
register locking patch.
------- Comment #13 From 2009-06-29 00:03:22 -------
Mark as Verified according to last comment
------- Comment #14 From 2010-01-04 05:52:41 -------
I can confirm this bug. I am on linux 2.6.32 and use iwlwifi-3945-ucode version
15.32.2.9.

This is in my dmesg:

iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux,
1.2.26ks
iwl3945: Copyright(c) 2003-2009 Intel Corporation
iwl3945 0000:06:00.0: PCI INT A -> Link[LNKD] -> GSI 11 (level, low) -> IRQ 11
iwl3945 0000:06:00.0: setting latency timer to 64
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF

<snip> many many more lines like this...</snip>

iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: MAC is in deep sleep!.  CSR_GP_CNTRL = 0xFFFFFFFF
iwl3945 0000:06:00.0: Error: saturation power is -1, less than minimum expected
40
iwl3945 0000:06:00.0: Invalid power index
iwl3945 0000:06:00.0: initializing driver failed
iwl3945 0000:06:00.0: PCI INT A disabled
iwl3945: probe of 0000:06:00.0 failed with error -5
------- Comment #15 From 2010-01-04 16:20:55 -------
(In reply to comment #14)
> I can confirm this bug. I am on linux 2.6.32 and use iwlwifi-3945-ucode version
> 15.32.2.9.
> 

Could you please try with the following patch as it is queued for 2.6.32 stable
http://git.kernel.org/?p=linux/kernel/git/stable/stable-queue.git;a=blob;f=queue-2.6.32/iwl3945-disable-power-save.patch;h=7a4773bbc933a43f8652acd3618c8aa817bfc8ed;hb=91642809b7b8c0a7e46d01dcf2dd3d5567489d33
?
------- Comment #16 From 2010-01-04 19:08:54 -------
(In reply to comment #14)
> I can confirm this bug. I am on linux 2.6.32 and use iwlwifi-3945-ucode version

Ramses, If you still see your issue after applying Reinette's patches, could
you please submit an new bug? This bug has been closed (marked as Verified)
long ago.
------- Comment #17 From 2010-01-05 01:14:39 -------
Did the patch make it into 2.6.32? Because that's the kernel I'm currently
using. 
And I'm sorry about posting in this closed bug report, I didn't know that
"verified" meant "closed".
------- Comment #18 From 2010-01-05 01:23:28 -------
(In reply to comment #17)
> And I'm sorry about posting in this closed bug report, I didn't know that
> "verified" meant "closed".

Sorry for the confusion. I seldom change bug status to "closed" since the bug
title is hard to read if the status is "closed".
------- Comment #19 From 2010-01-05 09:32:18 -------
(In reply to comment #17)
> Did the patch make it into 2.6.32? Because that's the kernel I'm currently
> using. 

The patch I referred to is queued for 2.6.32 stable so it should be in the next
2.6.32.x.
------- Comment #20 From 2010-01-05 09:35:19 -------
Ok, I am currently in the middle of my exams so I don't have time to compile a
patched kernel. I will do when my exams are finished (in a month.. ) if the
patch is not in the kernel by then.
------- Comment #22 From 2010-05-18 14:18:18 -------
(In reply to comment #21)
> I am running a kernel with the diffs at:
> http://git.kernel.org/?p=linux/kernel/git/stable/stable-queue.git;a=blob;f=queue-2.6.32/iwl3945-disable-power-save.patch;h=7a4773bbc933a43f8652acd3618c8aa817bfc8ed;hb=91642809b7b8c0a7e46d01dcf2dd3d5567489d33
> ?
> 
> but still hitting the problem.

Stavros, this bug report contains a few different issues and I cannot seem to
find any logs contributed by you. Which issue are you encountering?
------- Comment #23 From 2010-05-18 15:16:55 -------
(In reply to comment #22)
> (In reply to comment #21)
> > I am running a kernel with the diffs at:
> > http://git.kernel.org/?p=linux/kernel/git/stable/stable-queue.git;a=blob;f=queue-2.6.32/iwl3945-disable-power-save.patch;h=7a4773bbc933a43f8652acd3618c8aa817bfc8ed;hb=91642809b7b8c0a7e46d01dcf2dd3d5567489d33
> > ?
> > 
> > but still hitting the problem.
> 
> Stavros, this bug report contains a few different issues and I cannot seem to
> find any logs contributed by you. Which issue are you encountering?

Sorry Reinette, didn't know that there were more than one problems mentioned
here. And it might be actually that mine is a different one altogether.

Symptoms are the same. Network connectivity lost (usually under heavy network
load?), and have to shut down the interface and bring it back up to fix it.

Logs: (Not sure if the first line has actually anything to do with the network
card...)

[ 3984.896156] hda-intel: IRQ timing workaround is activated for card #0.
Suggest a bigger bdl_pos_adj.
[ 4005.504038] No probe response from AP 00:26:5a:2d:06:ca after 500ms,
disconnecting.
[ 4006.128069] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4006.128080] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4006.629039] iwl3945 0000:03:00.0: Error sending REPLY_SCAN_CMD: time out
after 500ms.
[ 4007.128491] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4007.128503] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4007.629060] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4007.629070] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4008.129035] iwl3945 0000:03:00.0: Error sending REPLY_TX_PWR_TABLE_CMD: time
out after 500ms.
[ 4012.128061] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4012.128071] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4012.629045] iwl3945 0000:03:00.0: Error sending REPLY_SCAN_CMD: time out
after 500ms.
[ 4013.129059] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4013.129070] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4013.633061] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4013.633072] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4014.133031] iwl3945 0000:03:00.0: Error sending REPLY_TX_PWR_TABLE_CMD: time
out after 500ms.
[ 4018.140028] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4018.140035] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4018.637038] iwl3945 0000:03:00.0: Error sending REPLY_SCAN_CMD: time out
after 500ms.
[ 4019.137026] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4019.137033] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4019.637073] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4019.637084] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4020.137023] iwl3945 0000:03:00.0: Error sending REPLY_TX_PWR_TABLE_CMD: time
out after 500ms.
[ 4021.541675] CE: hpet increasing min_delta_ns to 22500 nsec
[ 4024.137700] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4024.137710] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4024.636268] iwl3945 0000:03:00.0: Error sending REPLY_SCAN_CMD: time out
after 500ms.
[ 4025.137027] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4025.137034] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4025.637038] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4025.637048] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4026.137035] iwl3945 0000:03:00.0: Error sending REPLY_TX_PWR_TABLE_CMD: time
out after 500ms.
[ 4030.141151] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4030.141162] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4030.641086] iwl3945 0000:03:00.0: Error sending REPLY_SCAN_CMD: time out
after 500ms.
[ 4031.141042] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4031.141053] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4031.640068] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4031.640079] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4032.141033] iwl3945 0000:03:00.0: Error sending REPLY_TX_PWR_TABLE_CMD: time
out after 500ms.
[ 4033.376068] iwl3945 0000:03:00.0: Error sending REPLY_RXON: time out after
500ms.
[ 4033.376078] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[ 4033.376090] iwl3945 0000:03:00.0: No space for Tx
[ 4033.376096] iwl3945 0000:03:00.0: Error sending REPLY_LEDS_CMD: enqueue_hcmd
failed: -28
------- Comment #24 From 2010-05-19 10:50:07 -------
(In reply to comment #23)
> (In reply to comment #22)
> > (In reply to comment #21)
> > > I am running a kernel with the diffs at:
> > > http://git.kernel.org/?p=linux/kernel/git/stable/stable-queue.git;a=blob;f=queue-2.6.32/iwl3945-disable-power-save.patch;h=7a4773bbc933a43f8652acd3618c8aa817bfc8ed;hb=91642809b7b8c0a7e46d01dcf2dd3d5567489d33
> > > ?

It is not clear to me based on the one patch you link to above which kernel you
are running. I'd like to send you a patch to try ... on which kernel should I
base it? Since 2.6.33 has been stabilizing for a while now and 2.6.34 has just
been released ... can you try one of those? Alternatively you can use your
kernel of choice (with previous recommendations included) and obtain the latest
wireless bits using compat-wireless. None of these include the patch I am
planning though so please pick something and let me know what we are working
with so that we can work from there.

Thanks
------- Comment #25 From 2010-05-19 11:37:08 -------
(In reply to comment #24)
> (In reply to comment #23)
> > (In reply to comment #22)
> > > (In reply to comment #21)
> > > > I am running a kernel with the diffs at:
> > > > http://git.kernel.org/?p=linux/kernel/git/stable/stable-queue.git;a=blob;f=queue-2.6.32/iwl3945-disable-power-save.patch;h=7a4773bbc933a43f8652acd3618c8aa817bfc8ed;hb=91642809b7b8c0a7e46d01dcf2dd3d5567489d33
> > > > ?
> 
> It is not clear to me based on the one patch you link to above which kernel you
> are running. I'd like to send you a patch to try ... on which kernel should I
> base it? Since 2.6.33 has been stabilizing for a while now and 2.6.34 has just
> been released ... can you try one of those? Alternatively you can use your
> kernel of choice (with previous recommendations included) and obtain the latest
> wireless bits using compat-wireless. None of these include the patch I am
> planning though so please pick something and let me know what we are working
> with so that we can work from there.

Stavros, after looking into it the patch I'd like to send you has a lot of
dependencies that are in our latest code. Would it be possible to run your
wireless drivers from compat-wireless? I can then send you a patch based on our
latest code.
------- Comment #26 From 2010-05-19 15:29:13 -------
(In reply to comment #25)
> Stavros, after looking into it the patch I'd like to send you has a lot of
> dependencies that are in our latest code. Would it be possible to run your
> wireless drivers from compat-wireless? I can then send you a patch based on our
> latest code.

Sure
------- Comment #27 From 2010-05-19 15:39:05 -------
Created an attachment (id=2445) [details]
Enable stuck queue detection on 3945

(In reply to comment #26)
> (In reply to comment #25)
> > Stavros, after looking into it the patch I'd like to send you has a lot of
> > dependencies that are in our latest code. Would it be possible to run your
> > wireless drivers from compat-wireless? I can then send you a patch based on our
> > latest code.
> 
> Sure

Thanks! That makes it simpler ... could you please try attached patch?
------- Comment #28 From 2010-05-19 16:10:28 -------
(In reply to comment #27)
> Created an attachment (id=2445) [details] [details]
> Enable stuck queue detection on 3945
> 
> (In reply to comment #26)
> > (In reply to comment #25)
> > > Stavros, after looking into it the patch I'd like to send you has a lot of
> > > dependencies that are in our latest code. Would it be possible to run your
> > > wireless drivers from compat-wireless? I can then send you a patch based on our
> > > latest code.
> > 
> > Sure
> 
> Thanks! That makes it simpler ... could you please try attached patch?

Great many thanks. I think everything is much better now.

In the logs I see now:

[ 2693.016053] iwl3945 0000:03:00.0: queue 2 stuck 3 time. Fw reload.
[ 2693.016059] iwl3945 0000:03:00.0: On demand firmware reload
[ 2769.528054] iwl3945 0000:03:00.0: queue 4 stuck 3 time. Fw reload.
[ 2769.528063] iwl3945 0000:03:00.0: On demand firmware reload
------- Comment #29 From 2010-05-19 16:35:32 -------
(In reply to comment #28)
> (In reply to comment #27)
> > Created an attachment (id=2445) [details] [details] [details]
> > Enable stuck queue detection on 3945
> > 
> > (In reply to comment #26)
> > > (In reply to comment #25)
> > > > Stavros, after looking into it the patch I'd like to send you has a lot of
> > > > dependencies that are in our latest code. Would it be possible to run your
> > > > wireless drivers from compat-wireless? I can then send you a patch based on our
> > > > latest code.
> > > 
> > > Sure
> > 
> > Thanks! That makes it simpler ... could you please try attached patch?
> 
> Great many thanks. I think everything is much better now.
> 
> In the logs I see now:
> 
> [ 2693.016053] iwl3945 0000:03:00.0: queue 2 stuck 3 time. Fw reload.
> [ 2693.016059] iwl3945 0000:03:00.0: On demand firmware reload
> [ 2769.528054] iwl3945 0000:03:00.0: queue 4 stuck 3 time. Fw reload.
> [ 2769.528063] iwl3945 0000:03:00.0: On demand firmware reload

How often do you see these restarts? How does it impact your connectivity?
------- Comment #30 From 2010-05-19 16:40:28 -------
(In reply to comment #29)
> (In reply to comment #28)
> > (In reply to comment #27)
> > > Created an attachment (id=2445) [details] [details] [details] [details]
> > > Enable stuck queue detection on 3945
> > > 
> > > (In reply to comment #26)
> > > > (In reply to comment #25)
> > > > > Stavros, after looking into it the patch I'd like to send you has a lot of
> > > > > dependencies that are in our latest code. Would it be possible to run your
> > > > > wireless drivers from compat-wireless? I can then send you a patch based on our
> > > > > latest code.
> > > > 
> > > > Sure
> > > 
> > > Thanks! That makes it simpler ... could you please try attached patch?
> > 
> > Great many thanks. I think everything is much better now.
> > 
> > In the logs I see now:
> > 
> > [ 2693.016053] iwl3945 0000:03:00.0: queue 2 stuck 3 time. Fw reload.
> > [ 2693.016059] iwl3945 0000:03:00.0: On demand firmware reload
> > [ 2769.528054] iwl3945 0000:03:00.0: queue 4 stuck 3 time. Fw reload.
> > [ 2769.528063] iwl3945 0000:03:00.0: On demand firmware reload
> 
> How often do you see these restarts? How does it impact your connectivity?

Well I have been only running that for an hour or so, but I wouldn't say they
appear often. Only under heavy network load, and they don't seem to affect the
connectivity. At least it is not noticeable.


However it seems I am having more serious problems. I am sorry to bring bad
news, but it seems the new driver just crashed:

[ 3696.460864] BUG: unable to handle kernel NULL pointer dereference at (null)
[ 3696.460879] IP: [<fad50868>] iwl3945_request_scan+0x2e8/0x660 [iwl3945]
[ 3696.460900] *pde = 00000000 
[ 3696.460906] Oops: 0000 [#1] SMP 
[ 3696.460913] last sysfs file:
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/device:00/PNP0C09:00/PNP0C0A:00/power_supply/BAT0/current_now
[ 3696.460921] Modules linked in: b43legacy b43 ssb compat ath9k ath9k_common
ath9k_hw ath5k bnep rfcomm hidp hid sco l2cap btusb bluetooth at76c50x_usb
mac80211_hwsim mwl8k rndis_wlan rndis_host cdc_ether usbnet mii rt73usb
rt2500usb rt2x00usb rt61pci crc_itu_t rt2500pci rt2400pci rt2x00pci rt2x00lib
ar9170usb ath iwlagn iwl3945 iwlcore rtl8187 rtl8180 zd1211rw adm8211
eeprom_93cx6 p54usb p54pci p54common mac80211 usb8xxx libertas_cs libertas
ipw2200 ipw2100 libipw lib80211 cfg80211 compat_firmware_class btrfs
zlib_deflate crc32c libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat
jfs xfs exportfs reiserfs aes_i586 aes_generic binfmt_misc ppdev vboxnetadp
vboxnetflt vboxdrv bridge stp joydev dm_crypt snd_hda_codec_analog pcmcia
snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss arc4 snd_mixer_oss
thinkpad_acpi snd_pcm snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi
snd_seq_midi_event snd_seq ftdi_sio snd_timer snd_seq_device nsc_ircc snd
led_class usbserial nvram irda crc_ccitt yenta_socket rsrc_nonstatic psmouse
serio_raw pcmcia_core soundcore snd_page_alloc lp parport fbcon tileblit font
bitblit softcursor vga16fb vgastate radeon ttm drm_kms_helper intel_agp drm
i2c_algo_bit video output agpgart e1000e [last unloaded: bluetooth]
[ 3696.461160] 
[ 3696.461167] Pid: 15817, comm: iwl3945 Not tainted (2.6.32-22-generic
#33-Ubuntu) 2007WHH
[ 3696.461174] EIP: 0060:[<fad50868>] EFLAGS: 00010202 CPU: 0
[ 3696.461185] EIP is at iwl3945_request_scan+0x2e8/0x660 [iwl3945]
[ 3696.461191] EAX: f4c50700 EBX: 00000000 ECX: 00000000 EDX: 00000057
[ 3696.461196] ESI: 00000000 EDI: 00000000 EBP: f4f4bf38 ESP: f4f4bee0
[ 3696.461202]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 3696.461209] Process iwl3945 (pid: 15817, ti=f4f4a000 task=f4584010
task.ti=f4f4a000)
[ 3696.461213] Stack:
[ 3696.461217]  00000000 00000328 f33f66ac 00ff0057 c013ad01 f33f66ac f4584010
f45819a0
[ 3696.461232] <0> 00580021 00000000 00408740 f45b8b20 f271e800 f271e8f2
00000000 00000000
[ 3696.461247] <0> 00000000 00000001 008000d8 f45b8b20 f45b9098 f45be748
f4f4bf4c fad16397
[ 3696.461264] Call Trace:
[ 3696.461276]  [<c013ad01>] ? __enable_runtime+0x71/0xc0
[ 3696.461298]  [<fad16397>] ? iwl_bg_start_internal_scan+0x87/0xb0 [iwlcore]
[ 3696.461309]  [<c016369e>] ? run_workqueue+0x8e/0x150
[ 3696.461327]  [<fad16310>] ? iwl_bg_start_internal_scan+0x0/0xb0 [iwlcore]
[ 3696.461336]  [<c01637e4>] ? worker_thread+0x84/0xe0
[ 3696.461345]  [<c0167740>] ? autoremove_wake_function+0x0/0x50
[ 3696.461353]  [<c0163760>] ? worker_thread+0x0/0xe0
[ 3696.461360]  [<c01674b4>] ? kthread+0x74/0x80
[ 3696.461367]  [<c0167440>] ? kthread+0x0/0x80
[ 3696.461375]  [<c0104087>] ? kernel_thread_helper+0x7/0x10
[ 3696.461379] Code: ca c7 45 cc 00 00 00 00 89 5d d4 83 ea 01 66 89 55 b4 eb
13 8d b4 26 00 00 00 00 83 c6 01 39 70 08 0f 86 4d 01 00 00 8b 5c b0 20 <3b> 3b
75 ec 0f b7 43 06 89 fa 8b 4d dc 88 41 01 0f b6 c8 8b 45 
[ 3696.461470] EIP: [<fad50868>] iwl3945_request_scan+0x2e8/0x660 [iwl3945]
SS:ESP 0068:f4f4bee0
[ 3696.461486] CR2: 0000000000000000
[ 3696.461497] ---[ end trace 04557669f1c10b1f ]---
------- Comment #31 From 2010-05-20 10:46:36 -------
(In reply to comment #30)
> Well I have been only running that for an hour or so, but I wouldn't say they
> appear often. Only under heavy network load, and they don't seem to affect the
> connectivity. At least it is not noticeable.

Thanks for this information. I'll work on getting this patch into our driver.

> However it seems I am having more serious problems. I am sorry to bring bad
> news, but it seems the new driver just crashed:
> 
> [ 3696.460864] BUG: unable to handle kernel NULL pointer dereference at (null)
> [ 3696.460879] IP: [<fad50868>] iwl3945_request_scan+0x2e8/0x660 [iwl3945]

Since you are running the latest code I believe you have encountered a bug that
we just discovered ourselves. Could you please add your logs to #2208 to help
the resolution of that and also to help with the testing of the fix when it
comes out?

I now mark this bug as fixed - our validation team will verify it when the
patch enters our driver.