Hide Forgot
The wireless cards using the rt2860sta module fails to authenticate using WPA PSK-TKIP, most of the time. Occasionally it does succeed in connecting. It appears that NetworkManager does not wait long enough for wpa_supplicant before giving up. The NetworkManager logs during a connection attempt that fails are below. The process appears to be that it attempts to connect using the key entered earlier (before updating), this "takes too long" and it aborts, asking for a key. Upon cancellation, you can see it falls back on the connected eth0 interface. (this is a known reliable network) Hardware specifics: 01:00.0 Network controller: RaLink RT2860 Subsystem: RaLink Device 2790 Physical Slot: eeepc-wifi 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: 32 bytes Interrupt: pin A routed to IRQ 19 Region 0: Memory at f8000000 (32-bit, non-prefetchable) [size=64K] Capabilities: <access denied> Kernel driver in use: rt2800pci Kernel modules: rt2800pci Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) starting connection 'VFI Wireless' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0] Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0/wireless): access point 'VFI Wireless' has security, but secrets are required. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0] Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0] Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0/wireless): connection 'VFI Wireless' has security, and secrets exist. No new secrets needed. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: added 'ssid' value 'VFI Wireless' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: added 'scan_ssid' value '1' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: added 'key_mgmt' value 'WPA-PSK' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: added 'psk' value '<omitted>' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: added 'proto' value 'WPA RSN' Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Aug 11 09:57:56 wanderer NetworkManager[862]: <info> Config: set interface ap_scan to 1 Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: disconnected -> scanning Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: scanning -> authenticating Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: authenticating -> associating Aug 11 09:57:56 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: associating -> disconnected Aug 11 09:58:20 wanderer NetworkManager[862]: <warn> Activation (wlan0/wireless): association took too long. Aug 11 09:58:20 wanderer NetworkManager[862]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0] Aug 11 09:58:20 wanderer NetworkManager[862]: <warn> Activation (wlan0/wireless): asking for new secrets Aug 11 09:58:28 wanderer NetworkManager[862]: <warn> No agents were available for this request. Aug 11 09:58:28 wanderer NetworkManager[862]: <info> (wlan0): device state change: need-auth -> failed (reason 'no-secrets') [60 120 7] Aug 11 09:58:28 wanderer NetworkManager[862]: <warn> Activation (wlan0) failed for access point (VFI Wireless) Aug 11 09:58:28 wanderer NetworkManager[862]: <info> Marking connection 'VFI Wireless' invalid. Aug 11 09:58:28 wanderer NetworkManager[862]: <warn> Activation (wlan0) failed. Aug 11 09:58:28 wanderer NetworkManager[862]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0] Aug 11 09:58:28 wanderer NetworkManager[862]: <info> (wlan0): deactivating device (reason: 0). Aug 11 09:58:28 wanderer NetworkManager[862]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS. Aug 11 09:58:28 wanderer NetworkManager[862]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS. -------------------------------------- Should the connection succeed, this is seen: Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) starting connection 'VFI Wireless' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: completed -> disconnected Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0] Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0/wireless): access point 'VFI Wireless' has security, but secrets are required. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0] Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0] Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0] Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0/wireless): connection 'VFI Wireless' has security, and secrets exist. No new secrets needed. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: added 'ssid' value 'VFI Wireless' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: added 'scan_ssid' value '1' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: added 'key_mgmt' value 'WPA-PSK' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: added 'psk' value '<omitted>' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: added 'proto' value 'WPA RSN' Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Aug 11 10:12:22 wanderer NetworkManager[862]: <info> Config: set interface ap_scan to 1 Aug 11 10:12:22 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: disconnected -> scanning Aug 11 10:12:23 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: scanning -> associating Aug 11 10:12:23 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: associating -> associated Aug 11 10:12:24 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: associated -> 4-way handshake Aug 11 10:12:24 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: 4-way handshake -> group handshake Aug 11 10:12:24 wanderer NetworkManager[862]: <info> (wlan0): supplicant interface state: group handshake -> completed Aug 11 10:12:24 wanderer NetworkManager[862]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'VFI Wireless'. Aug 11 10:12:24 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. Aug 11 10:12:24 wanderer NetworkManager[862]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... Aug 11 10:12:24 wanderer NetworkManager[862]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0] Aug 11 10:12:24 wanderer NetworkManager[862]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds) The system then goes on to perform the DHCP transaction and business continues as usual. dmesg is fairly uneventful:[ 1228.599579] cfg80211: Calling CRDA for country: US [ 1228.627705] cfg80211: Regulatory domain changed to country: US [ 1228.627715] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) [ 1228.627725] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm) [ 1228.627734] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm) [ 1228.627743] cfg80211: (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) [ 1228.627752] cfg80211: (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) [ 1228.627761] cfg80211: (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) [ 1228.627770] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm) [ 1229.463489] wlan0: authenticate with 00:20:a6:50:ec:7d (try 1) [ 1229.465161] wlan0: authenticated [ 1229.465833] wlan0: associate with 00:20:a6:50:ec:7d (try 1) [ 1229.467855] wlan0: RX ReassocResp from 00:20:a6:50:ec:7d (capab=0x431 status=0 aid=4) [ 1229.467867] wlan0: associated [ 1240.594056] wlan0: no IPv6 routers present However, when it is taking a long time to authenticate this is what is seen (this is where NetworkManager "gives up") [ 261.962241] wlan0: authenticate with 00:20:a6:50:ec:7d (try 1) [ 261.963772] wlan0: authenticated [ 261.976318] wlan0: associate with 00:20:a6:50:ec:7d (try 1) [ 261.980265] wlan0: deauthenticated from 00:20:a6:50:ec:7d (Reason: 6) [ 293.547733] wlan0: authenticate with 00:20:a6:4f:28:0c (try 1) [ 293.551408] wlan0: authenticated [ 293.562458] wlan0: associate with 00:20:a6:4f:28:0c (try 1) [ 293.564821] wlan0: deauthenticated from 00:20:a6:4f:28:0c (Reason: 6) [ 323.738518] wlan0: authenticate with 00:20:a6:4f:28:0c (try 1) [ 323.741426] wlan0: authenticated [ 323.752491] wlan0: associate with 00:20:a6:4f:28:0c (try 1) [ 323.754375] wlan0: deauthenticated from 00:20:a6:4f:28:0c (Reason: 6) [ 363.024440] wlan0: authenticate with 00:20:a6:50:ec:7d (try 1) [ 363.026086] wlan0: authenticated [ 363.033329] wlan0: associate with 00:20:a6:50:ec:7d (try 1) [ 363.038518] wlan0: deauthenticated from 00:20:a6:50:ec:7d (Reason: 6) [ 846.319151] wlan0: authenticate with 00:20:a6:50:ec:7d (try 1) [ 846.328611] wlan0: authenticated [ 846.340163] wlan0: associate with 00:20:a6:50:ec:7d (try 1) [ 846.343466] wlan0: RX AssocResp from 00:20:a6:50:ec:7d (capab=0x431 status=0 aid=12) [ 846.343477] wlan0: associated [ 846.347693] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
I apoligize! When originally writing this I had thought it was a kernel problem. It became apparent that it was an issue with NetworkManager during the process, and I failed to update the component I was filing against!
Why do you think NM is at fault? Have you successfully connected without NM? Do you still see the issue? If so, please report: * dmesg * nm-tool * /var/log/messages * /var/log/wpa_supplicant.log (best with debugging on see http://live.gnome.org/NetworkManager/Debugging/#wpa_supplicant07) * rpm -q NetworkManager * uname -r
This message is a notice that Fedora 15 is now at end of life. Fedora has stopped maintaining and issuing updates for Fedora 15. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At this time, all open bugs with a Fedora 'version' of '15' have been closed as WONTFIX. (Please note: Our normal process is to give advanced warning of this occurring, but we forgot to do that. A thousand apologies.) Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, feel free to reopen this bug and simply change the 'version' to a later Fedora version. Bug Reporter: Thank you for reporting this issue and we are sorry that we were unable to fix it before Fedora 15 reached end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged to click on "Clone This Bug" (top right of this page) and open it against that version of Fedora. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping