Rtl8812au: Authentication timed out
Compiling, install and all went fine on Debian Stretch, but unfortunately no connection with any hotspot is possible.
I try to use the Archer T9UH V1.
What could be the problem?
Syslog:
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5614] device (wlx503eaa3f9f60): Activation: starting connection 'wifistation 1' (249c9238-dde7-421c-af14-6b0aebbaae4d)
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5616] audit: op="connection-activate" uuid="249c9238-dde7-421c-af14-6b0aebbaae4d" name="wifistation 1" pid=1775 uid=1000 result="success"
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5619] device (wlx503eaa3f9f60): state change: disconnected -> prepare (reason 'none') [30 40 0]
Apr 6 18:54:55 debianStretch dbus[693]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5621] manager: NetworkManager state is now CONNECTING
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5632] device (wlx503eaa3f9f60): state change: prepare -> config (reason 'none') [40 50 0]
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5636] device (wlx503eaa3f9f60): Activation: (wifi) access point 'wifistation 1' has security, but secrets are required.
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5636] device (wlx503eaa3f9f60): state change: config -> need-auth (reason 'none') [50 60 0]
Apr 6 18:54:55 debianStretch systemd[1]: Starting Network Manager Script Dispatcher Service...
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5707] device (wlx503eaa3f9f60): state change: need-auth -> prepare (reason 'none') [60 40 0]
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5714] device (wlx503eaa3f9f60): state change: prepare -> config (reason 'none') [40 50 0]
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5718] device (wlx503eaa3f9f60): Activation: (wifi) connection 'wifistation 1' has security, and secrets exist. No new secrets needed.
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5718] Config: added 'ssid' value 'wifistation'
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5718] Config: added 'scan_ssid' value '1'
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5719] Config: added 'key_mgmt' value 'WPA-PSK'
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5719] Config: added 'auth_alg' value 'OPEN'
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5719] Config: added 'psk' value '<hidden>'
Apr 6 18:54:55 debianStretch dbus[693]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 6 18:54:55 debianStretch systemd[1]: Started Network Manager Script Dispatcher Service.
Apr 6 18:54:55 debianStretch nm-dispatcher: req:1 'connectivity-change': new request (1 scripts)
Apr 6 18:54:55 debianStretch nm-dispatcher: req:1 'connectivity-change': start running ordered scripts...
Apr 6 18:54:55 debianStretch NetworkManager[711]: <info> [1523033695.5922] device (wlx503eaa3f9f60): supplicant interface state: inactive -> scanning
Apr 6 18:54:59 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: Trying to associate with 11:22:33:44:55:66 (SSID='wifistation' freq=2422 MHz)
Apr 6 18:54:59 debianStretch NetworkManager[711]: <info> [1523033699.2444] device (wlx503eaa3f9f60): supplicant interface state: scanning -> associating
Apr 6 18:54:59 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: Associated with 11:22:33:44:55:66
Apr 6 18:54:59 debianStretch NetworkManager[711]: <info> [1523033699.4557] device (wlx503eaa3f9f60): supplicant interface state: associating -> associated
Apr 6 18:54:59 debianStretch NetworkManager[711]: <info> [1523033699.4631] device (wlx503eaa3f9f60): supplicant interface state: associated -> 4-way handshake
Apr 6 18:55:09 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: Authentication with 11:22:33:44:55:66 timed out.
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=3 locally_generated=1
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="wifistation" auth_failures=1 duration=10 reason=WRONG_KEY
Apr 6 18:55:14 debianStretch NetworkManager[711]: <warn> [1523033714.4886] sup-iface[0x557a71fe7530,wlx503eaa3f9f60]: connection disconnected (reason -3)
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="wifistation" auth_failures=2 duration=20 reason=CONN_FAILED
Apr 6 18:55:14 debianStretch NetworkManager[711]: <info> [1523033714.4935] device (wlx503eaa3f9f60): supplicant interface state: 4-way handshake -> disconnected
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Apr 6 18:55:14 debianStretch NetworkManager[711]: <info> [1523033714.4945] device (wlx503eaa3f9f60): Activation: (wifi) disconnected during association, asking for new key
Apr 6 18:55:14 debianStretch NetworkManager[711]: <info> [1523033714.4946] device (wlx503eaa3f9f60): state change: config -> need-auth (reason 'supplicant-disconnect') [50 60 8]
/etc/NetworkManager/NetworkManager.conf:
[main]
plugins=ifupdown,keyfile
[ifupdown]
managed=false
[device]
wifi.scan-rand-mac-address=no
enterhaken
All 33 comments
The logs says..
Apr 6 18:55:14 debianStretch wpa_supplicant[1003]: wlx503eaa3f9f60: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
what it says is basicly "incorrect password"
kimocoder
on 6 Apr 2018
Yes, it shows the password field after that, but of course the passwords are correct. I copy paste them and also use them on the internal wifi.
enterhaken
on 6 Apr 2018
Maybe another pointer is ifconfig, I don't know.
It seems to be not able to send and most of received is dropped:
wlx503eaa3f9f60: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500
ether 50:3e:aa:3f:9f:60 txqueuelen 1000 (Ethernet)
RX packets 43 bytes 6665 (6.5 KiB)
RX errors 0 dropped 265 overruns 0 frame 0
TX packets 0 bytes 0 (0.0 B)
TX errors 0 dropped 43 overruns 0 carrier 0 collisions 0
which chipset is this? 8812au or 8814au?
kimocoder
on 6 Apr 2018
8814au
enterhaken
on 6 Apr 2018
After DKMS uninstall I also tried
make RTL8814=1
make install RTL8814=1
... but no change.
Some more data which maybe tells something:
/home/user iwconfig wlx503eaa3f9f60
wlx503eaa3f9f60 IEEE 802.11 ESSID:off/any
Mode:Managed Access Point: Not-Associated Tx-Power=40 dBm
Retry short limit:7 RTS thr:off Fragment thr:off
Encryption key:off
Power Management:off
/home/user cat /proc/net/wireless
Inter-| sta-| Quality | Discarded packets | Missed | WE
face | tus | link level noise | nwid crypt frag retry misc | beacon | 22
wlp3s0: 0000 58. -52. -256 0 0 0 0 213 0
What could I try next?
enterhaken
on 7 Apr 2018
Don't know whats wrong over there, 8814au works just fine here. DKMS is installation method and does not have anything to do with the driver function to do.
kimocoder
on 7 Apr 2018
Thank you for your time!
Of course you don't know what is wrong over here, but do you maybe have any idea what I could try next or how I could investigate the problem further to get to the root cause of it?
How would you proceed next if you encountered such a problem?
enterhaken
on 7 Apr 2018
well I may try to re-produce the issue as I'm using 8814au too. Give me "uname -a" output and I'll check myself
kimocoder
on 7 Apr 2018
#uname -a
Linux debianStretch 4.9.0-6-amd64 #1 SMP Debian 4.9.82-1+deb9u3 (2018-03-02) x86_64 GNU/Linux
Thanks. will make a VM machine and check. will take a few days as I'm kinda busy atm
kimocoder
on 7 Apr 2018
Thank you very much!
enterhaken
on 7 Apr 2018
Just to rule out a hardware failure, I could try out the Archer T9UH adapter now on Windows 10 and there it works flawlessly with the drivers from the adapters accompanying CD, so it must be a software problem.
enterhaken
on 8 Apr 2018
well.. trying to re-produce the problem on a VMware box, and I actually hit another problem with "power cycle". don't know if it's a kernel or VMware issue, but I'll switch to my pure Kali install and check it again.
dmesg output:
root@debian:/home/kimocoder# dmesg |tail
[ 456.774140] usb 1-1: device descriptor read/64, error 18
[ 457.109052] usb 1-1: new high-speed USB device number 14 using ehci-pci
[ 457.342777] usb 1-1: device descriptor read/64, error 18
[ 457.685473] usb 1-1: device descriptor read/64, error 18
[ 457.790666] usb usb1-port1: attempt power cycle
[ 458.328316] usb 1-1: new high-speed USB device number 15 using ehci-pci
[ 458.363625] usb 1-1: Invalid ep0 maxpacket: 9
[ 458.597063] usb 1-1: new high-speed USB device number 16 using ehci-pci
[ 458.624604] usb 1-1: Invalid ep0 maxpacket: 9
[ 458.632165] usb usb1-port1: unable to enumerate USB device
kimocoder
on 8 Apr 2018
I do not see that here when plugging in:
Apr 8 18:29:05 debianStretch kernel: [ 136.958044] usb 1-3: new high-speed USB device number 8 using xhci_hcd
Apr 8 18:29:05 debianStretch kernel: [ 137.098584] usb 1-3: New USB device found, idVendor=2357, idProduct=0106
Apr 8 18:29:05 debianStretch kernel: [ 137.098589] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 8 18:29:05 debianStretch kernel: [ 137.098592] usb 1-3: Product: 802.11ac NIC
Apr 8 18:29:05 debianStretch kernel: [ 137.098595] usb 1-3: Manufacturer: Realtek
Apr 8 18:29:05 debianStretch kernel: [ 137.098598] usb 1-3: SerialNumber: 123456
Apr 8 18:29:05 debianStretch mtp-probe: checking bus 1, device 8: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3"
Apr 8 18:29:05 debianStretch mtp-probe: bus: 1, device: 8 was not an MTP device
Apr 8 18:29:06 debianStretch kernel: [ 138.002385] usb 1-3: USB disconnect, device number 8
Apr 8 18:29:06 debianStretch kernel: [ 138.002637] usbcore: registered new interface driver 8814au
Apr 8 18:29:06 debianStretch kernel: [ 138.126339] usb 2-3: new SuperSpeed USB device number 3 using xhci_hcd
Apr 8 18:29:06 debianStretch kernel: [ 138.146383] usb 2-3: Int endpoint with wBytesPerInterval of 512 in config 1 interface 0 altsetting 0 ep 133: setting to 64
Apr 8 18:29:06 debianStretch kernel: [ 138.146528] usb 2-3: New USB device found, idVendor=2357, idProduct=0106
Apr 8 18:29:06 debianStretch kernel: [ 138.146532] usb 2-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 8 18:29:06 debianStretch kernel: [ 138.146535] usb 2-3: Product: 802.11ac NIC
Apr 8 18:29:06 debianStretch kernel: [ 138.146538] usb 2-3: Manufacturer: Realtek
Apr 8 18:29:06 debianStretch kernel: [ 138.146540] usb 2-3: SerialNumber: 123456
Apr 8 18:29:06 debianStretch wpa_supplicant[873]: p2p-dev-wlp3s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.3564] (wlan0): using nl80211 for WiFi device control
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.3566] device (wlan0): driver supports Access Point (AP) mode
Apr 8 18:29:06 debianStretch wpa_supplicant[873]: p2p-dev-wlp3s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
Apr 8 18:29:06 debianStretch systemd[1]: Starting Load/Save RF Kill Switch Status...
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.3583] manager: (wlan0): new 802.11 WiFi device (/org/freedesktop/NetworkManager/Devices/4)
Apr 8 18:29:06 debianStretch mtp-probe: checking bus 2, device 3: "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-3"
Apr 8 18:29:06 debianStretch mtp-probe: bus: 2, device: 3 was not an MTP device
Apr 8 18:29:06 debianStretch systemd[1]: Started Load/Save RF Kill Switch Status.
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.3818] rfkill2: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3:1.0/ieee80211/phy1/rfkill2) (driver 8814au)
Apr 8 18:29:06 debianStretch kernel: [ 138.291153] 8814au 2-3:1.0 wlx503eaa3f9f60: renamed from wlan0
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.4024] device (wlan0): interface index 4 renamed iface from 'wlan0' to 'wlx503eaa3f9f60'
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.4167] devices added (path: /sys/devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3:1.0/net/wlx503eaa3f9f60, iface: wlx503eaa3f9f60)
Apr 8 18:29:06 debianStretch kernel: [ 138.325580] IPv6: ADDRCONF(NETDEV_UP): wlx503eaa3f9f60: link is not ready
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.4168] device added (path: /sys/devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3:1.0/net/wlx503eaa3f9f60, iface: wlx503eaa3f9f60): no ifupdown configuration found.
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.4169] device (wlx503eaa3f9f60): state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.8238] (wlx503eaa3f9f60): using nl80211 for WiFi device control
Apr 8 18:29:06 debianStretch kernel: [ 138.731703] IPv6: ADDRCONF(NETDEV_UP): wlx503eaa3f9f60: link is not ready
Apr 8 18:29:06 debianStretch kernel: [ 138.731747] IPv6: ADDRCONF(NETDEV_CHANGE): wlx503eaa3f9f60: link becomes ready
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.8640] sup-iface[0x561454a67da0,wlx503eaa3f9f60]: supports 5 scan SSIDs
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.8647] device (wlx503eaa3f9f60): supplicant interface state: starting -> ready
Apr 8 18:29:06 debianStretch NetworkManager[683]: <info> [1523204946.8648] device (wlx503eaa3f9f60): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Apr 8 18:29:06 debianStretch kernel: [ 138.773286] IPv6: ADDRCONF(NETDEV_UP): wlx503eaa3f9f60: link is not ready
Apr 8 18:29:08 debianStretch ModemManager[656]: <info> Couldn't check support for device at '/sys/devices/pci0000:00/0000:00:14.0/usb2/2-3': not supported by any plugin
Apr 8 18:29:10 debianStretch NetworkManager[683]: <info> [1523204950.5193] device (wlx503eaa3f9f60): supplicant interface state: ready -> inactive
aaaah, what does "rfkill list" says?
kimocoder
on 8 Apr 2018
# rfkill list
0: hci0: Bluetooth
Soft blocked: no
Hard blocked: no
1: phy0: Wireless LAN
Soft blocked: no
Hard blocked: no
2: phy1: Wireless LAN
Soft blocked: no
Hard blocked: no
Ok it isn't that either. can't really reproduce the issue either, I get those power cyclings. but I'll go further when I got time.
kimocoder
on 8 Apr 2018
I am very interested in trying this driver with the AWUS036ACH, and joining the discussions in Tx power potential.
I have successfully compiled other rt8812au drivers, however, when I compile and install this one - wpa_supplicant reports authentication problems as described here.
Output of sudo uname -a
Linux CYM_logging_pi 4.9.35+ #1014 Fri Jun 30 14:34:49 BST 2017 armv6l GNU/Linu
and of cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)"
NAME="Raspbian GNU/Linux"
VERSION_ID="8"
VERSION="8 (jessie)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
I have found how to report more information from wpa_supplicant and show what I believe is the relevant section but it means very little to me:
wlan8: RX EAPOL from 00:1d:aa:a1:ea:d0
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 9e 37 33 98 21 c0 ac 99 1d a6 c5 d7 2e 14 35 fe aa d3 1f f9 83 ef 56 ed bb d5 d1 e6 ab 78 3a 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: Setting authentication timeout: 10 sec 0 usec
wlan8: IEEE 802.1X RX: version=1 type=3 length=95
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 9e 37 33 98 21 c0 ac 99 1d a6 c5 d7 2e 14 35 fe aa d3 1f f9 83 ef 56 ed bb d5 d1 e6 ab 78 3a 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: EAPOL-Key type=2
wlan8: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan8: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
key_nonce - hexdump(len=32): 84 9e 37 33 98 21 c0 ac 99 1d a6 c5 d7 2e 14 35 fe aa d3 1f f9 83 ef 56 ed bb d5 d1 e6 ab 78 3a
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlan8: WPA: RX message 1 of 4-Way Handshake from 00:1d:aa:a1:ea:d0 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
Get randomness: len=32 entropy=21
WPA: Renewed SNonce - hexdump(len=32): 89 a6 d7 76 72 4d 39 19 cc 3f 22 4d b0 4e f0 a2 e8 00 60 28 2e b6 22 4f b1 06 bb 2e 84 75 61 08
WPA: PTK derivation - A1=00:14:22:01:21:54 A2=00:1d:aa:a1:ea:d0
WPA: Nonce1 - hexdump(len=32): 89 a6 d7 76 72 4d 39 19 cc 3f 22 4d b0 4e f0 a2 e8 00 60 28 2e b6 22 4f b1 06 bb 2e 84 75 61 08
WPA: Nonce2 - hexdump(len=32): 84 9e 37 33 98 21 c0 ac 99 1d a6 c5 d7 2e 14 35 fe aa d3 1f f9 83 ef 56 ed bb d5 d1 e6 ab 78 3a
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01
wlan8: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 07 15 82 f8 89 ae a3 7f ed 74 e2 98 8f 74 11 11
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 89 a6 d7 76 72 4d 39 19 cc 3f 22 4d b0 4e f0 a2 e8 00 60 28 2e b6 22 4f b1 06 bb 2e 84 75 61 08 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 07 15 82 f8 89 ae a3 7f ed 74 e2 98 8f 74 11 11 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan8: RX EAPOL from 00:1d:aa:a1:ea:d0
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 02 61 44 a1 58 52 65 8a fe 11 99 b9 47 5d df 1a 87 61 a2 9d 64 3b 23 71 71 1d 32 a0 12 7b 9e 5c 52 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: IEEE 802.1X RX: version=1 type=3 length=95
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 02 61 44 a1 58 52 65 8a fe 11 99 b9 47 5d df 1a 87 61 a2 9d 64 3b 23 71 71 1d 32 a0 12 7b 9e 5c 52 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: EAPOL-Key type=2
wlan8: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan8: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
key_nonce - hexdump(len=32): 61 44 a1 58 52 65 8a fe 11 99 b9 47 5d df 1a 87 61 a2 9d 64 3b 23 71 71 1d 32 a0 12 7b 9e 5c 52
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan8: WPA: RX message 1 of 4-Way Handshake from 00:1d:aa:a1:ea:d0 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=00:14:22:01:21:54 A2=00:1d:aa:a1:ea:d0
WPA: Nonce1 - hexdump(len=32): 89 a6 d7 76 72 4d 39 19 cc 3f 22 4d b0 4e f0 a2 e8 00 60 28 2e b6 22 4f b1 06 bb 2e 84 75 61 08
WPA: Nonce2 - hexdump(len=32): 61 44 a1 58 52 65 8a fe 11 99 b9 47 5d df 1a 87 61 a2 9d 64 3b 23 71 71 1d 32 a0 12 7b 9e 5c 52
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 02
wlan8: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 5a 08 a6 5f e6 43 0f f6 e5 d6 e3 f3 b8 ca d5 f0
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 02 89 a6 d7 76 72 4d 39 19 cc 3f 22 4d b0 4e f0 a2 e8 00 60 28 2e b6 22 4f b1 06 bb 2e 84 75 61 08 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 5a 08 a6 5f e6 43 0f f6 e5 d6 e3 f3 b8 ca d5 f0 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
EAPOL: startWhen --> 0
EAPOL: disable timer tick
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: enable timer tick
EAPOL: txStart
WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
wlan8: RX EAPOL from 00:1d:aa:a1:ea:d0
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 03 de 78 b6 c3 e0 46 d1 43 10 04 ae 21 09 ce 7d 59 8d ef 82 c1 6d d0 99 bd d0 92 1c f8 55 ea 91 6e 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: IEEE 802.1X RX: version=1 type=3 length=95
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 03 de 78 b6 c3 e0 46 d1 43 10 04 ae 21 09 ce 7d 59 8d ef 82 c1 6d d0 99 bd d0 92 1c f8 55 ea 91 6e 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: EAPOL-Key type=2
wlan8: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan8: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
key_nonce - hexdump(len=32): de 78 b6 c3 e0 46 d1 43 10 04 ae 21 09 ce 7d 59 8d ef 82 c1 6d d0 99 bd d0 92 1c f8 55 ea 91 6e
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan8: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan8: WPA: RX message 1 of 4-Way Handshake from 00:1d:aa:a1:ea:d0 (ver=2)
To be clear its not a WRONG_KEY as the same wpa_supplicant file works fine with other drivers (eg https://github.com/diederikdehaas/rtl8812AU) Any pointers would be much appreciated.
cariad61
on 17 Apr 2018
Bit late to this party but hopefully might help.
I was having the exact same problem with the same handshake errors, could not sort it on KDE neon 16.04. Moved to Kubuntu 18.04 and installed same driver etc and it works, not well which is why I'm here looking for help (extremely low transfer speed) but it works.
SiIason
on 6 Jul 2018
@F3Speech what branch are you using?
kimocoder
on 6 Jul 2018
@kimocoder 5.1.5
Also appears the speed issue is nothing to do with the driver, changing from plasma_nm to wicd fixed the speed issue, created others but still progress :)
EDIT: Just FYI changing networkmanagers didn't fix the speed at some point wlan0 swapped with wlan1 making me think the speed was fixed :(
SiIason
on 7 Jul 2018
And of course I forgot to ask which chipset you got? Which adapter/chipset?
kimocoder
on 7 Jul 2018
AWUS036ACH/8812AU
I just tried the other branches 2.9 (wouldn't make, Im a newb could be me) and 2.20 (auth errors again, this time it wouldn't re-ask for my key it just wouldn't connect, didn't investigate further)
Back to 1.5 and after a reboot all is working again.
SiIason
on 7 Jul 2018
well, after loading a new version, you should "modprobe -r 8812au" then "modprobe 8812au" to load it again, or reboot (take longest time but..)
kimocoder
on 7 Jul 2018
Just reading your work on https://github.com/aircrack-ng/rtl8812au/issues/88 and would like your help to resolve this auth problem with 2.20 rather then ignore it and use older version - if you can guide me with what information you require? (wlan0 is my AWUS036ACH connected via USB3, wlan1 is internal wifi) I'm on 4.15.0-23-generic kernel with Kubuntu system; installed with dkms script.
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1637] device (wlan0): Activation: starting connection 'TALKTALKB56A24' (57a293ec-4103-4d67-a505-d512b322a2af)
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1639] audit: op="connection-activate" uuid="57a293ec-4103-4d67-a505-d512b322a2af" name="TALKTALKB56A24" pid=1141 uid=1000 result="success"
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1645] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1657] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1660] device (wlan0): Activation: (wifi) access point 'TALKTALKB56A24' has security, but secrets are required.
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1661] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1829] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1834] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1839] device (wlan0): Activation: (wifi) connection 'TALKTALKB56A24' has security, and secrets exist. No new secrets needed.
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1843] Config: added 'ssid' value 'TALKTALKB56A24'
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1844] Config: added 'scan_ssid' value '1'
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1846] Config: added 'bgscan' value 'simple:30:-80:86400'
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1848] Config: added 'key_mgmt' value 'WPA-PSK'
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1850] Config: added 'psk' value '<hidden>'
Jul 7 12:04:15 vaio NetworkManager[810]: <info> [1530961455.1991] device (wlan0): supplicant interface state: disconnected -> scanning
Jul 7 12:04:18 vaio wpa_supplicant[831]: wlan0: Trying to associate with 30:85:a9:69:81:e4 (SSID='TALKTALKB56A24' freq=2412 MHz)
Jul 7 12:04:18 vaio wpa_supplicant[831]: wlan0: Association request to the driver failed
Jul 7 12:04:18 vaio wpa_supplicant[831]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="TALKTALKB56A24" auth_failures=1 duration=10 reason=CONN_FAILED
Jul 7 12:04:18 vaio NetworkManager[810]: <info> [1530961458.7985] device (wlan0): supplicant interface state: scanning -> disconnected
Jul 7 12:04:28 vaio NetworkManager[810]: <info> [1530961468.8041] device (wlan0): supplicant interface state: disconnected -> scanning
Jul 7 12:04:32 vaio wpa_supplicant[831]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="TALKTALKB56A24"
Jul 7 12:04:32 vaio wpa_supplicant[831]: wlan0: Trying to associate with 7c:8b:ca:be:6f:4a (SSID='TALKTALKB56A24' freq=2462 MHz)
Jul 7 12:04:32 vaio wpa_supplicant[831]: wlan0: Association request to the driver failed
Jul 7 12:04:32 vaio wpa_supplicant[831]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="TALKTALKB56A24" auth_failures=2 duration=20 reason=CONN_FAILED
Jul 7 12:04:32 vaio NetworkManager[810]: <info> [1530961472.4029] device (wlan0): supplicant interface state: scanning -> disconnected
Jul 7 12:04:40 vaio NetworkManager[810]: <warn> [1530961480.6952] device (wlan0): Activation: (wifi) association took too long, failing activation
Jul 7 12:04:40 vaio NetworkManager[810]: <info> [1530961480.6953] device (wlan0): state change: config -> failed (reason 'ssid-not-found', sys-iface-state: 'managed')
Jul 7 12:04:40 vaio NetworkManager[810]: <warn> [1530961480.6975] device (wlan0): Activation: failed for connection 'TALKTALKB56A24'
Jul 7 12:04:40 vaio NetworkManager[810]: <info> [1530961480.6993] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jul 7 12:04:40 vaio kernel: [ 2467.277772] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul 7 12:04:44 vaio NetworkManager[810]: <info> [1530961484.4055] device (wlan0): supplicant interface state: disconnected -> inactive
SiIason
on 7 Jul 2018
Yeah, the work is currently stalled as I'm awaiting some adapters (8812 and 8811 chipset) to arrive, then I may try reproduce this myself :)
kimocoder
on 7 Jul 2018
@F3Speech Now you should try using the v5.2.20 branch which is the v5.2.20.2 driver.
Tested both 8811 and 8812 chipsets, and they both are in daily use more or less. Report back.
kimocoder
on 24 Jul 2018
Looks good initially. Connected first time, speeds are good.
SiIason
on 24 Jul 2018
I don't have time to look more into this right now, but might be an issue reconnecting after success connection or maybe a period of time. I'm getting the same problem as before when I disconnect and reconnect. I downed the interface and it connected first time when it came back up. Think this is the 2nd time I've noticed it happening. Will post more if I can make it repeatable. (ofc could just me my machine ;p)
SiIason
on 25 Jul 2018
@kimocoder Looks like it happens every time for me, login and auto connect with no problems. But if I disconnect and reconnect I cant get connected again without cycling the interface state down/up. Then it connects fine again for the first try and again if I disconnect I cant get back on...
Log from unsuccessful connection attempt.
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5658] device (wlp0s20u1): Activation: starting connection 'TALKTALKB56A24' (57a293ec-4103-4d67-a505-d512b322a2af)
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5660] audit: op="connection-activate" uuid="57a293ec-4103-4d67-a505-d512b322a2af" name="TALKTALKB56A24" pid=1233 uid=1000 result="success"
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5665] device (wlp0s20u1): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5675] device (wlp0s20u1): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5695] device (wlp0s20u1): Activation: (wifi) access point 'TALKTALKB56A24' has security, but secrets are required.
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5696] device (wlp0s20u1): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5868] device (wlp0s20u1): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5874] device (wlp0s20u1): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5877] device (wlp0s20u1): Activation: (wifi) connection 'TALKTALKB56A24' has security, and secrets exist. No new secrets needed.
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5877] Config: added 'ssid' value 'TALKTALKB56A24'
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5877] Config: added 'scan_ssid' value '1'
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5877] Config: added 'bgscan' value 'simple:30:-80:86400'
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5878] Config: added 'key_mgmt' value 'WPA-PSK'
Jul 25 17:55:24 vaio NetworkManager[854]: <info> [1532537724.5878] Config: added 'psk' value '<hidden>'
Jul 25 17:55:26 vaio NetworkManager[854]: <info> [1532537726.6047] device (wlp0s20u1): supplicant interface state: disconnected -> scanning
Jul 25 17:55:30 vaio wpa_supplicant[873]: wlp0s20u1: Trying to associate with 7c:8b:ca:be:6f:4a (SSID='TALKTALKB56A24' freq=2462 MHz)
Jul 25 17:55:30 vaio wpa_supplicant[873]: wlp0s20u1: Association request to the driver failed
Jul 25 17:55:30 vaio wpa_supplicant[873]: wlp0s20u1: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="TALKTALKB56A24" auth_failures=1 duration=10 reason=CONN_FAILED
Jul 25 17:55:30 vaio NetworkManager[854]: <info> [1532537730.1993] device (wlp0s20u1): supplicant interface state: scanning -> disconnected
Jul 25 17:55:40 vaio NetworkManager[854]: <info> [1532537740.2022] device (wlp0s20u1): supplicant interface state: disconnected -> scanning
Jul 25 17:55:43 vaio wpa_supplicant[873]: wlp0s20u1: CTRL-EVENT-SSID-REENABLED id=0 ssid="TALKTALKB56A24"
Jul 25 17:55:43 vaio wpa_supplicant[873]: wlp0s20u1: Trying to associate with 30:85:a9:69:81:e4 (SSID='TALKTALKB56A24' freq=2412 MHz)
Jul 25 17:55:43 vaio wpa_supplicant[873]: wlp0s20u1: Association request to the driver failed
Jul 25 17:55:43 vaio wpa_supplicant[873]: wlp0s20u1: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="TALKTALKB56A24" auth_failures=2 duration=20 reason=CONN_FAILED
Jul 25 17:55:43 vaio NetworkManager[854]: <info> [1532537743.7902] device (wlp0s20u1): supplicant interface state: scanning -> disconnected
Jul 25 17:55:49 vaio NetworkManager[854]: <warn> [1532537749.6977] device (wlp0s20u1): Activation: (wifi) association took too long, failing activation
Jul 25 17:55:49 vaio NetworkManager[854]: <info> [1532537749.6977] device (wlp0s20u1): state change: config -> failed (reason 'ssid-not-found', sys-iface-state: 'managed')
Jul 25 17:55:49 vaio NetworkManager[854]: <warn> [1532537749.6997] device (wlp0s20u1): Activation: failed for connection 'TALKTALKB56A24'
Jul 25 17:55:49 vaio NetworkManager[854]: <info> [1532537749.7013] device (wlp0s20u1): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jul 25 17:55:49 vaio kernel: [ 398.358461] IPv6: ADDRCONF(NETDEV_UP): wlp0s20u1: link is not ready
Jul 25 17:55:53 vaio NetworkManager[854]: <info> [1532537753.7933] device (wlp0s20u1): supplicant interface state: disconnected -> inactive
SiIason
on 25 Jul 2018
Also having authentication error thru "preshared key may be incorrect", but key is correct. Realtek RTL8812AU, Zyxel NWD6605, Branch 5.3.4
Linux amilo 4.9.0-11-686-pae #1 SMP Debian 4.9.189-3 (2019-09-02) i686 GNU/Linux
Network manager applet 1.44
I have two wifi cards, disabled all auto connections and tried manually, also with disable / enable networks but never got a connection with the rtl8812au, neither 2.4 / 5 Ghz
Sep 13 10:05:29 amilo wpa_supplicant[630]: wlx588bf39ab980: Trying to associate with 88:25:2c:34:d3:04 (SSID='WLAN-34D350' freq=2472 MHz)
Sep 13 10:05:29 amilo NetworkManager[383]: <info> [1568361929.4914] device (wlx588bf39ab980): supplicant interface state: disconnected -> associating
Sep 13 10:05:34 amilo wpa_supplicant[630]: wlx588bf39ab980: Associated with 88:25:2c:34:d3:04
Sep 13 10:05:34 amilo NetworkManager[383]: <info> [1568361934.0512] device (wlx588bf39ab980): supplicant interface state: associating -> 4-way handshake
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: Authentication with 88:25:2c:34:d3:04 timed out.
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: CTRL-EVENT-DISCONNECTED bssid=88:25:2c:34:d3:04 reason=3 locally_generated=1
Sep 13 10:05:44 amilo NetworkManager[383]: <warn> [1568361944.0567] sup-iface[0x1225820,wlx588bf39ab980]: connection disconnected (reason -3)
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="WLAN-34D350" auth_failures=1 duration=10 reason=WRONG_KEY
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="WLAN-34D350" auth_failures=2 duration=20 reason=CONN_FAILED
Sep 13 10:05:44 amilo wpa_supplicant[630]: wlx588bf39ab980: CTRL-EVENT-ASSOC-REJECT status_code=1
Sep 13 10:05:44 amilo NetworkManager[383]: <info> [1568361944.0610] device (wlx588bf39ab980): supplicant interface state: 4-way handshake -> disconnected
Sep 13 10:05:44 amilo NetworkManager[383]: <info> [1568361944.0632] device (wlx588bf39ab980): Activation: (wifi) disconnected during association, asking for new key
Sep 13 10:05:44 amilo NetworkManager[383]: <info> [1568361944.0634] device (wlx588bf39ab980): state change: config -> need-auth (reason 'supplicant-disconnect') [50 60 8]
Doppel-D
on 13 Sep 2019
This issue should be resolved in latest branch. If not, please re-open
kimocoder
on 26 Nov 2019
Related issues
manofftoday
路
8Comments
cristianav
路
7Comments
etem
路
8Comments
iagosrodrigues
路
6Comments
oldstanda
路
5Comments