ipw3945 in 2.6.24-23 not connecting WPAPSK AES

[Jacek_G]

KUBUNTU 8.04
today i have upgraded to kernel 2.6.24-23 and my wifi card intel 3945 (hp nx7400 laptop) stoped connecting.
data from /var/log/deamon.log
when not working:
Jan 9 14:53:09 gemini NetworkManager: <debug> [1231509189.201342] nm_device_802_11_wireless_get_activation_ap(): Forcing AP 'orion-net'
Jan 9 14:53:09 gemini NetworkManager: <info> User Switch: /org/freedesktop/NetworkManager/Devices/eth1 / orion-net
Jan 9 14:53:09 gemini NetworkManager: <info> Deactivating device eth1.
Jan 9 14:53:09 gemini NetworkManager: <info> Device eth1 activation scheduled...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) started...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Jan 9 14:53:09 gemini NetworkManager: <info> Activation (eth1/wireless): access point 'orion-net' is encrypted, and a key exists. No new key needed.
Jan 9 14:53:10 gemini NetworkManager: <info> retry to connect to global supplicant socket (try=1)
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'INTERFACE_ADD eth1^I^Iwext^I/var/run/wpa_supplicant0^I'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> kernel_driver for non broadcast check: iwl3945 (has_scan_capa_ssid=0)
Jan 9 14:53:10 gemini NetworkManager: <info> using has_buggy_apscan_2 fix for iwl3945
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'AP_SCAN 1'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'ADD_NETWORK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was '0'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 6f72696f6e2d6e6574'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 scan_ssid 1'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
Jan 9 14:53:10 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:53:10 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Jan 9 14:53:16 gemini NetworkManager: <info> Old device 'eth1' activating, won't change.
Jan 9 14:53:26 gemini NetworkManager: <WARN> request_and_convert_scan_results(): card took too much time scanning. Get a better one.
Jan 9 14:53:32 gemini NetworkManager: <info> Old device 'eth1' activating, won't change.
Jan 9 14:53:39 gemini hcid[17086]: Default passkey agent (:1.201, /org/kde/kbluetooth_1234) unregistered
Jan 9 14:53:47 gemini NetworkManager: <WARN> request_and_convert_scan_results(): card took too much time scanning. Get a better one.
Jan 9 14:53:53 gemini NetworkManager: <info> Old device 'eth1' activating, won't change.

When working (on kernel 2.6.24-22):
Jan 9 14:59:32 gemini NetworkManager: <info> Activation (eth1) New wireless user key requested for network 'orion-net'.
Jan 9 14:59:32 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) New wireless user key for network 'orion-net' received.
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Jan 9 14:59:33 gemini NetworkManager: <info> Activation (eth1/wireless): access point 'orion-net' is encrypted, and a key exists. No new key needed.
Jan 9 14:59:34 gemini NetworkManager: <info> retry to connect to global supplicant socket (try=1)
Jan 9 14:59:34 gemini NetworkManager: <info> SUP: sending command 'INTERFACE_ADD eth1^I^Iwext^I/var/run/wpa_supplicant0^I'
Jan 9 14:59:34 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> kernel_driver for non broadcast check: iwl3945 (has_scan_capa_ssid=0)
Jan 9 14:59:35 gemini NetworkManager: <info> using has_buggy_apscan_2 fix for iwl3945
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'AP_SCAN 1'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'ADD_NETWORK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was '0'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 6f72696f6e2d6e6574'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 scan_ssid 1'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
Jan 9 14:59:35 gemini NetworkManager: <info> SUP: response was 'OK'
Jan 9 14:59:35 gemini NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Jan 9 14:59:38 gemini modprobe: WARNING: Error inserting padlock_aes (/lib/modules/2.6.24-22-generic/kernel/drivers/crypto/padlock-aes.ko): No such device
Jan 9 14:59:38 gemini hcid[7776]: Default passkey agent (:1.25, /org/kde/kbluetooth_1234) registered
Jan 9 14:59:38 gemini hcid[7776]: Default authorization agent (:1.25, /org/kde/kbluetooth_auth_1234) registered
Jan 9 14:59:38 gemini NetworkManager: <info> Supplicant state changed: 1
Jan 9 14:59:38 gemini NetworkManager: <info> Activation (eth1/wireless) Stage 2 of 5 (Device Configure) successful. Connected to access point 'orion-net'.
Jan 9 14:59:38 gemini NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.
Jan 9 14:59:38 gemini NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) started...
Jan 9 14:59:39 gemini NetworkManager: <info> Activation (eth1) Beginning DHCP transaction.
Jan 9 14:59:39 gemini NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.
Jan 9 14:59:39 gemini NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface eth1

sorry for my english

[Leann Ogasawara (leannogasawara)]

Hi Jacek_G,

Can you capture your dmesg output after you notice this issue? Please then attach it to this report. Additionally, can you also try installing the linux-ubuntu-modules package (version 2.6.24-23.36) to see if it helps? It contains a fix for bug 226413 which sounds similar to the issue you are seeing. If the issue still exists, it might also be good to see the dmesg output from your system after you installed and tested with linux-ubuntu-modules. Thanks.

[Jacek_G (wafelj)]

i had linux-ubuntu-modules package version 2.6.24-23.36 installed, but today i wanted to catch dmesg, but suddenly... everything worked ok... i dont know, why it is working now, and why it have not worked... i'm sorry for disturbing... please close the bug...

[Yann (lostec)]

I've experienced this a few times, note the AP was up and running:

Jan 13 10:55:26 marsupilami kernel: [ 7.149411] iwl3945: Error sending REPLY_RXON: time out after 500ms.
Jan 13 10:55:26 marsupilami kernel: [ 7.149419] iwl3945: Error clearing ASSOC_MSK on current configuration (-110).
Jan 13 10:55:27 marsupilami kernel: [ 7.705032] iwl3945: Error sending REPLY_RXON: time out after 500ms.
Jan 13 10:55:27 marsupilami kernel: [ 7.705039] iwl3945: Error clearing ASSOC_MSK on current configuration (-110).
Jan 13 10:55:33 marsupilami kernel: [ 13.461886] wlan0: No ProbeResp from current AP 00:14:bf:64:95:24 - assume out of range
Jan 13 10:55:33 marsupilami kernel: [ 13.462868] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:33 marsupilami kernel: [ 13.462875] wlan0: deauthenticated
Jan 13 10:55:34 marsupilami kernel: [ 14.463446] wlan0: authenticate with AP 00:14:bf:64:95:24
Jan 13 10:55:34 marsupilami kernel: [ 14.464639] wlan0: RX authentication from 00:14:bf:64:95:24 (alg=0 transaction=2 status=0)
Jan 13 10:55:34 marsupilami kernel: [ 14.464644] wlan0: authenticated
Jan 13 10:55:34 marsupilami kernel: [ 14.464647] wlan0: associate with AP 00:14:bf:64:95:24
Jan 13 10:55:34 marsupilami kernel: [ 14.466118] wlan0: authentication frame received from 00:14:bf:64:95:24, but not in authenticate state -
ignored
Jan 13 10:55:34 marsupilami kernel: [ 14.467703] wlan0: authentication frame received from 00:14:bf:64:95:24, but not in authenticate state -
ignored
Jan 13 10:55:34 marsupilami kernel: [ 14.469111] wlan0: RX ReassocResp from 00:14:bf:64:95:24 (capab=0x411 status=0 aid=1)
Jan 13 10:55:34 marsupilami kernel: [ 14.469115] wlan0: associated
Jan 13 10:55:39 marsupilami kernel: [ 20.141377] wlan0: No ProbeResp from current AP 00:14:bf:64:95:24 - assume out of range
Jan 13 10:55:39 marsupilami kernel: [ 20.142350] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.142357] wlan0: deauthenticated
Jan 13 10:55:39 marsupilami kernel: [ 20.143477] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.144446] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.145230] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.146276] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.147286] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:39 marsupilami kernel: [ 20.148289] wlan0: RX deauthentication from 00:14:bf:64:95:24 (reason=7)
Jan 13 10:55:40 marsupilami kernel: [ 21.147900] wlan0: authenticate with AP 00:14:bf:64:95:24
Jan 13 10:55:40 marsupilami kernel: [ 21.149108] wlan0: RX authentication from 00:14:bf:64:95:24 (alg=0 transaction=2 status=0)
Jan 13 10:55:40 marsupilami kernel: [ 21.149116] wlan0: authenticated
Jan 13 10:55:40 marsupilami kernel: [ 21.149120] wlan0: associate with AP 00:14:bf:64:95:24
Jan 13 10:55:40 marsupilami kernel: [ 21.150652] wlan0: authentication frame received from 00:...

[Jacek_G (wafelj)]

ok i was wrong bug exist, but only on certain AP (or configurations), in my house it is working, but in my girlfriend is not - both use WPA - PSK one is AES (not working), and another one migth be TKIP (i dont remember, and cant check, because i use crapy netgear, and i dont have any connecting to conf in hime)

[Leann Ogasawara (leannogasawara)]

Thanks Jacek_G. Would you be willing to also test the more recent Intrepid Ibex 8.10 release? You should be able to easily test via a LiveCD. If that fails, I'd also suggest testing the most recent pre-release of Jaunty (currently Alpha 3) - http://cdimage.ubuntu.com/releases/jaunty/ . Thanks in advance.

[Jacek_G (wafelj)]

i just have tested 8.10 livecd, and i could not been able even to find i wifi network :| (iwlist wlan0 scan), i've tried to connect to network same as to hidden but this not work too...

[Yann (lostec)]

Under Hardy 2.6.24-23:
Same problem (dmesg shows deauthentications from AP) on 2 laptops using a 3945 ABG (my father's lenovo, connected on a WPA+AES-PSK AP, Orange Livebox ; my Toshiba, connected on a WPA2+AES-PSK AP, from Linksys).

issuing a "sudo /etc/init.d/networking restart" make it work most of the times... but is can deassociate the same way within minutes or hours, randomly.

I didn't made TKIP trys as this WPA setup is now unsure.

Both machines are configured "old school" with /etc/network/interfaces, not using NM (as this one does not come up before gnome keyring, used to store wifi passphrase, is unlocked by a local user login... and I need to be able to reboot remotely!).

So this may be a pure iwl and/or wpa_supplicant problem. Booting on 2.6.24-22 allows a reliable wifi.

Reading forums/newsgroup, a lot of 3945 and 4965 based laptops seems to experiment this problem.

[Yann (lostec)]

Will this huge pb for such a common wireless hardware be considered one day?

In 2.6.24-24 it's still there:

****
May 8 08:46:12 marsupilami kernel: [ 8384.134659] wlan0: No ProbeResp from current AP 00:14:bf:XX:XX:XX - assume out of range
May 8 08:46:12 marsupilami kernel: [ 8384.767249] iwl3945: Error sending REPLY_RXON: time out after 500ms.
May 8 08:46:12 marsupilami kernel: [ 8384.767260] iwl3945: Error clearing ASSOC_MSK on current configuration (-110).
May 8 08:46:13 marsupilami kernel: [ 8385.321903] iwl3945: Error sending REPLY_RXON: time out after 500ms.
(...)
May 8 08:46:30 marsupilami kernel: [ 8402.786914] iwl3945: Error clearing ASSOC_MSK on current configuration (-110).
May 8 08:46:31 marsupilami kernel: [ 8403.514440] iwl3945: Error sending REPLY_RXON: time out after 500ms.
May 8 08:46:31 marsupilami kernel: [ 8403.514451] iwl3945: Error clearing ASSOC_MSK on current configuration (-110).
May 8 08:46:31 marsupilami kernel: [ 8403.746298] iwl3945: No space for Tx
May 8 08:46:31 marsupilami kernel: [ 8403.746309] iwl3945: Error sending REPLY_RXON: iwl_enqueue_hcmd failed: -28
May 8 08:46:31 marsupilami kernel: [ 8403.746314] iwl3945: Error clearing ASSOC_MSK on current configuration (-28).
****

Note my AP neither laptop came "out of range", some poor TX/RX level management by this iwl driver may be considered... Also note under windows XP double-boot everithing is perfect... as it was under Dapper with ipw driver that should really have stayed unchanged.

Regards

[penalvch (penalvch)]

Jacek_G, thank you for reporting this and helping make Ubuntu better. Hardy desktop reached EOL on May 12, 2011.
Please see this document for currently supported Ubuntu releases:
https://wiki.ubuntu.com/Releases

We were wondering if this is still an issue on a supported release? If so, can you try with the latest development release of Ubuntu? ISO CD images are available from http://cdimage.ubuntu.com/releases/ .

If it remains an issue, could you run the following command in a supported release from a Terminal (Applications->Accessories->Terminal). It will automatically gather and attach updated debug information to this report.

apport-collect -p linux <replace-with-bug-number>

Also, if you could test the latest upstream kernel available that would be great. It will allow additional upstream developers to examine the issue. Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Once you've tested the upstream kernel, please remove the 'needs-upstream-testing' tag. This can be done by clicking on the yellow pencil icon next to the tag located at the bottom of the bug description and deleting the 'needs-upstream-testing' text. Please let us know your results.

Thanks in advance.

[Launchpad Janitor (janitor)]

[Expired for linux (Ubuntu) because there has been no activity for 60 days.]