On Wed, Mar 29, 2017 at 10:54 PM, Janusz Dziedzic <janusz.dziedzic@xxxxxxxxx> wrote: > On 29 March 2017 at 19:03, Tim Harvey <tharvey@xxxxxxxxxxxxx> wrote: >> Greetings, >> >> (resending plaintext - oops) >> >> I'm seeing failures to authenticate with a WPA2 secured AP using ath9k >> based cards on wireless-next: >> >> root@xenial-armhf:~# wpa_passphrase testssid testpass > >> /etc/wpa_supplicant/wpa_supplicant.conf >> >> root@xenial-armhf:~# iw reg get >> country US: DFS-FCC >> (2402 - 2472 @ 40), (N/A, 30), (N/A) >> (5170 - 5250 @ 80), (N/A, 17), (N/A) >> (5250 - 5330 @ 80), (N/A, 23), (0 ms), DFS >> (5490 - 5730 @ 160), (N/A, 23), (0 ms), DFS >> (5735 - 5835 @ 80), (N/A, 30), (N/A) >> (57240 - 63720 @ 2160), (N/A, 40), (N/A) >> >> root@xenial-armhf:~# wpa_supplicant -i wlan0 -c >> /etc/wpa_supplicant/wpa_supplicant.conf >> Successfully initialized wpa_supplicant >> [ 1882.699010] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready >> nl80211: send_and_recv->nl_recvms[ 1886.262884] wlan0: authenticate >> with 02:1a:11:f2:35:9c >> gs failed: -33 >> wlan0: SME: Trying to authenticate with 02:1a:11:f2:35:9c >> (SSID='testssid' freq=2437 MHz) >> [ 1886.280755] wlan0: send auth to 02:1a:11:f2:35:9c (try 1/3) >> [ 1887.033449] wlan0: send auth to 02:1a:11:f2:35:9c (try 2/3) >> [ 1887.993413] wlan0: send auth to 02:1a:11:f2:35:9c (try 3/3) >> [ 1888.953390] wlan0: authentication with 02:1a:11:f2:35:9c timed out >> wlan0: SME: Trying to authenticat[ 1892.507484] wlan0: authenticate >> with 02:1a:11:f2:35:9c >> e with 02:1a:11:f2:35:9c (SSID='testssid' freq=2437 MHz) >> [ 1892.527460] wlan0: send auth to 02:1a:11:f2:35:9c (try 1/3) >> [ 1893.993401] wlan0: send auth to 02:1a:11:f2:35:9c (try 2/3) >> [ 1894.953419] wlan0: send auth to 02:1a:11:f2:35:9c (try 3/3) >> [ 1895.993387] wlan0: authentication with 02:1a:11:f2:35:9c timed out >> wlan0: SME: Trying to authenticat[ 1899.997262] wlan0: authenticate >> with 02:1a:11:f2:35:9c >> e with 02:1a:11:f2:35:9c (SSID='testssid' freq=2437 MHz) >> [ 1900.017252] wlan0: send auth to 02:1a:11:f2:35:9c (try 1/3) >> [ 1901.033259] wlan0: send auth to 02:1a:11:f2:35:9c (try 2/3) >> [ 1901.993345] wlan0: send auth to 02:1a:11:f2:35:9c (try 3/3) >> [ 1902.953270] wlan0: authentication with 02:1a:11:f2:35:9c timed out >> wlan0: SME: Trying to authenticat[ 1907.407446] wlan0: authenticate >> with 02:1a:11:f2:35:9c >> e with 02:1a:11:f2:35:9c (SSID='testssid' freq=2437 MHz) >> [ 1907.427370] wlan0: send auth to 02:1a:11:f2:35:9c (try 1/3) >> [ 1908.003204] wlan0: send auth to 02:1a:11:f2:35:9c (try 2/3) >> [ 1908.953275] wlan0: send auth to 02:1a:11:f2:35:9c (try 3/3) >> [ 1909.993254] wlan0: authentication with 02:1a:11:f2:35:9c timed out >> wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="testssid" >> auth_failures=1 duration=10 reason=CONN_FAILED >> ^Cnl80211: deinit ifname=wlan0 disabled_11b_rates=0 >> wlan0: CTRL-EVENT-TERMINATING >> >> I've tried loading ath9k with nohwcrypt=1 and see the same. >> >> I do not have any trouble with an ath10k card in the same system: >> >> root@xenial-armhf:~# wpa_supplicant -i wlan1 -c >> /etc/wpa_supplicant/wpa_supplicant.conf >> Successfully initialized wpa_supplicant >> [ 593.401846] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready >> wlan1: SME: Trying to authenticat[ 596.857230] wlan1: authenticate >> with 02:1a:11:f1:b9:02 >> e with 02:1a:11:f1:b9:02 (SSID='testssid' freq=2437 MHz) >> [ 596.876749] wlan1: send auth to 02:1a:11:f1:b9:02 (try 1/3) >> [ 596.886290] wlan1: authenticated >> wlan1: Trying to associate with 02:1a:11:f1:b9:02 (SSID='testssid' >> freq=2437 MHz) >> [ 596.909012] wlan1: associate with 02:1a:11:f1:b9:02 (try 1/3) >> [ 596.922374] wlan1: RX AssocResp from 02:1a:11:f1:b9:02 (capab=0x411 >> status=0 aid=1) >> [ 596.940754] wlan1: associated >> [ 596.943954] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready >> wlan1: Associated with 02:1a:11:f1:b9:02 >> wlan1: WPA: Key negotiation completed with 02:1a:11:f1:b9:02 [PTK=CCMP GTK=CCMP] >> wlan1: CTRL-EVENT-CONNECTED - Connection to 02:1a:11:f1:b9:02 >> completed [id=0 id_str=] >> wlan1: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US >> ^^^^ at this point I can dhcp IP config and all is good >> >> Here's the PCI info for the two cards: >> >> 08:00.0 Ethernet controller [0200]: Marvell Technology Group Ltd. >> 88E8057 PCI-E Gigabit Ethernet Controller [11ab:4380] >> 09:00.0 Network controller [0280]: Qualcomm Atheros AR9580 Wireless >> Network Adapter [168c:0033] (rev 01) >> >> I don't know when ath9k last worked honestly. I usually use them under >> OpenWrt which has its own patches against periodic updates of linux >> backports. I noticed this first with Ubuntu 16.04 with the Ubuntu 4.4 >> kernel, saw it still with the Ubuntu 4.8 kernel, then repeated the >> issue in wireless-next. >> >> Any ideas? >> > Interesting. Are you sure wlan0 is ath9k and wlan1 is ath10k? > ath9k is quite stable - I have AR9462 and works fine with 4.4 and current. > So, I would suspect some issues with ath10k :) > > What if you will modprobe -r ath10k_pci and next run the test? > It's ath9k for sure... several different ath9k radios fail the same way: WLE350NX, WLE200NX, WPEA-127NE, SR710E. I'm surprised as heck as well. I only put the ath10k radio in to ensure I don't have some configuration issue (and have since removed it and only test with 1 card at a time). I've also ensured that a variety of radios/drivers work with the same Ubuntu xenial (16.04) userspace and kernels such as ath10k, carl9170, iwlwifi. Is there some userspace configuration issue I may have related to regdomain on ath9k that perhaps isn't applicable on other drivers? Note that depending on the kernel version I don't always get the same failure. Here is Ubuntu 4.8.0-30-generic which is where I originally saw the issue and started troubleshooting. In this case we auth/assoc and then immediately get disconnected from the AP: root@xenial-armhf:~# uname -a Linux xenial-armhf 4.8.0-30-generic #32~16.04.1-Ubuntu SMP Fri Dec 2 03:46:03 UTC 2016 armv7l armv7l armv7l GNU/Linux root@xenial-armhf:~# wpa_supplicant -i wlan0 -c /etc/wpa_supplicant/wpa_supplicant.conf -D nl80211 Successfully initialized wpa_supplicant [ 240.086690] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready wlan0: SME: Trying to authenticat[ 243.332657] wlan0: authenticate with 02:1a:11:f9:e9:04 e with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 243.354923] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 243.895326] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 244.382493] wlan0: authenticated ^^^^ athenticated wlan0: Trying to associate with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 244.423275] wlan0: associate with 02:1a:11:f9:e9:04 (try 1/3) [ 245.879282] wlan0: associate with 02:1a:11:f9:e9:04 (try 2/3) [ 246.462630] wlan0: RX AssocResp from 02:1a:11:f9:e9:04 (capab=0x411 status=0 aid=1) [ 246.470554] wlan0: associated ^^^^ associated [ 246.473628] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready wlan0: Associated with 02:1a:11:f9:e9:04 wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US wlan0: CTRL-EVENT-DISCONNECTED bssid=02:1a:11:f9:e9:04 reason=4 locally_generated=1 ^^^^ disconnected because of no activity? This was within around 1 second of the association wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="testssid" auth_failures=1 duration=10 reason=WRONG_KEY ^^^^ but we already authenticated??? wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD wlan0: CTRL-EVENT-SSID-REENABLED [ 259.744812] wlan0: authenticate with 02:1a:11:f9:e9:04 id=0 ssid="testssid" wlan0: SME: Trying to authenticate with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 259.766920] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 260.798457] wlan0: authenticated wlan0: Trying to associate with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 260.839297] wlan0: associate with 02:1a:11:f9:e9:04 (try 1/3) [ 261.879297] wlan0: associate with 02:1a:11:f9:e9:04 (try 2/3) [ 262.878638] wlan0: RX AssocResp from 02:1a:11:f9:e9:04 (capab=0x411 status=0 aid=1) [ 262.886553] wlan0: associated wlan0: Associated with 02:1a:11:f9:e9:04 wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US wlan0: CTRL-EVENT-DISCONNECTED bssid=02:1a:11:f9:e9:04 reason=4 locally_generated=1 wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="testssid" auth_failures=2 duration=23 reason=WRONG_KEY wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD ^Cnl80211: deinit ifname=wlan0 disabled_11b_rates=0 wlan0: CTRL-EVENT-TERMINATING And linux-wireless/master (we never get auuthenticated with ath9k): root@xenial-armhf:~# uname -a Linux xenial-armhf 4.11.0-rc2 #579 SMP Thu Mar 30 07:44:08 PDT 2017 armv7l armv7l armv7l GNU/Linux root@xenial-armhf:~# wpa_supplicant -i wlan0 -c /etc/wpa_supplicant/wpa_supplicant.conf -D nl80211 Successfully initialized wpa_supplicant [ 27.312919] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready wlan0: SME: Trying to authenticat[ 30.924677] wlan0: authenticate with 02:1a:11:f9:e9:04 e with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 30.954609] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 32.090557] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 33.129011] wlan0: send auth to 02:1a:11:f9:e9:04 (try 3/3) [ 34.088942] wlan0: authentication with 02:1a:11:f9:e9:04 timed out wlan0: SME: Trying to authenticat[ 37.670515] wlan0: authenticate with 02:1a:11:f9:e9:04 e with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 37.693822] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 39.128907] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 40.089009] wlan0: send auth to 02:1a:11:f9:e9:04 (try 3/3) [ 41.128974] wlan0: authentication with 02:1a:11:f9:e9:04 timed out wlan0: SME: Trying to authenticat[ 45.092584] wlan0: authenticate with 02:1a:11:f9:e9:04 e with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 45.115914] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 46.008936] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 46.968911] wlan0: send auth to 02:1a:11:f9:e9:04 (try 3/3) [ 48.008849] wlan0: authentication with 02:1a:11:f9:e9:04 timed out wlan0: SME: Trying to authenticat[ 52.472625] wlan0: authenticate with 02:1a:11:f9:e9:04 e with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 52.495857] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 53.058850] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 54.008860] wlan0: send auth to 02:1a:11:f9:e9:04 (try 3/3) [ 54.968960] wlan0: authentication with 02:1a:11:f9:e9:04 timed out wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="testssid" auth_failures=1 duration=10 reason=CONN_FAILED wlan0: CTRL-EVENT-SSID-REENABLED [ 71.862102] wlan0: authenticate with 02:1a:11:f9:e9:04 id=0 ssid="testssid" wlan0: SME: Trying to authenticate with 02:1a:11:f9:e9:04 (SSID='testssid' freq=2437 MHz) [ 71.885021] wlan0: send auth to 02:1a:11:f9:e9:04 (try 1/3) [ 73.128873] wlan0: send auth to 02:1a:11:f9:e9:04 (try 2/3) [ 74.008857] wlan0: send auth to 02:1a:11:f9:e9:04 (try 3/3) [ 74.969026] wlan0: authentication with 02:1a:11:f9:e9:04 timed out wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="testssid" auth_failures=2 duration=23 reason=CONN_FAILED Regards, Tim
