Bug 14808

Summary:	rt2800usb does not work, rt2870sta does
Product:	Drivers	Reporter:	Josip Rodin (joy+kernel)
Component:	network-wireless	Assignee:	Gertjan van Wingerde (gwingerde)
Status:	CLOSED PATCH_ALREADY_AVAILABLE
Severity:	normal	CC:	andreas.sturmlechner, bas, gwingerde, IvDoorn, linville, spsppl
Priority:	P1
Hardware:	x86-64
OS:	Linux
Kernel Version:	2.6.32	Subsystem:
Regression:	No	Bisected commit-id:

Description Josip Rodin 2009-12-14 13:09:03 UTC

Hi,

I tried to use the new non-staging driver for my Edimax EW7711USn 7392:7711 USB device, but it doesn't work on my WPA2-PSK network - wpa_supplicant just keeps trying to connect but fails saying practically nothing (just repeats CTRL-EVENT-SCAN-RESULTS occasionally). tshark indicates that it exchanges some EAPOL packets with my AP, but it goes on and on, and doesn't work out.

Whereas, with rt2870sta I get the following:

Dec 14 14:55:03 pork kernel: rt2870sta: module is from the staging directory, the quality is unknown, you have been warned.
Dec 14 14:55:03 pork kernel: rtusb init --->
Dec 14 14:55:03 pork kernel: 
Dec 14 14:55:03 pork kernel: 
Dec 14 14:55:03 pork kernel: === pAd = ffffc90010601000, size = 587792 ===
Dec 14 14:55:03 pork kernel: 
Dec 14 14:55:03 pork kernel: <-- RTMPAllocAdapterBlock, Status=0
Dec 14 14:55:03 pork kernel: usbcore: registered new interface driver rt2870
Dec 14 14:55:04 pork kernel: <-- RTMPAllocTxRxRingMemory, Status=0
Dec 14 14:55:04 pork kernel: -->RTUSBVenderReset
Dec 14 14:55:04 pork kernel: <--RTUSBVenderReset
Dec 14 14:55:04 pork kernel: --> Error 2 opening /etc/Wireless/RT3070STA/RT3070STA.dat
Dec 14 14:55:04 pork kernel: 1. Phy Mode = 0
Dec 14 14:55:04 pork kernel: 2. Phy Mode = 0
Dec 14 14:55:04 pork kernel: RTMPSetPhyMode: channel is out of range, use first channel=1 
Dec 14 14:55:04 pork kernel: 3. Phy Mode = 0
Dec 14 14:55:04 pork kernel: MCS Set = 00 00 00 00 00
Dec 14 14:55:04 pork kernel: <==== RTMPInitialize, Status=0
Dec 14 14:55:04 pork kernel: 0x1300 = 00043266
Dec 14 14:55:11 pork wpa_supplicant[2734]: CTRL-EVENT-SCAN-RESULTS 
Dec 14 14:55:11 pork wpa_supplicant[2734]: Trying to associate with 00:21:04:4b:2c:a0 (SSID='ShadowGreen' freq=2417 MHz)
Dec 14 14:55:11 pork wpa_supplicant[2734]: Association request to the driver failed
Dec 14 14:55:11 pork kernel: ===>rt_ioctl_giwscan. 7(7) BSS returned, data->length = 1033
Dec 14 14:55:11 pork kernel: ==>rt_ioctl_siwfreq::SIOCSIWFREQ[cmd=0x8b04] (Channel=2)
Dec 14 14:55:11 pork kernel: DRS: unkown mode,default use 11N 1S AP 
Dec 14 14:55:11 pork kernel: DRS: unkown mode (SupRateLen=0, ExtRateLen=0, MCSSet[0]=0x0, MCSSet[1]=0x0)
Dec 14 14:55:11 pork wpa_supplicant[2734]: Associated with 00:21:04:4b:2c:a0
Dec 14 14:55:12 pork wpa_supplicant[2734]: WPA: Key negotiation completed with 00:21:04:4b:2c:a0 [PTK=CCMP GTK=CCMP]
Dec 14 14:55:12 pork wpa_supplicant[2734]: CTRL-EVENT-CONNECTED - Connection to 00:21:04:4b:2c:a0 completed (auth) [id=0 id_str=]
Dec 14 14:55:14 pork kernel: wlan0: no IPv6 routers present
Dec 14 14:55:16 pork dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
Dec 14 14:55:16 pork dhclient: DHCPNAK from 192.168.5.1
Dec 14 14:55:17 pork dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 7
Dec 14 14:55:17 pork dhclient: DHCPOFFER from 192.168.5.1
Dec 14 14:55:17 pork dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
Dec 14 14:55:17 pork dhclient: DHCPACK from 192.168.5.1

BTW I used the staging driver with 2.6.30 and it worked.

If I can provide more information, please don't hesitate to ask.

TIA.

Comment 1 Gertjan van Wingerde 2009-12-14 17:06:15 UTC

Could you provide the dmesg output of the non-working driver?

By the looks of it you are having an rt3070 based device, which indeed isn't working yet in rt2x00.
Proper support for those devices hopefully can reach the upstream kernel in 2.6.34.

Comment 2 Josip Rodin 2009-12-14 17:45:13 UTC

I removed the staging module, made sure nothing in lsmod mentioned rt*, and did a modprobe rt2800usb, and this is what syslog says:

Dec 14 18:39:14 pork kernel: cfg80211: Calling CRDA to update world regulatory domain
Dec 14 18:39:14 pork kernel: phy0: Selected rate control algorithm 'minstrel'
Dec 14 18:39:14 pork kernel: usbcore: registered new interface driver rt2800usb
Dec 14 18:39:14 pork kernel: udev: renamed network interface wlan0 to wlan1
Dec 14 18:39:14 pork kernel: rt2800usb 1-9:1.0: firmware: requesting rt2870.bin
Dec 14 18:39:14 pork kernel: ADDRCONF(NETDEV_UP): wlan1: link is not ready
Dec 14 18:39:16 pork wpa_supplicant[3581]: Failed to initiate AP scan.
Dec 14 18:39:16 pork dhclient: Internet Systems Consortium DHCP Client V3.1.3
Dec 14 18:39:16 pork dhclient: Copyright 2004-2009 Internet Systems Consortium.
Dec 14 18:39:16 pork dhclient: All rights reserved.
Dec 14 18:39:16 pork dhclient: For info, please visit https://www.isc.org/software/dhcp/
Dec 14 18:39:16 pork dhclient: 
Dec 14 18:39:17 pork wpa_supplicant[3581]: CTRL-EVENT-SCAN-RESULTS 
Dec 14 18:39:17 pork wpa_supplicant[3581]: Trying to associate with 00:21:04:4b:2c:a0 (SSID='ShadowGreen' freq=2417 MHz)
Dec 14 18:39:17 pork kernel: wlan1: deauthenticating from 00:21:04:4b:2c:a0 by local choice (reason=3)
Dec 14 18:39:17 pork kernel: wlan1: direct probe to AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:17 pork kernel: wlan1: direct probe responded
Dec 14 18:39:17 pork kernel: wlan1: authenticate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:17 pork kernel: wlan1: authenticated
Dec 14 18:39:17 pork kernel: wlan1: associate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:17 pork kernel: wlan1: RX AssocResp from 00:21:04:4b:2c:a0 (capab=0x431 status=0 aid=4)
Dec 14 18:39:17 pork kernel: wlan1: associated
Dec 14 18:39:17 pork wpa_supplicant[3581]: Associated with 00:21:04:4b:2c:a0
Dec 14 18:39:17 pork kernel: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Dec 14 18:39:17 pork dhclient: Listening on LPF/wlan1/00:1f:1f:55:8c:a3
Dec 14 18:39:17 pork dhclient: Sending on   LPF/wlan1/00:1f:1f:55:8c:a3
Dec 14 18:39:17 pork dhclient: Sending on   Socket/fallback
Dec 14 18:39:19 pork dhclient: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 3
Dec 14 18:39:20 pork kernel: wlan1: deauthenticated from 00:21:04:4b:2c:a0 (Reason: 2)
Dec 14 18:39:20 pork wpa_supplicant[3581]: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Dec 14 18:39:20 pork wpa_supplicant[3581]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Dec 14 18:39:21 pork wpa_supplicant[3581]: CTRL-EVENT-SCAN-RESULTS 
Dec 14 18:39:21 pork wpa_supplicant[3581]: Trying to associate with 00:21:04:4b:2c:a0 (SSID='ShadowGreen' freq=2417 MHz)
Dec 14 18:39:21 pork kernel: wlan1: direct probe to AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:21 pork kernel: wlan1: direct probe responded
Dec 14 18:39:21 pork kernel: wlan1: authenticate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:21 pork kernel: wlan1: authenticated
Dec 14 18:39:21 pork kernel: wlan1: associate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:21 pork kernel: wlan1: RX ReassocResp from 00:21:04:4b:2c:a0 (capab=0x431 status=0 aid=4)
Dec 14 18:39:21 pork kernel: wlan1: associated
Dec 14 18:39:21 pork wpa_supplicant[3581]: Associated with 00:21:04:4b:2c:a0
Dec 14 18:39:22 pork dhclient: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 7
Dec 14 18:39:24 pork kernel: wlan1: deauthenticated from 00:21:04:4b:2c:a0 (Reason: 2)
Dec 14 18:39:24 pork wpa_supplicant[3581]: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Dec 14 18:39:24 pork wpa_supplicant[3581]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Dec 14 18:39:25 pork wpa_supplicant[3581]: CTRL-EVENT-SCAN-RESULTS 
Dec 14 18:39:25 pork wpa_supplicant[3581]: Trying to associate with 00:21:04:4b:2c:a0 (SSID='ShadowGreen' freq=2417 MHz)
Dec 14 18:39:25 pork kernel: wlan1: direct probe to AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:25 pork kernel: wlan1: direct probe responded
Dec 14 18:39:25 pork kernel: wlan1: authenticate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:25 pork kernel: wlan1: authenticated
Dec 14 18:39:25 pork kernel: wlan1: associate with AP 00:21:04:4b:2c:a0 (try 1)
Dec 14 18:39:25 pork kernel: wlan1: RX ReassocResp from 00:21:04:4b:2c:a0 (capab=0x431 status=0 aid=4)
Dec 14 18:39:25 pork kernel: wlan1: associated
Dec 14 18:39:25 pork wpa_supplicant[3581]: Associated with 00:21:04:4b:2c:a0
Dec 14 18:39:28 pork kernel: wlan1: no IPv6 routers present
Dec 14 18:39:29 pork kernel: wlan1: deauthenticated from 00:21:04:4b:2c:a0 (Reason: 2)
Dec 14 18:39:29 pork dhclient: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 8
Dec 14 18:39:29 pork wpa_supplicant[3581]: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Dec 14 18:39:29 pork wpa_supplicant[3581]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Dec 14 18:39:30 pork wpa_supplicant[3581]: CTRL-EVENT-SCAN-RESULTS 
Dec 14 18:39:30 pork wpa_supplicant[3581]: Trying to associate with 00:21:04:4b:2c:a0 (SSID='ShadowGreen' freq=2417 MHz)
...

Repetitio ad nauseam. I'm noticing the explicit errors now - but they're still wrong. The wlan1 wpa_supplicant configuration file is the same one the working (staging) driver uses, I literally reference the exact same file from interfaces(5).

Comment 3 Gertjan van Wingerde 2009-12-14 17:56:02 UTC

OK. The part that I'm after doesn't show up in syslog.

Can you post the output of dmesg (Just type dmesg on the command line).

I'm mostly interested in lines like this:
[    6.088988] phy3 -> rt2x00_set_chip: Info - Chipset detected - rt: 1600, rf: 0006, rev: 30700201.

Comment 4 Josip Rodin 2009-12-14 18:00:35 UTC

There simply isn't any of that, anywhere. Suggestions?

Comment 5 Josip Rodin 2009-12-14 19:10:14 UTC

I plugged it into another machine to eliminate the other one as a factor, and had a "d'oh" moment - it negotiates physical parameters when they - change... :) I should have just plugged it out and back in. Anyway this is what it says on the other machine, also with 2.6.32:

Dec 14 19:53:40 CNZGRIJRL kernel: usb 1-1: new high speed USB device using ehci_hcd and address 4
Dec 14 19:53:40 CNZGRIJRL kernel: usb 1-1: configuration #1 chosen from 1 choice
Dec 14 19:56:48 CNZGRIJRL kernel: phy2: Selected rate control algorithm 'minstrel'
Dec 14 19:56:48 CNZGRIJRL kernel: Registered led device: rt2800usb-phy2::radio
Dec 14 19:56:48 CNZGRIJRL kernel: Registered led device: rt2800usb-phy2::assoc
Dec 14 19:56:48 CNZGRIJRL kernel: Registered led device: rt2800usb-phy2::quality
Dec 14 19:56:48 CNZGRIJRL kernel: usbcore: registered new interface driver rt2800usb
Dec 14 19:58:48 CNZGRIJRL kernel: rt2800usb 1-1:1.0: firmware: requesting rt2870.bin
Dec 14 19:58:48 CNZGRIJRL kernel: ADDRCONF(NETDEV_UP): wlan1: link is not ready

It gets stuck there, as this machine's wpa_supplicant doesn't do anything with it - the link remains down even though I'm actually much closer to the AP on this machine... the green indicator light on the card just keeps blinking several times a second. I'll try it on the original machine in a bit.

Comment 6 Gertjan van Wingerde 2009-12-14 19:19:33 UTC

OK.

BTW, you will need to enable CONFIG_RT2X00_DEBUG to get the message I am after.

Comment 7 Josip Rodin 2009-12-14 19:25:49 UTC

Oh, okay. Here we go:

usb 2-2: new high speed USB device using ehci_hcd and address 5
usb 2-2: configuration #1 chosen from 1 choice
phy4 -> rt2x00_set_chip: Info - Chipset detected - rt: 1600, rf: 0005, rev: 30700201.
phy4: Selected rate control algorithm 'minstrel'
Registered led device: rt2800usb-phy4::radio
Registered led device: rt2800usb-phy4::assoc
Registered led device: rt2800usb-phy4::quality
usbcore: registered new interface driver rt2800usb
phy4 -> rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'.
rt2800usb 2-2:1.0: firmware: requesting rt2870.bin
phy4 -> rt2x00lib_request_firmware: Info - Firmware detected - version: 0.10.
phy4 -> rt2x00mac_conf_tx: Info - Configured TX queue 0 - CWmin: 3, CWmax: 4, Aifs: 2, TXop: 102.
phy4 -> rt2x00mac_conf_tx: Info - Configured TX queue 1 - CWmin: 4, CWmax: 5, Aifs: 2, TXop: 188.
phy4 -> rt2x00mac_conf_tx: Info - Configured TX queue 2 - CWmin: 5, CWmax: 10, Aifs: 3, TXop: 0.
phy4 -> rt2x00mac_conf_tx: Info - Configured TX queue 3 - CWmin: 5, CWmax: 10, Aifs: 7, TXop: 0.
ADDRCONF(NETDEV_UP): wlan1: link is not ready

Comment 8 Gertjan van Wingerde 2009-12-14 19:30:46 UTC

(In reply to comment #7)
> phy4 -> rt2x00_set_chip: Info - Chipset detected - rt: 1600, rf: 0005, rev:
> 30700201.

OK. That explains it. It indeed is a RT3070 device which unfortunately isn't supported yet.

Stay tuned, I may have some patches available in the next few weeks for this.

Comment 9 Josip Rodin 2009-12-14 19:52:56 UTC

Thanks. Isn't this a bit confusing to have a device supported by the upstream 28* driver while it's not actually 28* :)

Comment 10 Bas Zoetekouw 2009-12-24 16:21:13 UTC

fwiw, I have the same problems with my sitecom usb device (0df6:003f).  The chipset is slightly different though:

phy0 -> rt2x00_print_chip: Info - Chipset detected - rt: 1800, rf: 0006, rev: 30700201.

I tried with today's git, but although to seems to be detected and initialized fine, it simply doesn't return any scanning results.
This is rather confusing, actually.  Would it be possible to show a warning when a device is detected that is not yet supported?

Comment 11 John W. Linville 2010-03-15 00:46:40 UTC

*** Bug 15300 has been marked as a duplicate of this bug. ***

Comment 12 John W. Linville 2010-03-15 00:46:50 UTC

*** Bug 15535 has been marked as a duplicate of this bug. ***

Comment 13 Gertjan van Wingerde 2010-12-15 20:58:42 UTC

2.6.36 should support these devices properly now.

Can any of you test that kernel version to see that your devices work okay?

Comment 14 spsppl 2010-12-15 21:36:33 UTC

I'm on 2.6.35-23-generic and its been working for awhile now.

I have a few different Alfa cards and iwconfig is reporting the correct driver in all cases.

Comment 15 Gertjan van Wingerde 2010-12-15 21:49:22 UTC

OK. Then I'll close this bug entry.