Random connection breaks with kernel 2.6.32

Live forum: http://rt2x00.serialmonkey.com/viewtopic.php?t=6043

4javier

03-01-2010 14:45:08

[codeyurbibgp]Bus 001 Device 007: ID 050d:7050 Belkin Components F5D7050 ver 1000 WiFi
[/codeyurbibgp]

[codeyurbibgp]wlan0 IEEE 802.11bg ESSID:"Casa"
Mode:Managed Frequency:2.412 GHz Access Point: 00:1C:A2:6B:A4:83
Bit Rate=54 Mb/s Tx-Power=20 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Power Management:on
Link Quality=59/70 Signal level=-51 dBm
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0
[/codeyurbibgp]
encryption wpa tkip

dmesg just after connection break
[codeyurbibgp]phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 1 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
phy2 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
No probe response from AP 00:1c:a2:6b:a4:83 after 500ms, disconnecting.
[/codeyurbibgp]

dmesg after I phisically disconnect and reconnect the receiver
[codeyurbibgp]usb 1-2.1: USB disconnect, address 5
usb 1-2.1: new high speed USB device using ehci_hcd and address 6
usb 1-2.1: configuration #1 chosen from 1 choice
phy3: Selected rate control algorithm 'minstrel'
Registered led device: rt2500usb-phy3::radio
Registered led device: rt2500usb-phy3::quality
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
wlan0: no IPv6 routers present
ATL1E 0000:02:00.0: irq 29 for MSI/MSI-X
ADDRCONF(NETDEV_UP): eth0: link is not ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX ReassocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=12 aid=0)
wlan0: AP denied association (code=12)
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
ATL1E 0000:02:00.0: irq 29 for MSI/MSI-X
ADDRCONF(NETDEV_UP): eth0: link is not ready
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=12 aid=0)
wlan0: AP denied association (code=12)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 2)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
wlan0: no IPv6 routers present
phy3 -> rt2500usb_set_device_state: Error - Device failed to enter state 1 (-16).
phy3 -> rt2500usb_set_device_state: Error - Device failed to enter state 3 (-16).
No probe response from AP 00:1c:a2:6b:a4:83 after 500ms, disconnecting.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x0444 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x06 failed for offset 0x0444 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x04d4 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x06 failed for offset 0x04d2 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x06 failed for offset 0x04d4 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x04d4 with error -71.
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x06 failed for offset 0x04d2 with error -71.
usb 1-2.1: USB disconnect, address 6
phy3 -> rt2x00usb_vendor_request: Error - Vendor Request 0x06 failed for offset 0x04d4 with error -19.
usb 1-2.1: new high speed USB device using ehci_hcd and address 7
usb 1-2.1: configuration #1 chosen from 1 choice
phy4: Selected rate control algorithm 'minstrel'
Registered led device: rt2500usb-phy4::radio
Registered led device: rt2500usb-phy4::quality
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
ATL1E 0000:02:00.0: irq 29 for MSI/MSI-X
ADDRCONF(NETDEV_UP): eth0: link is not ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=12 aid=0)
wlan0: AP denied association (code=12)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
ADDRCONF(NETDEV_UP): wlan0: link is not ready
ATL1E 0000:02:00.0: irq 29 for MSI/MSI-X
ADDRCONF(NETDEV_UP): eth0: link is not ready
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: deauthenticating from 00:1c:a2:6b:a4:83 by local choice (reason=3)
wlan0: direct probe to AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: direct probe responded
wlan0: authenticate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: authenticated
wlan0: associate with AP 00:1c:a2:6b:a4:83 (try 1)
wlan0: RX AssocResp from 00:1c:a2:6b:a4:83 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
wlan0: no IPv6 routers present
[/codeyurbibgp]

After reconnecting, first connection attempt fails, second try goes well.

Ask me for any other information you need.

IvD

03-01-2010 15:15:38

Disable power saving
[quote1hque900]iwconfig wlan0 power off[/quote1hque900]

4javier

04-01-2010 20:35:29

Thanks, that seems to solve the problem. I'llwait until next kernel release to check if the issue will have been patched.
Thanks again D

mced

05-06-2011 09:56:45

Sorry if I'm breaking any rule raising an old thread, but I think my experience can help other people.

I've been happily using rt2x00 driver for a long time, with excellent performance with both rt2500 and rt61 chips. But after updating Debian from Lenny to Squeeze (kernel 2.6.24 > 2.6.3x), headaches began. Logs where the same as 4javier's

[code73zzvc8h]# lspci | grep -i ralink
00:0d.0 Network controller: RaLink RT2561/RT61 rev B 802.11g

# grep wlan0 /var/log/syslog | head -13
May 31 18:04:40 machine kernel: [41016.971844] wlan0: deauthenticating from 00:13:10:xx:xx:xx by local choice (reason=3)
May 31 18:04:40 machine kernel: [41017.156648] wlan0: authenticate with 00:13:10:xx:xx:xx (try 1)
May 31 18:04:40 machine kernel: [41017.158126] wlan0: authenticated
May 31 18:04:40 machine kernel: [41017.158182] wlan0: associate with 00:13:10:xx:xx:xx (try 1)
May 31 18:04:40 machine kernel: [41017.160695] wlan0: RX AssocResp from 00:13:10:xx:xx:xx (capab=0x431 status=0 aid=1)
May 31 18:04:40 machine kernel: [41017.160702] wlan0: associated
May 31 18:04:50 machine kernel: [41027.167860] wlan0: deauthenticating from 00:13:10:xx:xx:xx by local choice (reason=3)
May 31 18:04:51 machine kernel: [41028.389293] wlan0: authenticate with 00:13:10:xx:xx:xx (try 1)
May 31 18:04:51 machine kernel: [41028.390769] wlan0: authenticated
May 31 18:04:51 machine kernel: [41028.390818] wlan0: associate with 00:13:10:xx:xx:xx (try 1)
May 31 18:04:51 machine kernel: [41028.393359] wlan0: RX AssocResp from 00:13:10:xx:xx:xx (capab=0x431 status=0 aid=1)
May 31 18:04:51 machine kernel: [41028.393368] wlan0: associated
May 31 18:05:01 machine kernel: [41038.395400] wlan0: deauthenticating from 00:13:10:xx:xx:xx by local choice (reason=3)
[/code73zzvc8h]

That behaviour was constant using kernel 2.6.32 (making impossible to establish a WPA connection) and random with 2.6.38.

The only workaround which has worked for me is the "nohwcrypt" trick ( http//www.google.es/search?q=options+n ... monkey.com ).

I know this fix is documented in this site, but I couldn't find it related to the "rt61pci-WPA-deauthenticating-local choice-reason=3" stuff. I hope this can help other suffering people (I even considered buying another wireless card with no-Ralink chipset).

dvlierop

12-06-2011 10:17:37

Hi guys,

rt2x00.serialmonkey.com is still alive after all these years, great! I've been a bit worried that the project might have died, because of troubles in connecting lately (no, it wasn't due to my wireless drivers ;-)). But it's good to know that you're still working on the drivers.

Anyway, I've recently upgraded my PC to Fedora 15 and have encountered disconnections too. I'm running kernel

[code3qrr3b8y]2.6.38.6-27.fc15.x86_64 #1 SMP[/code3qrr3b8y]

I've noticed similar "deauthenticating by local choice (reason=3)" lines in dmesg output

[code3qrr3b8y][ 7.202768] NetworkManager[940]: <info> (wlan0): new 802.11 WiFi device (driver: 'rt61pci' ifindex: 2)
[ 7.202775] NetworkManager[940]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0
[ 7.202782] NetworkManager[940]: <info> (wlan0): now managed
[ 7.202790] NetworkManager[940]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
[ 7.202797] NetworkManager[940]: <info> (wlan0): bringing up device.
[ 7.231400] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 9.856038] wlan0: authenticate with 00:21:29:b5:f1:31 (try 1)
[ 9.857538] wlan0: authenticated
[ 9.863036] wlan0: associate with 00:21:29:b5:f1:31 (try 1)
[ 9.867573] wlan0: RX AssocResp from 00:21:29:b5:f1:31 (capab=0x411 status=0 aid=1)
[ 9.867578] wlan0: associated
[ 9.869571] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 9.891545] bridge-wlan0: device is wireless, enabling SMAC
[ 9.891553] bridge-wlan0: up
[ 9.891559] bridge-wlan0: attached
[ 20.330024] wlan0: no IPv6 routers present
[11242.341297] wlan0: deauthenticating from 00:21:29:b5:f1:31 by local choice (reason=3)
[11242.409145] bridge-wlan0: disabling the bridge on dev down
[11242.427081] bridge-wlan0: down
[11242.427187] bridge-wlan0: detached
[/code3qrr3b8y]

I will try the tricks mentioned above and report back what works.

Thanks!

Diederik

mced

12-06-2011 16:39:39

Since I added that module start option (nohwcrypt), this is working even better that I could imagine. My wireless router* says the following

[code2shklbkv]Wireless Packet Info
Received (RX)
100%
2554647 OK, no error
Transmitted (TX)
100%
3891762 OK, no error [/code2shklbkv]

First time I've reached zero error.


*WRT54G with DD-WRT firmware.

dvlierop

01-07-2011 19:44:16

Yep, turning off power management was all that it took!

Thanks a lot!