Description of problem: Since upgrading from Fedora 10 to Fedora 11 my Gigabyte AirCruiser G usb adapter is no longer able to connect to my WPA/WPA2 Personal wireless router. Version-Release number of selected component (if applicable): NetworkManager-0.7.1-8.git20090708.fc11.x86_64 How reproducible: Every time, using any Fedora 11 released version of NetworkManager Steps to Reproduce: 1. Select the network in the NetworkManager Applet 2. Enter the password Actual results: After a short while the password prompt re-appears. See kernel log below. Expected results: To be connected, authenticated and get network info via DHCP. This worked fine in Fedora 10. Additional info: kernel log: usb 2-2.1.4: new high speed USB device using ehci_hcd and address 8 usb 2-2.1.4: New USB device found, idVendor=1044, idProduct=8008 usb 2-2.1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 usb 2-2.1.4: Product: 802.11 bg WLAN usb 2-2.1.4: Manufacturer: Ralink usb 2-2.1.4: configuration #1 chosen from 1 choice cfg80211: Calling CRDA to update world regulatory domain cfg80211: World regulatory domain updated: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) phy0: Selected rate control algorithm 'minstrel' Registered led device: rt73usb-phy0::radio Registered led device: rt73usb-phy0::assoc Registered led device: rt73usb-phy0::quality usbcore: registered new interface driver rt73usb cfg80211: Calling CRDA for country: NO cfg80211: Regulatory domain changed to country: NO (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm) (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm) (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm) (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm) rt73usb 2-2.1.4:1.0: firmware: requesting rt73.bin ADDRCONF(NETDEV_UP): wlan0: link is not ready wlan0: authenticate with AP 00:22:07:02:68:34 wlan0: authenticated wlan0: associate with AP 00:22:07:02:68:34 wlan0: RX AssocResp from 00:22:07:02:68:34 (capab=0x411 status=0 aid=3) wlan0: associated ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready wlan0: disassociating by local choice (reason=3) wlan0: no IPv6 routers present wlan0: direct probe to AP 00:22:07:02:68:34 try 1 wlan0: direct probe to AP 00:22:07:02:68:34 try 2 wlan0 direct probe responded wlan0: authenticate with AP 00:22:07:02:68:34 wlan0: authenticated wlan0: associate with AP 00:22:07:02:68:34 wlan0: RX AssocResp from 00:22:07:02:68:34 (capab=0x411 status=0 aid=3) wlan0: associated wlan0: disassociating by local choice (reason=3) wlan0: direct probe to AP 00:22:07:02:68:34 try 1 wlan0 direct probe responded wlan0: authenticate with AP 00:22:07:02:68:34 wlan0: authenticated wlan0: associate with AP 00:22:07:02:68:34 wlan0: RX AssocResp from 00:22:07:02:68:34 (capab=0x411 status=0 aid=3) wlan0: associated wlan0: disassociating by local choice (reason=3)
Thanks for filling this bug. Can you please add your entirely /var/log/messages after the problem occur? Thank you. -- Fedora Bugzappers volunteer triage team https://fedoraproject.org/wiki/BugZappers
Here is the full /var/log/messages from the moment the device is plugged in, to the moment I give up on trying to connect: Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: new high speed USB device using ehci_hcd and address 7 Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: New USB device found, idVendor=1044, idProduct=8008 Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: Product: 802.11 bg WLAN Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: Manufacturer: Ralink Sep 24 17:43:57 localhost kernel: usb 2-2.1.4: configuration #1 chosen from 1 choice Sep 24 17:43:57 localhost kernel: cfg80211: Calling CRDA to update world regulatory domain Sep 24 17:43:57 localhost kernel: cfg80211: World regulatory domain updated: Sep 24 17:43:57 localhost kernel: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) Sep 24 17:43:57 localhost kernel: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Sep 24 17:43:57 localhost kernel: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Sep 24 17:43:57 localhost kernel: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Sep 24 17:43:57 localhost kernel: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Sep 24 17:43:57 localhost kernel: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Sep 24 17:43:58 localhost kernel: Registered led device: rt73usb-phy0::radio Sep 24 17:43:58 localhost kernel: Registered led device: rt73usb-phy0::assoc Sep 24 17:43:58 localhost kernel: Registered led device: rt73usb-phy0::quality Sep 24 17:43:58 localhost kernel: usbcore: registered new interface driver rt73usb Sep 24 17:43:58 localhost kernel: cfg80211: Calling CRDA for country: NO Sep 24 17:43:58 localhost kernel: cfg80211: Regulatory domain changed to country: NO Sep 24 17:43:58 localhost kernel: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) Sep 24 17:43:58 localhost kernel: (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm) Sep 24 17:43:58 localhost kernel: (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm) Sep 24 17:43:58 localhost kernel: (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm) Sep 24 17:43:58 localhost kernel: (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm) Sep 24 17:43:58 localhost NetworkManager: <info> (wlan0): driver supports SSID scans (scan_capa 0x01). Sep 24 17:43:58 localhost NetworkManager: <info> (wlan0): new 802.11 WiFi device (driver: 'usb') Sep 24 17:43:58 localhost NetworkManager: <info> (wlan0): exported as /org/freedesktop/Hal/devices/net_00_24_1d_9a_bf_03 Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): device state change: 1 -> 2 (reason 2) Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): bringing up device. Sep 24 17:44:02 localhost kernel: rt73usb 2-2.1.4:1.0: firmware: requesting rt73.bin Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): preparing device. Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 2). Sep 24 17:44:02 localhost kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready Sep 24 17:44:02 localhost NetworkManager: <info> Policy set 'System eth0' (eth0) as default for routing and DNS. Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): device state change: 2 -> 3 (reason 0) Sep 24 17:44:02 localhost NetworkManager: <info> (wlan0): supplicant interface state: starting -> ready Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) starting connection 'Auto Inteno_35' Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0) Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0/wireless): access point 'Auto Inteno_35' has security, but secrets are required. Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0) Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto Inteno_35' has security, and secrets exist. No new secrets needed. Sep 24 17:44:07 localhost NetworkManager: <info> Config: added 'ssid' value 'Inteno_35' Sep 24 17:44:07 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1' Sep 24 17:44:07 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' Sep 24 17:44:07 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>' Sep 24 17:44:07 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Sep 24 17:44:07 localhost NetworkManager: <info> Config: set interface ap_scan to 1 Sep 24 17:44:07 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:44:12 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:44:13 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating Sep 24 17:44:13 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:44:13 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:44:13 localhost kernel: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Sep 24 17:44:15 localhost avahi-daemon[2086]: Registering new address record for fe80::224:1dff:fe9a:bf03 on wlan0.*. Sep 24 17:44:16 localhost ntpd[2015]: Listening on interface #6 wlan0, fe80::224:1dff:fe9a:bf03#123 Enabled Sep 24 17:44:22 localhost NetworkManager: <info> wlan0: link timed out. Sep 24 17:44:23 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:44:23 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:44:23 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:44:24 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating Sep 24 17:44:25 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:44:25 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:44:32 localhost NetworkManager: <info> Activation (wlan0/wireless): association took too long. Sep 24 17:44:32 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Sep 24 17:44:32 localhost NetworkManager: <info> Activation (wlan0/wireless): asking for new secrets Sep 24 17:44:32 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Sep 24 17:44:36 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0) Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Sep 24 17:44:36 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto Inteno_35' has security, and secrets exist. No new secrets needed. Sep 24 17:44:36 localhost NetworkManager: <info> Config: added 'ssid' value 'Inteno_35' Sep 24 17:44:36 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1' Sep 24 17:44:36 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' Sep 24 17:44:36 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>' Sep 24 17:44:36 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Sep 24 17:44:36 localhost NetworkManager: <info> Config: set interface ap_scan to 1 Sep 24 17:44:36 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:44:37 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating Sep 24 17:44:37 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:44:37 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:44:47 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:44:47 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:44:47 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:44:48 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating Sep 24 17:44:49 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> associated Sep 24 17:44:59 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:44:59 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:44:59 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:45:00 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating Sep 24 17:45:01 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:45:01 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:45:02 localhost NetworkManager: <info> Activation (wlan0/wireless): association took too long. Sep 24 17:45:02 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Sep 24 17:45:02 localhost NetworkManager: <info> Activation (wlan0/wireless): asking for new secrets Sep 24 17:45:02 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:45:10 localhost pulseaudio[2407]: reserve-wrap.c: Failed to acquire reservation lock on device 'Audio0': Input/output error Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Sep 24 17:45:11 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0) Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Sep 24 17:45:11 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto Inteno_35' has security, and secrets exist. No new secrets needed. Sep 24 17:45:11 localhost NetworkManager: <info> Config: added 'ssid' value 'Inteno_35' Sep 24 17:45:11 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1' Sep 24 17:45:11 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' Sep 24 17:45:11 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>' Sep 24 17:45:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Sep 24 17:45:11 localhost NetworkManager: <info> Config: set interface ap_scan to 1 Sep 24 17:45:11 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:45:11 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:45:11 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:45:12 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating Sep 24 17:45:12 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:45:12 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:45:22 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:45:22 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:45:22 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:45:23 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating Sep 24 17:45:24 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:45:24 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:45:34 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:45:34 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Sep 24 17:45:34 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Sep 24 17:45:35 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating Sep 24 17:45:36 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Sep 24 17:45:36 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Sep 24 17:45:37 localhost NetworkManager: <info> Activation (wlan0/wireless): association took too long. Sep 24 17:45:37 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Sep 24 17:45:37 localhost NetworkManager: <info> Activation (wlan0/wireless): asking for new secrets Sep 24 17:45:37 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Sep 24 17:45:38 localhost pulseaudio[2407]: reserve-wrap.c: Failed to acquire reservation lock on device 'Audio0': Input/output error Sep 24 17:45:38 localhost NetworkManager: <WARN> get_secrets_cb(): Couldn't get connection secrets: applet-device-wifi.c.1541 (get_secrets_dialog_response_cb): canceled. Sep 24 17:45:38 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 9 (reason 7) Sep 24 17:45:38 localhost NetworkManager: <info> Activation (wlan0) failed for access point (Inteno_35) Sep 24 17:45:38 localhost NetworkManager: <info> Marking connection 'Auto Inteno_35' invalid. Sep 24 17:45:38 localhost NetworkManager: <info> Activation (wlan0) failed. Sep 24 17:45:38 localhost NetworkManager: <info> (wlan0): device state change: 9 -> 3 (reason 0) Sep 24 17:45:38 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 0). Sep 24 17:45:38 localhost NetworkManager: <info> Policy set 'System eth0' (eth0) as default for routing and DNS.
What specific kernel version, and can you attach the output of dmesg showing the insertion of the device? It should look something like this: usb 2-1: new high speed USB device using ehci_hcd and address 2 usb 2-1: New USB device found, idVendor=148f, idProduct=2573 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 usb 2-1: Product: 802.11 bg WLAN usb 2-1: Manufacturer: Ralink usb 2-1: configuration #1 chosen from 1 choice phy1 -> rt2500usb_init_eeprom: Error - Invalid RT chipset detected. phy1 -> rt2x00lib_probe_dev: Error - Failed to allocate device. usbcore: registered new interface driver rt2500usb phy2: Selected rate control algorithm 'minstrel' Registered led device: rt73usb-phy2::radio Registered led device: rt73usb-phy2::assoc Registered led device: rt73usb-phy2::quality usbcore: registered new interface driver rt73usb I can get an rt73usb device associating fine using 2.6.30.9-90.fc11.x86_64, which is the latest Fedora 11 updated kernel. Let me know!
FOr the record, those error messages didn't affect operation, and the AP I was associating to is a WPA-PSK/TKIP AP.
Using kernel 2.6.30.9-96.fc11.x86_64 the kernel log when attaching is : usb 2-2.1.3: new high speed USB device using ehci_hcd and address 7 usb 2-2.1.3: New USB device found, idVendor=1044, idProduct=8008 usb 2-2.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 usb 2-2.1.3: Product: 802.11 bg WLAN usb 2-2.1.3: Manufacturer: Ralink usb 2-2.1.3: configuration #1 chosen from 1 choice cfg80211: Calling CRDA to update world regulatory domain cfg80211: World regulatory domain updated: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) phy0: Selected rate control algorithm 'minstrel' Registered led device: rt73usb-phy0::radio Registered led device: rt73usb-phy0::assoc Registered led device: rt73usb-phy0::quality usbcore: registered new interface driver rt73usb rt73usb 2-2.1.3:1.0: firmware: requesting rt73.bin
(In reply to comment #5) > Using kernel 2.6.30.9-96.fc11.x86_64 the kernel log when attaching is : > > usb 2-2.1.3: new high speed USB device using ehci_hcd and address 7 > usb 2-2.1.3: New USB device found, idVendor=1044, idProduct=8008 > usb 2-2.1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 > usb 2-2.1.3: Product: 802.11 bg WLAN > usb 2-2.1.3: Manufacturer: Ralink > usb 2-2.1.3: configuration #1 chosen from 1 choice > cfg80211: Calling CRDA to update world regulatory domain > cfg80211: World regulatory domain updated: > (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) > (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) > (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) > (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) > (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) > (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) > phy0: Selected rate control algorithm 'minstrel' > Registered led device: rt73usb-phy0::radio > Registered led device: rt73usb-phy0::assoc > Registered led device: rt73usb-phy0::quality > usbcore: registered new interface driver rt73usb > rt73usb 2-2.1.3:1.0: firmware: requesting rt73.bin So does that work? Or is this log from a failure as well?
That log is from a failure. I will soon be able to try a fresh Fedora 11 re-install if you think the Fedora 10 to 11 upgrade process maybe caused the breakage.
(In reply to comment #7) > That log is from a failure. I will soon be able to try a fresh Fedora 11 > re-install if you think the Fedora 10 to 11 upgrade process maybe caused the > breakage. Probably not... So, lets take this a step further. Can you put add "-dddt" to the end of the Exec= line in /usr/share/dbus-1/system-services/fi.epitest.hostap.WPASupplicant.service so that it looks like: Exec=/usr/sbin/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -u -f /var/log/wpa_supplicant.log -dddt (all on one line of course) Then 'killall -TERM wpa_supplicant', plug the dongle in, and try to get it to connect. When it fails, grab /var/log/wpa_supplicant.log and attach it to this bug report. The output of NetworkManager from /var/log/messages for the failure would also be helpful. Thanks!
Created attachment 369525 [details] wpa_supplicant.log
Here's the NetworkManager messages from /var/log/messages while generating the wp_supplicant.log: Nov 14 10:15:06 localhost NetworkManager: <info> starting... Nov 14 10:15:06 localhost NetworkManager: <WARN> nm_generic_enable_loopback(): error -17 returned from rtnl_addr_add():#012Sucess#012 Nov 14 10:15:06 localhost NetworkManager: <info> (eth0): new Ethernet device (driver: 'r8169') Nov 14 10:15:06 localhost NetworkManager: <info> (eth0): exported as /org/freedesktop/Hal/devices/net_00_50_8d_98_ac_8e Nov 14 10:15:06 localhost NetworkManager: <info> Trying to start the supplicant... Nov 14 10:15:06 localhost NetworkManager: <info> Trying to start the system settings daemon... Nov 14 10:15:06 localhost nm-system-settings: Loaded plugin ifcfg-rh: (c) 2007 - 2008 Red Hat, Inc. To report bugs please use the NetworkManager mailing list. Nov 14 10:15:11 localhost NetworkManager: <info> (eth0): device state change: 1 -> 2 (reason 2) Nov 14 10:15:11 localhost NetworkManager: <info> (eth0): bringing up device. Nov 14 10:15:11 localhost NetworkManager: <info> (eth0): preparing device. Nov 14 10:15:11 localhost NetworkManager: <info> (eth0): deactivating device (reason: 2). Nov 14 10:16:55 localhost NetworkManager: <info> Trying to start the supplicant... Nov 14 10:17:01 localhost NetworkManager: <info> (wlan0): driver supports SSID scans (scan_capa 0x01). Nov 14 10:17:01 localhost NetworkManager: <info> (wlan0): new 802.11 WiFi device (driver: 'usb') Nov 14 10:17:01 localhost NetworkManager: <info> (wlan0): exported as /org/freedesktop/Hal/devices/net_00_24_1d_9a_bf_03 Nov 14 10:17:05 localhost NetworkManager: <info> (wlan0): device state change: 1 -> 2 (reason 2) Nov 14 10:17:05 localhost NetworkManager: <info> (wlan0): bringing up device. Nov 14 10:17:06 localhost NetworkManager: <info> (wlan0): preparing device. Nov 14 10:17:06 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 2). Nov 14 10:17:06 localhost NetworkManager: <info> (wlan0): device state change: 2 -> 3 (reason 0) Nov 14 10:17:06 localhost NetworkManager: <info> (wlan0): supplicant interface state: starting -> ready Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) starting connection 'Auto Inteno_35' Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0) Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0/wireless): access point 'Auto Inteno_35' has security, but secrets are required. Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0) Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0) Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto Inteno_35' has security, and secrets exist. No new secrets needed. Nov 14 10:17:11 localhost NetworkManager: <info> Config: added 'ssid' value 'Inteno_35' Nov 14 10:17:11 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1' Nov 14 10:17:11 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' Nov 14 10:17:11 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>' Nov 14 10:17:11 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Nov 14 10:17:11 localhost NetworkManager: <info> Config: set interface ap_scan to 1 Nov 14 10:17:11 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Nov 14 10:17:16 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Nov 14 10:17:17 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating Nov 14 10:17:17 localhost NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake Nov 14 10:17:17 localhost NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated Nov 14 10:17:26 localhost NetworkManager: <info> wlan0: link timed out. Nov 14 10:17:27 localhost NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected Nov 14 10:17:27 localhost NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning Nov 14 10:17:36 localhost NetworkManager: <info> Activation (wlan0/wireless): association took too long. Nov 14 10:17:36 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0) Nov 14 10:17:36 localhost NetworkManager: <info> Activation (wlan0/wireless): asking for new secrets Nov 14 10:17:36 localhost NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected Nov 14 10:17:42 localhost NetworkManager: <WARN> get_secrets_cb(): Couldn't get connection secrets: applet-device-wifi.c.1541 (get_secrets_dialog_response_cb): canceled. Nov 14 10:17:42 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 9 (reason 7) Nov 14 10:17:42 localhost NetworkManager: <info> Activation (wlan0) failed for access point (Inteno_35) Nov 14 10:17:42 localhost NetworkManager: <info> Marking connection 'Auto Inteno_35' invalid. Nov 14 10:17:42 localhost NetworkManager: <info> Activation (wlan0) failed. Nov 14 10:17:42 localhost NetworkManager: <info> (wlan0): device state change: 9 -> 3 (reason 0) Nov 14 10:17:42 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 0).
From the supplicant logs it looks like the driver sends an association event right in the middle of the 4-way handshake: 1258190237.498351: State: ASSOCIATING -> 4WAY_HANDSHAKE 1258190237.498405: WPA: RX message 1 of 4-Way Handshake from 00:22:07:02:68:34 (ver=1) 1258190237.499460: WPA: Renewed SNonce - hexdump(len=32): 1d bb 8a 71 e2 cd 84 5b e2 f1 ee 5f de 5f 23 3e c3 11 72 f0 04 f6 c2 42 7d f2 f0 16 1d 51 d7 1c 1258190237.499513: WPA: PTK derivation - A1=00:24:1d:9a:bf:03 A2=00:00:00:00:00:00 1258190237.499548: WPA: PMK - hexdump(len=32): [REMOVED] 1258190237.499562: WPA: PTK - hexdump(len=64): [REMOVED] 1258190237.499577: WPA: WPA IE for msg 2/4 - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02 1258190237.499596: WPA: Sending EAPOL-Key 2/4 1258190237.499610: WPA: Use BSSID (00:00:00:00:00:00) as the destination for EAPOL-Key 1258190237.499632: WPA: TX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 09 00 20 00 00 00 00 00 00 00 00 1d bb 8a 71 e2 cd 84 5b e2 f1 ee 5f de 5f 23 3e c3 11 72 f0 04 f6 c2 42 7d f2 f0 16 1d 51 d7 1c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 76 f7 c5 a9 f7 5a 44 a1 8e 1a c1 95 18 7f 59 3d 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02 1258190237.502227: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) 1258190237.502250: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added 1258190237.502263: Wireless event: cmd=0x8c02 len=269 1258190237.502276: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00)' 1258190237.502316: Association info event 1258190237.502328: req_ies - hexdump(len=60): 00 09 49 6e 74 65 6e 6f 5f 33 35 01 08 02 04 0b 16 0c 12 18 24 32 04 30 48 60 6c dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02 dd 07 00 50 f2 02 00 01 00 1258190237.502352: resp_ies - hexdump(len=53): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 dd 09 00 10 18 02 02 f4 00 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 1258190237.502376: WPA: set own WPA/RSN IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02 1258190237.502398: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1258190237.502413: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added 1258190237.502426: Wireless event: cmd=0x8b15 len=24 1258190237.502438: Wireless event: new AP: 00:22:07:02:68:34 1258190237.502450: State: 4WAY_HANDSHAKE -> ASSOCIATED which doesn't help anything. John, does this ring a bell at all? Not all rt73usb is broken with 2.6.30.9-96.fc11 as I can connect OK but the reporter cannot... Ronny, can you attach logs from 'dmesg' (run that command in a terminal) from around the time the problem occurs? The 'dmesg' output gets reset each time you boot up, so I'd suggest reproducing the issue, then doing something like 'dmesg > ~/Desktop/dmesg-log.txt' and attaching that file from your desktop. Thanks!
Created attachment 369859 [details] dmesg log dmesg log from trying to connect twice and failing
Ok thanks; the dmesg logs look OK... One more thing then. Can you run 'iwevent' in a terminal and try to reproduce the issue, then paste the 'iwevent' output into this bug?
$ iwevent Waiting for Wireless Events from interfaces... 20:28:22.585721 wlan0 Set Mode:Managed 20:28:33.895581 wlan0 Scan request completed 20:28:33.895742 wlan0 Set Mode:Managed 20:28:33.916637 wlan0 Set Frequency:2.462 GHz (Channel 11) 20:28:33.944314 wlan0 Custom driver event:ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00) 20:28:33.945365 wlan0 New Access Point/Cell address:00:22:07:02:68:34 20:28:43.946549 wlan0 New Access Point/Cell address:Not-Associated 20:28:45.260556 wlan0 Scan request completed 20:28:45.260576 wlan0 Set Mode:Managed 20:28:45.260585 wlan0 Set Frequency:2.462 GHz (Channel 11) 20:28:45.295094 wlan0 Custom driver event:ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00) 20:28:45.296153 wlan0 New Access Point/Cell address:00:22:07:02:68:34 20:28:49.278216 wlan0 Scan request completed 20:28:53.004456 wlan0 New Access Point/Cell address:Not-Associated 20:28:57.473558 wlan0 Scan request completed 20:28:57.473579 wlan0 Set Mode:Managed 20:28:57.473587 wlan0 Set Frequency:2.462 GHz (Channel 11) 20:28:57.514343 wlan0 Custom driver event:ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00) 20:28:57.515297 wlan0 New Access Point/Cell address:00:22:07:02:68:34 20:29:07.516114 wlan0 New Access Point/Cell address:Not-Associated 20:29:08.815019 wlan0 Scan request completed 20:29:08.815040 wlan0 Set Mode:Managed 20:29:08.815049 wlan0 Set Frequency:2.462 GHz (Channel 11) 20:29:08.850845 wlan0 Custom driver event:ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00) 20:29:08.851820 wlan0 New Access Point/Cell address:00:22:07:02:68:34 20:29:18.852902 wlan0 New Access Point/Cell address:Not-Associated 20:29:20.151178 wlan0 Scan request completed 20:29:20.151473 wlan0 Set Mode:Managed 20:29:20.151484 wlan0 Set Frequency:2.462 GHz (Channel 11) 20:29:20.187882 wlan0 Custom driver event:ASSOCINFO(ReqIEs=0009496e74656e6f5f3335010802040b160c12182432043048606cdd160050f20101000050f20201000050f20201000050f202dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd090010180202f4000000dd180050f2020101800003a4000027a4000042435e0062322f00) 20:29:20.188857 wlan0 New Access Point/Cell address:00:22:07:02:68:34 20:29:21.002320 wlan0 New Access Point/Cell address:Not-Associated
With the lastest update of NetworkManager (NetworkManager-0.7.998-2.git20100106.fc12.x86_64) and kernel (kernel-2.6.31.12-174.2.22.fc12.x86_64) my card is once more working correctly.