hostapd: AP-STA-POSSIBLE-PSK-MISMATCH after unprovoked AP-STA-DISCONNECTED

kolAflash commented 4 years ago

I'm running my ALFA AWUS036ACH in AP/MASTER mode via hostapd.

After a few minutes (maybe 5 minutes), my client always gets disconnected. And if the client tries to reconnect the PSK is wrong.

The problem only disappears when restarting hostapd. So I guess it's quite sure a problem of the AP. (nevertheless, I'll test different client scenarios in the next days)

Tested versions: 5.6.4.2 and 5.3.4 OS and hostapd: Debian-10.5.0 (AMD64)

hostapd.conf

``` interface=wlan0 bridge=br0 # SSID to be used in IEEE 802.11 management frames ssid=kolAnetzB # Driver interface type (hostap/wired/none/nl80211/bsd) driver=nl80211 # Country code (ISO/IEC 3166-1) country_code=DE # Operation mode (a = IEEE 802.11a (5 GHz), b = IEEE 802.11b (2.4 GHz) hw_mode=a # Channel number channel=36 # Maximum number of stations allowed #max_num_sta=5 # Bit field: bit0 = WPA, bit1 = WPA2 wpa=2 # Bit field: 1=wpa, 2=wep, 3=both auth_algs=1 # Set of accepted cipher suites; disabling insecure TKIP wpa_pairwise=CCMP # Set of accepted key management algorithms wpa_key_mgmt=WPA-PSK wpa_passphrase=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX # hostapd event logger configuration logger_stdout=-1 logger_stdout_level=2 ```

short log

``` wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE Using interface wlan0 with hwaddr f2:04:90:06:e0:4b and ssid "kolAnetzB" wlan0: interface state COUNTRY_UPDATE->ENABLED wlan0: AP-ENABLED wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-CONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session 76814C7AB6484158 wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: disassociated wlan0: AP-STA-DISCONNECTED d8:12:65:96:6e:2b wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-POSSIBLE-PSK-MISMATCH d8:12:65:96:6e:2b wlan0: AP-STA-POSSIBLE-PSK-MISMATCH d8:12:65:96:6e:2b wlan0: AP-STA-POSSIBLE-PSK-MISMATCH d8:12:65:96:6e:2b wlan0: AP-STA-POSSIBLE-PSK-MISMATCH d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: disassociated ```

88XXau_disconnects.txt

kolAflash commented 4 years ago

Version 4.3.21 seems to work stable. (worked for at least 10 minutes and > 1 GB data) Although there's some stuff in the log, TCP connections from the clients stay stable. (transferred 1 GB data via scp and watched a YouTube video on a second client)

log

wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE Using interface wlan0 with hwaddr f2:69:27:34:fd:8e and ssid "kolAnetzB" wlan0: interface state COUNTRY_UPDATE->ENABLED wlan0: AP-ENABLED wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-CONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session 00EABBE5D07C00FE wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: disassociated wlan0: AP-STA-DISCONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-CONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session 3EEE8B0D8FD4A10B wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-DISCONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: disassociated wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: AP-STA-CONNECTED d8:12:65:96:6e:2b wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session FDE2DF9FF64ABC23 wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session FDE2DF9FF64ABC23 wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: STA d8:12:65:96:6e:2b IEEE 802.11: associated wlan0: STA d8:12:65:96:6e:2b RADIUS: starting accounting session FDE2DF9FF64ABC23 wlan0: STA d8:12:65:96:6e:2b WPA: pairwise key handshake completed (RSN) wlan0: AP-STA-DISCONNECTED d8:12:65:96:6e:2b wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: STA 84:cf:bf:8b:3b:7d IEEE 802.11: associated wlan0: AP-STA-CONNECTED 84:cf:bf:8b:3b:7d wlan0: STA 84:cf:bf:8b:3b:7d RADIUS: starting accounting session 40243D6E339B269D wlan0: STA 84:cf:bf:8b:3b:7d WPA: pairwise key handshake completed (RSN) wlan0: AP-STA-DISCONNECTED 84:cf:bf:8b:3b:7d wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED

So this might be a regression from somewhere >=4.3.21 to somewhere <=5.3.4

jtroeth1 commented 4 years ago

Hi, I have this exact issue, can connect fine, then after about 5 minutes i get booted and cannot reconnect.

kolAflash commented 4 years ago

Sadly 4.3.21 also tends to disconnect periodically - at least with on my notebook (HP EliteBook 735 - RTL8822BE). But instead of 5.3.4 it allows reconnecting without restarting hostapd.

Disconnect log from my notebook:

Sep 23 01:08:47 mycomputer kernel: [107352.349242] rtw_8822be 0000:03:00.0: sta ca:d3:ee:01:23:45 with macid 0 left
Sep 23 01:09:00 mycomputer kernel: [107365.950748] wlan0: authenticate with ca:d3:ee:01:23:45
Sep 23 01:09:01 mycomputer kernel: [107366.520895] wlan0: send auth to ca:d3:ee:01:23:45 (try 1/3)
Sep 23 01:09:01 mycomputer kernel: [107366.522777] wlan0: authenticated
Sep 23 01:09:01 mycomputer kernel: [107366.523040] rtw_8822be 0000:03:00.0 wlan0: disabling HT/VHT/HE as WMM/QoS is not supported by the AP
Sep 23 01:09:01 mycomputer kernel: [107366.524891] wlan0: associate with ca:d3:ee:01:23:45 (try 1/3)
Sep 23 01:09:01 mycomputer kernel: [107366.526021] wlan0: RX AssocResp from ca:d3:ee:01:23:45 (capab=0x11 status=0 aid=1)
Sep 23 01:09:01 mycomputer kernel: [107366.526053] rtw_8822be 0000:03:00.0: sta ca:d3:ee:01:23:45 joined with macid 0
Sep 23 01:09:01 mycomputer kernel: [107366.526499] wlan0: associated
Sep 23 01:09:02 mycomputer kernel: [107367.406401] wlan0: deauthenticating from ca:d3:ee:01:23:45 by local choice (Reason: 3=DEAUTH_LEAVING)
Sep 23 01:09:02 mycomputer kernel: [107367.406640] rtw_8822be 0000:03:00.0: sta ca:d3:ee:01:23:45 with macid 0 left
Sep 23 01:09:02 mycomputer kernel: [107367.433607] rtw_8822be 0000:03:00.0: stop vif d8:12:65:ab:cd:ef on port 0
Sep 23 01:09:02 mycomputer kernel: [107367.936728] rtw_8822be 0000:03:00.0: start vif fa:6d:89:67:89:ab on port 0
Sep 23 01:09:07 mycomputer kernel: [107372.737789] rtw_8822be 0000:03:00.0: stop vif fa:6d:89:67:89:ab on port 0
Sep 23 01:09:08 mycomputer kernel: [107373.248656] rtw_8822be 0000:03:00.0: start vif d8:12:65:ab:cd:ef on port 0
Sep 23 01:09:12 mycomputer kernel: [107377.499736] wlan0: authenticate with ca:d3:ee:01:23:45
Sep 23 01:09:12 mycomputer kernel: [107378.065090] wlan0: send auth to ca:d3:ee:01:23:45 (try 1/3)
Sep 23 01:09:12 mycomputer kernel: [107378.066058] wlan0: authenticated
Sep 23 01:09:12 mycomputer kernel: [107378.067406] rtw_8822be 0000:03:00.0 wlan0: disabling HT/VHT/HE as WMM/QoS is not supported by the AP
Sep 23 01:09:12 mycomputer kernel: [107378.068845] wlan0: associate with ca:d3:ee:01:23:45 (try 1/3)
Sep 23 01:09:12 mycomputer kernel: [107378.069987] wlan0: RX AssocResp from ca:d3:ee:01:23:45 (capab=0x11 status=0 aid=1)
Sep 23 01:09:12 mycomputer kernel: [107378.070012] rtw_8822be 0000:03:00.0: sta ca:d3:ee:01:23:45 joined with macid 0
Sep 23 01:09:12 mycomputer kernel: [107378.070363] wlan0: associated
Sep 23 01:09:12 mycomputer kernel: [107378.076719] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready

kolAflash commented 4 years ago

I've found out, that the bug disappears if I switch from Debian-10 (stable) to Debian-11 (testing) or to openSUSE-15.2. (only tested version 5.6.4.2 until now)

I'm still trying to figure out the details and I'm also experiencing a very similar issue with another USB WLAN /Wi-Fi adapter (Ralink RT5572). https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=970877

Workaround: I didn't want to change my operating system or upgrade it to Debian-Testing. So I found a simple and nasty workaround: I'm now running Debian-Testing inside a Qemu VM with 256 MB of memory. And I passtrough the Wi-Fi usb device to the VM. Works great!

lukasnxyz commented 3 years ago

I have the same issue

I am setting up an access point with a raspberry pi 0 w and am using hostapd and dhcpd. I have everything setup but when I reboot the pi and try to connect to it from my Arch Linux computer, I get kicked off of the network after about 5 minutes or if I have the pi in my network connections history, I cannot connect at all and it instead puts me through a password loop hole.

hostapd config file

country_code=US
interface=wlan0
ssid=raspwifi
hw_mode=g
channel=6
macaddr_acl=0
auth_algs=1
ignore_broadcast_ssid=0
wpa=2
wpa_passphrase=password
wpa_key_mgmt=WPA-PSK
wpa_pairwise=TKIP

hostapd log

I tried using sudo /usr/sbin/hostapd /etc/hostapd/hostapd.conf to check the log and to see what happens when I connect and if I have the pi deleted from my connection history, my computer connects successfully but after about 5 minutes the log shows wlan0: INTERFACE-DISABLED and wlan0: INTERFACE-ENABLED which boots me off of the pi.

When I try and connect with the pi in my connection history, the hosapd log shows wlan0: AP-STA-POSSIBLE-PSK-MISMATCH <bssid>.

How do I fix this? What am I doing wrong?

kolAflash commented 3 years ago

I've found out, that the bug disappears if I switch from Debian-10 (stable) to Debian-11 (testing) or to openSUSE-15.2. (only tested version 5.6.4.2 until now)

I'm still trying to figure out the details and I'm also experiencing a very similar issue with another USB WLAN /Wi-Fi adapter (Ralink RT5572). https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=970877

Workaround: I didn't want to change my operating system or upgrade it to Debian-Testing. So I found a simple and nasty workaround: I'm now running Debian-Testing inside a Qemu VM with 256 MB of memory. And I passtrough the Wi-Fi usb device to the VM. Works great!

Looks like this might not be correct.

I recently upgraded the whole system to Debian-11. (stopped using the Debian-11 VM) And it looks like the issue is still there.

This might be some kind of conflict with other kernel modules on the host system. Or the bug only appears on "busy" systems running multiple software, which causes more random situations in memory.

cxpreng commented 2 years ago

As always in Linux things are half done, poorly implemented or not at all, 2 years later the problem is still there, just came here to rant 'cause I'm having the same issue with a freshly installed Raspberry OS (based in Debian 11 and there's not even a decent debugging tool! ♥︎  So it's not about the system being busy, I have 25% mem used and less than 10% CPU load, to me it's just a bug in hostapd.

Ardragoon commented 1 year ago

As always in Linux things are half done, poorly implemented or not at all, 2 years later the problem is still there, just came here to rant 'cause I'm having the same issue with a freshly installed Raspberry OS (based in Debian 11 and there's not even a decent debugging tool! ♥︎  So it's not about the system being busy, I have 25% mem used and less than 10% CPU load, to me it's just a bug in hostapd.

And here we are again almost 3 Years later.

wlan0: interface state UNINITIALIZED->ENABLED wlan0: AP-ENABLED wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: STA de:26:19:22:36:93 IEEE 802.11: associated wlan0: AP-STA-POSSIBLE-PSK-MISMATCH de:26:19:22:36:93 wlan0: STA de:26:19:22:36:93 IEEE 802.11: disassociated

after 5 mins. Enabled-Disabled and boom. i cant connect again. This time on an Raspi Pi4 2GB with latest kali.

Ardragoon commented 1 year ago

After a few Hours i figured something out that works for me. First of all, i just want a WarDrive, Normally you just start your Pi and done. Everything is stored on a USB-Drive. But i dont like that idea. So an AP, without Internet would be nice. But with the Onboard Wifi Chip !!!(WLAN0)!!! Here i use an RPI4 2GB

And Yes... Every 5 mins there is a DISABLED/ENABLED

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ date Sat Jan 28 10:37:17 AM GMT 2023

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ sudo hostapd /etc/hostapd/hostapd.conf

wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE wlan0: interface state COUNTRY_UPDATE->ENABLED wlan0: AP-ENABLED wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: INTERFACE-DISABLED wlan0: INTERFACE-ENABLED wlan0: interface state ENABLED->DISABLED wlan0: AP-DISABLED wlan0: CTRL-EVENT-TERMINATING

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ date Sat Jan 28 10:51:50 AM GMT 2023

That sucks...

I searched for an Timeout/Release in every config. Changed much and nothing helps... Even "sudo hostapd -dd /etc/hostapd/hostapd.conf" dont give useful information. Or a log file...

I installed a clean Kali. using the Release: 2022.4

After "sudo apt update && sudo apt upgrade -y && sudo reboot now"

I also installed

sudo apt install dnsmasq sudo apt install hostapd

My dnsmasq.conf (/etc/dnsmasq.conf) looks like this

interface=wlan0 dhcp-range=192.168.100.2,192.168.100.10,24h dhcp-option=option:dns-server,192.168.100.1

My hostapd.conf (/etc/hostapd/hostapd.conf) looks like this

interface=wlan0

driver=nl80211

country_code=AT ssid=WarDrive hw_mode=g ieee80211n=1 channel=13 macaddr_acl=0 auth_algs=1 wpa=2 wpa_passphrase=12345678 wpa_key_mgmt=WPA-PSK wpa_pairwise=TKIP rsn_pairwise=CCMP

Nothing special.

As there is no Internet on the Raspi i dont need an ip table forwarding.

The dnsmasq get a auto start. sudo systemctl enable dnsmasq

I have to set the ip range for my WLAN0 manually. sudo ifconfig wlan0 up 192.168.100.1 netmask 255.255.255.0

My iwconfig

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ iwconfig lo no wireless extensions.

eth0 no wireless extensions.

wlan0 IEEE 802.11 ESSID:off/any Mode:Managed Access Point: Not-Associated Tx-Power=31 dBm Retry short limit:7 RTS thr:off Fragment thr:off Power Management:on

The wlan0 is in Managed mode. And no Access Point is Associated.

Now we can start the hostapd, but in this state its Disabling/Enabling itself. I decided to stop there and dont use the RPI as an AP...

If you want it as an WarDrive you can use airmon. To start airmon you have to check processes that could cause troubles.

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ sudo airmon-ng check

Found 3 processes that could cause trouble. Kill them using 'airmon-ng check kill' before putting the card in monitor mode, they will interfere by changing channels and sometimes putting the interface back in managed mode

PID Name 306 dhclient 459 NetworkManager 494 wpa_supplicant

To go on, we use command "sudo airmon-ng check kill" That kills dhclient and wpa_supplicant NetworkManager is still running.

!And thats it!

I really accidentally started hostapd. And it stays Enabled ^.- (sudo hostapd /etc/hostapd/hostapd.conf)

Rebooted. Startet hostapd again. And it wont work DISABLED/ENABLED After "sudo airmon-ng check kill" i started hostapd again. And it stays ENABLED ....

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ date Sat Jan 28 11:58:15 AM GMT 2023

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ sudo hostapd /etc/hostapd/hostapd.conf wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE wlan0: interface state COUNTRY_UPDATE->ENABLED wlan0: AP-ENABLED wlan0: STA de:26:19:22:36:93 IEEE 802.11: associated wlan0: AP-STA-CONNECTED de:26:19:22:36:93 wlan0: STA de:26:19:22:36:93 RADIUS: starting accounting session 9B9C755AB07529A0 wlan0: STA de:26:19:22:36:93 WPA: pairwise key handshake completed (RSN) wlan0: EAPOL-4WAY-HS-COMPLETED de:26:19:22:36:93 wlan0: STA de:26:19:22:36:93 IEEE 802.11: disassociated wlan0: AP-STA-DISCONNECTED de:26:19:22:36:93 wlan0: STA de:26:19:22:36:93 IEEE 802.11: associated wlan0: AP-STA-CONNECTED de:26:19:22:36:93 wlan0: STA de:26:19:22:36:93 RADIUS: starting accounting session 71C186FC5DB118F4 wlan0: STA de:26:19:22:36:93 WPA: pairwise key handshake completed (RSN) wlan0: EAPOL-4WAY-HS-COMPLETED de:26:19:22:36:93 wlan0: interface state ENABLED->DISABLED wlan0: AP-STA-DISCONNECTED de:26:19:22:36:93 wlan0: AP-DISABLED wlan0: CTRL-EVENT-TERMINATING nl80211: deinit ifname=wlan0 disabled_11b_rates=0

┌──(kali㉿kali-raspberry-pi)-[~/start] └─$ date Sun Jan 29 01:36:20 PM GMT 2023

Here yo can see 2 connections One Yesterday and one today for testing if its still running.

The AP on this RPI works like a Charm even with a "vncserver :1"

And yup. i love my sudo :P

greets Ardragoon

przemo71J commented 9 months ago

As mentioned above, before restarting hostapd basically run "sudo airmon-ng check kill"

aircrack-ng / rtl8812au