Arch Linux

bgth

Member

Registered: 2018-05-21

Posts: 31

[SOLVED] Connection drops after switch from wpa_supplicant to iwd

Hello everyone,

I have a problem with my wifi setting. Some days ago I switched from wpa_supplicant to iwd. Since then I get notification about a connection lost (round about ervery 10min) and after some time I get a missmatch between the wifi status shown by iwctl and networkmanager. Sometimes iwctl shows that the state is disconnected but networkmanager shows that i am still connected (and in this situation i am not connected)

Maybe I first tell you what I did
1. Stop and Disable wpa_supplicant
2. uninstall wpa_supplicant
2. Install iwd
3. Start and Enable iwd
4. Added iwd as backend for networkmanager
5. restarted networkmanager

The used hardware is a thinkpad T480s.

I added the output of journalctl during a connection drop.

-- Logs begin at Thu 2020-04-02 08:45:56 CEST, end at Mon 2020-10-26 17:42:45 CET. --
Okt 26 17:38:38 thinkpad kernel: wlan0: disassociated from 2c:3a:fd:dc:39:af (Reason: 2=PREV_AUTH_NOT_VALID)
Okt 26 17:38:38 thinkpad iwd[933]: Received Deauthentication event, reason: 2, from_ap: true
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.8988] device (wlan0): new IWD device state is disconnected
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.8990] device (wlan0): state change: activated -> failed (reason 'supplicant-disconnect', sys-iface-state: 'managed')
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9001] manager: NetworkManager state is now DISCONNECTED
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <warn>  [1603730318.9033] device (wlan0): Activation: failed for connection 'WLANSSID'
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9053] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Withdrawing address record for fe80::c84e:8ebb:4e24:1cc6 on wlan0.
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::c84e:8ebb:4e24:1cc6.
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Interface wlan0.IPv6 no longer relevant for mDNS.
Okt 26 17:38:38 thinkpad dbus-daemon[929]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=1021 comm="/usr/bin/NetworkManager --no-daemon ")
Okt 26 17:38:38 thinkpad systemd[1]: Starting Network Manager Script Dispatcher Service...
Okt 26 17:38:38 thinkpad dbus-daemon[929]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Okt 26 17:38:38 thinkpad systemd[1]: Started Network Manager Script Dispatcher Service.
Okt 26 17:38:38 thinkpad audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:38:38 thinkpad kernel: audit: type=1130 audit(1603730318.923:117): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9272] dhcp4 (wlan0): canceled DHCP transaction
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9273] dhcp4 (wlan0): state changed bound -> done
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Withdrawing address record for ip-adress.27 on wlan0.
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Leaving mDNS multicast group on interface wlan0.IPv4 with address ip-adress.27.
Okt 26 17:38:38 thinkpad avahi-daemon[927]: Interface wlan0.IPv4 no longer relevant for mDNS.
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9481] policy: auto-activating connection 'WLANSSID' (abc-def-ghi-jkl)
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9760] device (wlan0): Activation: starting connection 'WLANSSID' (abc-def-ghi-jkl)
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9765] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9775] manager: NetworkManager state is now CONNECTING
Okt 26 17:38:38 thinkpad NetworkManager[1021]: <info>  [1603730318.9787] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.0195] device (wlan0): new IWD device state is connecting
Okt 26 17:38:39 thinkpad kernel: wlan0: authenticate with 2c:3a:fd:dc:39:af
Okt 26 17:38:39 thinkpad kernel: wlan0: send auth to 2c:3a:fd:dc:39:af (try 1/3)
Okt 26 17:38:39 thinkpad kernel: wlan0: authenticate with 2c:3a:fd:dc:39:af
Okt 26 17:38:39 thinkpad kernel: wlan0: send auth to 2c:3a:fd:dc:39:af (try 1/3)
Okt 26 17:38:39 thinkpad kernel: wlan0: authenticated
Okt 26 17:38:39 thinkpad kernel: wlan0: associate with 2c:3a:fd:dc:39:af (try 1/3)
Okt 26 17:38:39 thinkpad kernel: wlan0: RX AssocResp from 2c:3a:fd:dc:39:af (capab=0x1431 status=0 aid=3)
Okt 26 17:38:39 thinkpad kernel: wlan0: associated
Okt 26 17:38:39 thinkpad kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2710] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful.  Connected to 'WLANSSID'.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2714] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2725] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Okt 26 17:38:39 thinkpad avahi-daemon[927]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::c84e:8ebb:4e24:1cc6.
Okt 26 17:38:39 thinkpad avahi-daemon[927]: New relevant interface wlan0.IPv6 for mDNS.
Okt 26 17:38:39 thinkpad avahi-daemon[927]: Registering new address record for fe80::c84e:8ebb:4e24:1cc6 on wlan0.*.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2775] device (wlan0): new IWD device state is connected
Okt 26 17:38:39 thinkpad kernel: wlan0: Limiting TX power to 20 (20 - 0) dBm as advertised by 2c:3a:fd:dc:39:af
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2995] dhcp4 (wlan0): option dhcp_lease_time      => '864000'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2996] dhcp4 (wlan0): option domain_name          => 'DOMAINNAME'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2997] dhcp4 (wlan0): option domain_name_servers  => 'ip-adress.1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2997] dhcp4 (wlan0): option expiry               => '1604594319'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2997] dhcp4 (wlan0): option ip_address           => 'ip-adress.27'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2997] dhcp4 (wlan0): option next_server          => 'ip-adress.1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2998] dhcp4 (wlan0): option ntp_servers          => 'ip-adress.1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2998] dhcp4 (wlan0): option requested_broadcast_address => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2998] dhcp4 (wlan0): option requested_domain_name => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2998] dhcp4 (wlan0): option requested_domain_name_servers => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2999] dhcp4 (wlan0): option requested_domain_search => '1'
Okt 26 17:38:39 thinkpad avahi-daemon[927]: Joining mDNS multicast group on interface wlan0.IPv4 with address ip-adress.27.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2999] dhcp4 (wlan0): option requested_host_name  => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2999] dhcp4 (wlan0): option requested_interface_mtu => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.2999] dhcp4 (wlan0): option requested_ms_classless_static_routes => '1'
Okt 26 17:38:39 thinkpad avahi-daemon[927]: New relevant interface wlan0.IPv4 for mDNS.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3000] dhcp4 (wlan0): option requested_nis_domain => '1'
Okt 26 17:38:39 thinkpad avahi-daemon[927]: Registering new address record for ip-adress.27 on wlan0.IPv4.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3000] dhcp4 (wlan0): option requested_nis_servers => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3000] dhcp4 (wlan0): option requested_ntp_servers => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3000] dhcp4 (wlan0): option requested_rfc3442_classless_static_routes => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3000] dhcp4 (wlan0): option requested_root_path  => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3001] dhcp4 (wlan0): option requested_routers    => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3001] dhcp4 (wlan0): option requested_static_routes => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3001] dhcp4 (wlan0): option requested_subnet_mask => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3001] dhcp4 (wlan0): option requested_time_offset => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3002] dhcp4 (wlan0): option requested_wpad       => '1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3002] dhcp4 (wlan0): option routers              => 'ip-adress.1'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3002] dhcp4 (wlan0): option subnet_mask          => '255.255.255.0'
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3002] dhcp4 (wlan0): state changed unknown -> bound
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3048] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3125] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3134] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3151] manager: NetworkManager state is now CONNECTED_LOCAL
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3197] manager: NetworkManager state is now CONNECTED_SITE
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3202] policy: set 'WLANSSID' (wlan0) as default for IPv4 routing and DNS
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.3312] device (wlan0): Activation: successful, device activated.
Okt 26 17:38:39 thinkpad NetworkManager[1021]: <info>  [1603730319.4064] manager: NetworkManager state is now CONNECTED_GLOBAL
Okt 26 17:38:50 thinkpad systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Okt 26 17:38:50 thinkpad audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:38:50 thinkpad kernel: audit: type=1131 audit(1603730330.270:118): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:39:10 thinkpad gnome-shell[1694]: libinput error: client bug: timer event8 debounce short: scheduled expiry is in the past (-1ms), your system is too slow
Okt 26 17:40:05 thinkpad rtkit-daemon[1498]: Supervising 5 threads of 2 processes of 1 users.
Okt 26 17:40:05 thinkpad rtkit-daemon[1498]: Supervising 5 threads of 2 processes of 1 users.
Okt 26 17:40:10 thinkpad rtkit-daemon[1498]: Supervising 5 threads of 2 processes of 1 users.
Okt 26 17:40:10 thinkpad rtkit-daemon[1498]: Supervising 5 threads of 2 processes of 1 users.
Okt 26 17:40:31 thinkpad gnome-shell[1694]: libinput error: event7  - Elan Touchpad: client bug: event processing lagging behind by 24ms, your system is too slow
Okt 26 17:42:12 thinkpad systemd[1]: Starting Cleanup of Temporary Directories...
Okt 26 17:42:12 thinkpad systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Okt 26 17:42:12 thinkpad systemd[1]: Finished Cleanup of Temporary Directories.
Okt 26 17:42:12 thinkpad audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:42:12 thinkpad audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:42:12 thinkpad kernel: audit: type=1130 audit(1603730532.561:119): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:42:12 thinkpad kernel: audit: type=1131 audit(1603730532.561:120): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 26 17:42:45 thinkpad gnome-shell[1694]: libinput error: event7  - Elan Touchpad: client bug: event processing lagging behind by 21ms, your system is too slow

Hope some has an idea, whats wrong here. If you need further information, pls. let me know.
Thank you in advance.

Last edited by bgth (2020-10-26 21:01:59)

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 21,742

Re: [SOLVED] Connection drops after switch from wpa_supplicant to iwd

what happens if you disable the  iwd service? generally - at least with wpa_supplicant it's like that - you shouldn't enable the daemon for the backend while attempting to use it with networkmanager.

bgth

Member

Registered: 2018-05-21

Posts: 31

Re: [SOLVED] Connection drops after switch from wpa_supplicant to iwd

So I just disabled the iwd.service and rebooted. But the Problem is still there. What confuses me is that there is this message in the log file

Okt 26 18:28:38 thinkpad kernel: wlan0: disassociated from 2c:3a:fd:dc:39:af (Reason: 2=PREV_AUTH_NOT_VALID)
Okt 26 18:28:38 thinkpad iwd[985]: Received Deauthentication event, reason: 2, from_ap: true

And I just saw, that my router tells me that I am connected via WPA3 but the NetworkManager tells me that I am connected via WPA2. If I changed that to WPA3 it still shows me that it uses WPA2.

bgth

Member

Registered: 2018-05-21

Posts: 31

Re: [SOLVED] Connection drops after switch from wpa_supplicant to iwd

I just found

https://bbs.archlinux.org/viewtopic.php?pid=1933027
https://lkml.org/lkml/2020/10/14/1101

Maybe this helps

bgth

Member

Registered: 2018-05-21

Posts: 31

Re: [SOLVED] Connection drops after switch from wpa_supplicant to iwd

It looks like adding

[General]
ControlPortOverNL80211=False

to /etc/iwd/main.conf did the trick.