Am 04.01.20 um 23:15 schrieb "Jürgen Bausa":
I am running a laptop (Xiaomi Air 12) with debian Buster AMD64 and use KDE with network-Manager.
Wifi is supplied by a Fritzbox 7530 wifi-router (2.4 and 5 GHz with same ssid and wpa2).
Since I use the Fritzbox (before that I used a TP-Link router, that did not have this problem)
I experience the following problem:
When a new connection is initiated by the laptop (after reboot or resume) in some cases (about 5-10 %)
the connection is made for a very short time only. The laptop is then disconnected and a window appears
on the desktop, saying that the password had been wrong (which is definitely not the case: the correct password
is stored in NMs database) and asking for the correct one. When I type in the correct password,
the connection is made. Or, if I just close the window and click on the connection in NM, the
connection is also made.
>
Sounds like you are connecting to the AP, 4-way handshake is completed
successful. Then for some reason the AP or the station re-key the
connection and something goes wrong in the new handshake.
The invalid password prompt for that case has just been fixed in the git
master with commit 84877f253 ("wpa_supplicant: Do not try to detect PSK
mismatch during PTK rekeying") and should simple reconnect to the AP
without a password prompt.
But that is not answering why the PTK is being rekeyed in the first
case. Can you provide a debug log with timestamps from the full
connection? Starting at the initial connect.
You should be able to enable full debug logging via:
sudo dbus-send --system --print-reply --dest=fi.w1.wpa_supplicant1
/fi/w1/wpa_supplicant1 org.freedesktop.DBus.Properties.Set
string:fi.w1.wpa_supplicant1 string:DebugLevel variant:string:"msgdump"
On my system I can see the debug messages in real time with
journalctl -u wpa_supplicant -f
This should produce quite many lines when you connect but still protect
the really confidential key parts.
This is what I find in the routers log (lina is my laptop):
(translation from german).
20.12.19 22:57:51 WIFI-device has been disconnected (5 GHz), lina, IP 192.168.0.31, MAC XX:XX:XX:XX:XX:XX.
20.12.19 22:57:48 WIFI-device has been connected, WIFI reactivated with full power (5 GHz).
These two things are always the same, when the problem happens:
- the router resumes from power saving mode when the first attempt to connect is made (WIFI reactivated with full power)
- 5 Ghz is used
This is what I find in the laptops log:
wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=DE
wlp1s0: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='meineSSID' freq=5220 MHz)
wlp1s0: Trying to associate with XX:XX:XX:XX:XX:XX (SSID='meineSSID' freq=5220 MHz)
wlp1s0: Associated with XX:XX:XX:XX:XX:XX
wlp1s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
wlp1s0: WPA: Key negotiation completed with XX:XX:XX:XX:XX:XX [PTK=CCMP GTK=CCMP]
wlp1s0: CTRL-EVENT-CONNECTED - Connection to XX:XX:XX:XX:XX:XX completed [id=0 id_str=]
wlp1s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-70 noise=9999 txrate=6000
This is missing time stamps but seems to be a normal connect without PTK
rekey
Dec 20 22:57:48 lina avahi-daemon[637]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fe80::31a:e3aa:b668:28ed.
Dec 20 22:57:48 lina avahi-daemon[637]: New relevant interface wlp1s0.IPv6 for mDNS.
Dec 20 22:57:48 lina avahi-daemon[637]: Registering new address record for fe80::31a:e3aa:b668:28ed on wlp1s0.*.
Dec 20 22:57:49 lina dhclient[17036]: DHCPREQUEST for 192.168.0.31 on wlp1s0 to 255.255.255.255 port 67
Here we have time stamps the log messages are only telling us that you
could connect.
wlp1s0: CTRL-EVENT-DISCONNECTED bssid=XX:XX:XX:XX:XX:XX reason=2
wlp1s0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
wlp1s0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="meineSSID" auth_failures=1 duration=10 reason=WRONG_KEY
dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/5
The time stamps are again missing. But this looks like the 4-way
handshake has been restarted for some reason and failed.
wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Dec 20 22:57:54 lina systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Dec 20 22:58:06 lina avahi-daemon[637]: Withdrawing address record for fe80::31a:e3aa:b668:28ed on wlp1s0.
Dec 20 22:58:06 lina avahi-daemon[637]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address xxxx::xxxx:xxxx:xxxx:xxxx.
Dec 20 22:58:06 lina avahi-daemon[637]: Interface wlp1s0.IPv6 no longer relevant for mDNS.
Looks like the normal reaction due to the disconnect
wlp1s0: Reject scan trigger since one is already pending
The whole thing only happens with the debian buster laptop. No problem with other clients (android, Mac, iphone, Windows10)
They may just reconnect without the incorrect password prompt. In fact
something like that seems to be likely here.
I tried this in another house, where same router is used. There, the same problem appears. However with a different
laptop (Acer), but also debian buster AMD64 with KDE and network-Manager (and wpasupplicant).
Anyone else using a Fritzbox Router? Having or not having this problem? I am not sure if it is related to router, NM,
kernel, or wpasupplicant. I dont think its related to the wifi driver, because it happened on two laptops with different hardware.
Is there any way for me to obtain more information do debug this?
The debug logs mentioned above would be the next step for me.
Regards,
Jürgen
_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap
_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap
