You are not logged in.

#1 2021-06-10 11:32:12

zegkljan
Member
Registered: 2017-12-30
Posts: 60

wpa_supplicant service does not stop

The first symptom of my problem was that my PC was not shutting down - it hung on a black screen with cursor blinking in the top left corner. To troubleshoot the issue I removed the quiet kernel parameter to see what is going on. I discovered that the system hangs on stopping Network Manager and WPA supplicant. This was consistent with the fact that if I performed a power off before the PC (laptop, actually) connected to wifi, the shutdown went normally. So, to test the theory further, I wanted to manually stop wpa_supplicant.service. However, when I do this

systemctl stop wpa_supplicant.service

the stopping does not complete, it hangs and does not return the control over the console. If I display the status of the service from another console, it shows as deactivating. Manually killing the wpa_supplicant process also does nothing. The only way I figured to get out of this situation is to issue the Alt+SysRq+B shortcut to force reboot the system. The wpa_supplicant logs for that particular boot when I attempted to stop the service look like this:

... previous boot(s)
-- Boot 6c988d3d745f437598652cf42ffba0b1 --
čen 10 10:56:26 eddie systemd[1]: Starting WPA supplicant...
čen 10 10:56:26 eddie systemd[1]: Started WPA supplicant.
čen 10 10:56:26 eddie wpa_supplicant[523]: Successfully initialized wpa_supplicant
čen 10 10:56:27 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:27 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:27 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:28 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:33 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:33 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:56:36 eddie wpa_supplicant[523]: wlan1: SME: Trying to authenticate with 70:4f:57:37:19:65 (SSID='wigfi2.4' freq=2412 MHz)
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: Trying to associate with 70:4f:57:37:19:65 (SSID='wigfi2.4' freq=2412 MHz)
čen 10 10:56:37 eddie wpa_supplicant[523]: RRM: Ignoring radio measurement request: Not associated
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: Associated with 70:4f:57:37:19:65
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: WPA: Key negotiation completed with 70:4f:57:37:19:65 [PTK=CCMP GTK=CCMP]
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-CONNECTED - Connection to 70:4f:57:37:19:65 completed [id=0 id_str=]
čen 10 10:56:37 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-59 noise=-112 txrate=162000
čen 10 10:57:03 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 10:57:03 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 11:01:23 eddie wpa_supplicant[523]: wlan1: WPA: Group rekeying completed with 70:4f:57:37:19:65 [GTK=CCMP]
čen 10 11:10:26 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-DISCONNECTED bssid=70:4f:57:37:19:65 reason=3 locally_generated=1
čen 10 11:10:26 eddie wpa_supplicant[523]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
čen 10 11:10:27 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 11:10:27 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 11:10:28 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
čen 10 11:10:42 eddie systemd[1]: Stopping WPA supplicant...
čen 10 11:10:42 eddie wpa_supplicant[523]: nl80211: deinit ifname=wlan1 disabled_11b_rates=0
čen 10 11:10:42 eddie wpa_supplicant[523]: wlan1: CTRL-EVENT-TERMINATING
čen 10 11:10:42 eddie wpa_supplicant[523]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
čen 10 11:12:12 eddie systemd[1]: wpa_supplicant.service: State 'stop-sigterm' timed out. Killing.
čen 10 11:12:12 eddie systemd[1]: wpa_supplicant.service: Killing process 523 (wpa_supplicant) with signal SIGKILL.
čen 10 11:13:42 eddie systemd[1]: wpa_supplicant.service: Processes still around after SIGKILL. Ignoring.
čen 10 11:15:12 eddie systemd[1]: wpa_supplicant.service: State 'final-sigterm' timed out. Killing.
čen 10 11:15:12 eddie systemd[1]: wpa_supplicant.service: Killing process 523 (wpa_supplicant) with signal SIGKILL.
čen 10 11:16:42 eddie systemd[1]: wpa_supplicant.service: Processes still around after final SIGKILL. Entering failed mode.
čen 10 11:16:42 eddie systemd[1]: wpa_supplicant.service: Failed with result 'timeout'.
čen 10 11:16:42 eddie systemd[1]: wpa_supplicant.service: Unit process 523 (wpa_supplicant) remains running after unit stopped.
čen 10 11:16:42 eddie systemd[1]: Stopped WPA supplicant.
-- Boot 7a7d6f9e7ea64a43ba8b8b95c8f8621e --
... following boot(s)

The log shows "Stopped WPA supplicant" but that is actually not the case, the process is still there. When the system shutdown fails, I think what is happening is that it "stops" the service like this but the process is still hanging there, causing the shutdown process to hang as well. But I don't know, I'm not very knowledgeable in these areas.

Another weird thing is that the wpa_supplicant.service is not enabled but is started anyway, even if NetworkManager.service is disabled. I cannot see it in systemctl list-dependencies either.

What could be the the problem? How is it possible that a service is started without it being neither enabled or wanted by another service? How can I make the service work as expected (i.e. stop it when I or the system tells it to stop)?

I'd be happy to provide additional info if instructed.

Offline

#2 2021-06-10 12:27:16

V1del
Forum Moderator
Registered: 2012-10-16
Posts: 21,427

Re: wpa_supplicant service does not stop

Services can be started by invocation through other services which is e.g. what NetworkManager does, it calls wpa_supplicant itself. In general this reads like classic multiple networking services fighting for the interface. What's your output for

find /etc/systemd -type l -exec test -f {} \; -print | awk -F'/' '{ printf ("%-40s | %s\n", $(NF-0), $(NF-1)) }' | sort -f

Offline

#3 2021-06-10 12:39:58

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

V1del wrote:

Services can be started by invocation through other services which is e.g. what NetworkManager does, it calls wpa_supplicant itself.

I have written, I found wpa_supplicant started just after reboot even when NetworkManager is disabled and not started.

V1del wrote:

In general this reads like classic multiple networking services fighting for the interface. What's your output for

find /etc/systemd -type l -exec test -f {} \; -print | awk -F'/' '{ printf ("%-40s | %s\n", $(NF-0), $(NF-1)) }' | sort -f
$ find /etc/systemd -type l -exec test -f {} \; -print | awk -F'/' '{ printf ("%-40s | %s\n", $(NF-0), $(NF-1)) }' | sort -f
bluetooth.service                        | bluetooth.target.wants
cups.path                                | multi-user.target.wants
cups.service                             | printer.target.wants
cups.socket                              | sockets.target.wants
dbus-org.bluez.service                   | system
dbus-org.freedesktop.nm-dispatcher.service | system
dbus-org.freedesktop.resolve1.service    | system
dbus-org.freedesktop.timesync1.service   | system
dirmngr.socket                           | sockets.target.wants
display-manager.service                  | system
docker.service                           | multi-user.target.wants
foldingathome.service                    | multi-user.target.wants
getty@tty1.service                       | getty.target.wants
gpg-agent-browser.socket                 | sockets.target.wants
gpg-agent-extra.socket                   | sockets.target.wants
gpg-agent.socket                         | sockets.target.wants
gpg-agent-ssh.socket                     | sockets.target.wants
NetworkManager.service                   | multi-user.target.wants
NetworkManager-wait-online.service       | network-online.target.wants
p11-kit-server.socket                    | sockets.target.wants
paccache.timer                           | timers.target.wants
pipewire-media-session.service           | pipewire.service.wants
pipewire-pulse.socket                    | sockets.target.wants
pipewire.socket                          | sockets.target.wants
reflector.timer                          | timers.target.wants
remote-fs.target                         | multi-user.target.wants
sshd.socket                              | sockets.target.wants
systemd-resolved.service                 | multi-user.target.wants
systemd-timesyncd.service                | sysinit.target.wants
xdg-user-dirs-update.service             | default.target.wants

Offline

#4 2021-06-10 13:34:41

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

Please post a complete system journal from a boot where wpa_supplicant is started despite NM being disablded.

Online

#5 2021-06-10 14:56:29

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

It's rather long, so here: http://ix.io/3pt5

Offline

#6 2021-06-10 15:04:12

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

Invoked by geoclue (which is invoked by gnome-shell)

Jun 10 16:50:27 eddie dbus-daemon[414]: [system] Activating via systemd: service name='fi.w1.wpa_supplicant1' unit='wpa_supplicant.service' requested by ':1.29' (uid=971 pid=989 comm="/usr/lib/geoclue ")
Jun 10 16:50:27 eddie systemd[1]: Starting WPA supplicant...
Jun 10 16:50:27 eddie dbus-daemon[414]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
Jun 10 16:50:27 eddie systemd[1]: Started WPA supplicant.
Jun 10 16:50:27 eddie audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 10 16:50:27 eddie wpa_supplicant[1000]: Successfully initialized wpa_supplicant
Jun 10 16:50:27 eddie systemd[1]: Reached target Network.

Most likely because wifi is enabled in /etc/geoclue/geoclue.conf - there's no effort to stop it in this journal, but I guess you need to stop geoclue first.

Online

#7 2021-06-11 05:56:32

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

Nice catch. I have disabled wifi in /etc/geoclue/geoclue.conf and wpa_supplicant.service is not starting anymore. However, the original problem remains - when I actually start NetworkManager.service, which in turn starts wpa_supplicant.service, I am unable to stop it. A manual attempt to do this (systemctl stop wpa_supplicant.service) looks like this:

čen 11 07:39:28 eddie systemd[1]: Stopping WPA supplicant...
čen 11 07:40:58 eddie systemd[1]: wpa_supplicant.service: State 'stop-sigterm' timed out. Killing.
čen 11 07:40:58 eddie systemd[1]: wpa_supplicant.service: Killing process 2183 (wpa_supplicant) with signal SIGKILL.
čen 11 07:42:28 eddie systemd[1]: wpa_supplicant.service: Processes still around after SIGKILL. Ignoring.
čen 11 07:43:58 eddie systemd[1]: wpa_supplicant.service: State 'final-sigterm' timed out. Killing.
čen 11 07:43:58 eddie systemd[1]: wpa_supplicant.service: Killing process 2183 (wpa_supplicant) with signal SIGKILL.
čen 11 07:45:29 eddie systemd[1]: wpa_supplicant.service: Processes still around after final SIGKILL. Entering failed mode.
čen 11 07:45:29 eddie systemd[1]: wpa_supplicant.service: Failed with result 'timeout'.
čen 11 07:45:29 eddie systemd[1]: wpa_supplicant.service: Unit process 2183 (wpa_supplicant) remains running after unit stopped.
čen 11 07:45:29 eddie systemd[1]: Stopped WPA supplicant.

And indeed, the process is still happily running.

By the way, basically the same thing happens with NetworkManager.service too:

čen 11 07:36:29 eddie systemd[1]: Stopping Network Manager...
čen 11 07:36:29 eddie NetworkManager[2173]: <info>  [1623389789.9189] caught SIGTERM, shutting down normally.
čen 11 07:36:29 eddie NetworkManager[2173]: <info>  [1623389789.9224] device (wlan0): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
čen 11 07:36:29 eddie NetworkManager[2173]: <info>  [1623389789.9876] device (wlan0): set-hw-addr: reset MAC address to 04:CE:14:07:43:2B (unmanage)
čen 11 07:36:30 eddie NetworkManager[2173]: <info>  [1623389790.0768] device (p2p-dev-wlan0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
čen 11 07:36:30 eddie NetworkManager[2173]: <info>  [1623389790.0786] device (wlan1): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
čen 11 07:36:30 eddie NetworkManager[2173]: <info>  [1623389790.1635] device (wlan1): set-hw-addr: reset MAC address to 6C:0B:84:26:73:D7 (unmanage)
čen 11 07:38:00 eddie systemd[1]: NetworkManager.service: State 'stop-sigterm' timed out. Killing.
čen 11 07:38:00 eddie systemd[1]: NetworkManager.service: Killing process 2173 (NetworkManager) with signal SIGKILL.
čen 11 07:39:30 eddie systemd[1]: NetworkManager.service: Processes still around after SIGKILL. Ignoring.
čen 11 07:41:00 eddie systemd[1]: NetworkManager.service: State 'final-sigterm' timed out. Killing.
čen 11 07:41:00 eddie systemd[1]: NetworkManager.service: Killing process 2173 (NetworkManager) with signal SIGKILL.
čen 11 07:42:30 eddie systemd[1]: NetworkManager.service: Processes still around after final SIGKILL. Entering failed mode.
čen 11 07:42:30 eddie systemd[1]: NetworkManager.service: Failed with result 'timeout'.
čen 11 07:42:30 eddie systemd[1]: NetworkManager.service: Unit process 2173 (NetworkManager) remains running after unit stopped.
čen 11 07:42:30 eddie systemd[1]: Stopped Network Manager.
čen 11 07:42:30 eddie systemd[1]: NetworkManager.service: Consumed 1.762s CPU time.

The system refuses to shut down too (my very original problem).

Offline

#8 2021-06-11 06:49:18

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

Does it meet the PID wpa_supplicant.service thinks it has?

What's its state?

ps aux | grep wpa

Online

#9 2021-06-11 08:19:21

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

Yes it does. The log:

čen 11 08:58:59 eddie systemd[1]: Stopping WPA supplicant...
čen 11 08:58:59 eddie wpa_supplicant[2029]: wlan1: CTRL-EVENT-DISCONNECTED bssid=70:4f:57:37:19:65 reason=3 locally_generated=1
čen 11 08:58:59 eddie wpa_supplicant[2029]: nl80211: deinit ifname=wlan1 disabled_11b_rates=0
čen 11 08:58:59 eddie wpa_supplicant[2029]: wlan1: CTRL-EVENT-TERMINATING
čen 11 08:58:59 eddie wpa_supplicant[2029]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
čen 11 09:00:29 eddie systemd[1]: wpa_supplicant.service: State 'stop-sigterm' timed out. Killing.
čen 11 09:00:29 eddie systemd[1]: wpa_supplicant.service: Killing process 2029 (wpa_supplicant) with signal SIGKILL.
čen 11 09:01:59 eddie systemd[1]: wpa_supplicant.service: Processes still around after SIGKILL. Ignoring.
čen 11 09:03:29 eddie systemd[1]: wpa_supplicant.service: State 'final-sigterm' timed out. Killing.
čen 11 09:03:29 eddie systemd[1]: wpa_supplicant.service: Killing process 2029 (wpa_supplicant) with signal SIGKILL.
čen 11 09:05:00 eddie systemd[1]: wpa_supplicant.service: Processes still around after final SIGKILL. Entering failed mode.
čen 11 09:05:00 eddie systemd[1]: wpa_supplicant.service: Failed with result 'timeout'.
čen 11 09:05:00 eddie systemd[1]: wpa_supplicant.service: Unit process 2029 (wpa_supplicant) remains running after unit stopped.
čen 11 09:05:00 eddie systemd[1]: Stopped WPA supplicant.

ps aux | grep wpa

root        2029  0.0  0.1  15364  9600 ?        Ds   07:50   0:00 /usr/bin/wpa_supplicant -u -s -O /run/wpa_supplicant
zegkljan    6491  0.0  0.7 974280 63060 pts/0    S+   08:58   0:00 journalctl -fu wpa_supplicant.service
zegkljan    9810  0.0  0.0   8936  2328 pts/1    S+   10:13   0:00 grep --color=auto wpa

Out of curiosity, I tried to start wpa_supplicant.service again from this state and this is the log:

čen 11 10:14:34 eddie systemd[1]: wpa_supplicant.service: Found left-over process 2029 (wpa_supplicant) in control group while starting unit. Ignoring.
čen 11 10:14:34 eddie systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
čen 11 10:14:34 eddie systemd[1]: Starting WPA supplicant...
čen 11 10:14:34 eddie wpa_supplicant[10039]: dbus: Could not request service name: already registered
čen 11 10:14:34 eddie wpa_supplicant[10039]: Failed to initialize wpa_supplicant
čen 11 10:14:34 eddie systemd[1]: wpa_supplicant.service: Main process exited, code=exited, status=255/EXCEPTION

Offline

#10 2021-06-11 13:26:56

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

It's likely waiting for some I/O ("D" state) - you could strace it to see where it's hanging around or check the dmesg for IO errors.

Does the wifi NIC work? Can you ping an IP over it? (Before trying to take it down)?
Is it in the "D" state before the attempt to terminate it?

Online

#11 2021-06-13 13:36:03

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

When wpa_supplicant and NetworkManager are up and running, everything works just fine, I can ping, wget, whatever. When I stop wpa_supplicant, I cannot ping anymore, even before systemd starts reporting the term/kill timeouts.
It seems not to be in the D state before the termination attempt:

ps aux | grep wpa
root        2636  0.1  0.1  15256  8976 ?        Ss   14:59   0:00 /usr/bin/wpa_supplicant -u -s -O /run/wpa_supplicant
zegkljan    2912  0.0  0.0   8936  2436 pts/2    S+   15:00   0:00 grep --color=auto wpa

Here is the strace (started before the stop command):

> sudo strace -p 2228
[sudo] password for zegkljan: 
strace: Process 2228 attached
pselect6(27, [4 5 7 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26], [], [4], {tv_sec=6, tv_nsec=560380876}, NULL) = 0 (Timeout)
pselect6(27, [4 5 7 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26], [], [4], {tv_sec=9, tv_nsec=999996000}, NULL) = 0 (Timeout)
pselect6(27, [4 5 7 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26], [], [4], {tv_sec=9, tv_nsec=999995000}, NULL) = 0 (Timeout)
pselect6(27, [4 5 7 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26], [], [4], {tv_sec=9, tv_nsec=999994000}, NULL) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=1, si_uid=0} ---
--- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=1, si_uid=0} ---
rt_sigaction(SIGALRM, {sa_handler=0x5643a91eee00, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f73c4f24da0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
alarm(2)                                = 0
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
alarm(0)                                = 2
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587328, nlmsg_pid=-1786771276}, "\x27\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x06\x00\x36\x00\x03\x00\x00\x00\x0a\x00\x06\x00\x70\x4f\x57\x37\x19\x65\x00\x00"}, iov_len=48}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 48
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587328, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587328, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587328, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587328, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getpid()                                = 2228
sendto(3, "<29>Jun 13 14:49:08 wpa_supplica"..., 125, MSG_NOSIGNAL, NULL, 0) = 125
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\1H\0\0\0\320\2\0\0\206\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=152}, {iov_base="\37\0\0\0fi.w1.wpa_supplicant1.Interf"..., iov_len=72}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 224
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\1$\0\0\0\321\2\0\0\203\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=152}, {iov_base="\34\0\0\0\0\0\0\0\20\0\0\0DisconnectReason\0\1i\0"..., iov_len=36}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 188
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 27
ioctl(27, SIOCGIFINDEX, {ifr_name="wlan1", ifr_ifindex=4}) = 0
close(27)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587329, nlmsg_pid=-1786771276}, "\x0c\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x05\x00\x08\x00\x00\x00\x00\x00"}, iov_len=36}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587329, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587329, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587329, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587329, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 27
ioctl(27, SIOCGIFINDEX, {ifr_name="wlan1", ifr_ifindex=4}) = 0
close(27)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587330, nlmsg_pid=-1786771276}, "\x0c\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x05\x00\x08\x00\x01\x00\x00\x00"}, iov_len=36}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587330, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587330, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587330, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587330, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 27
ioctl(27, SIOCGIFINDEX, {ifr_name="wlan1", ifr_ifindex=4}) = 0
close(27)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587331, nlmsg_pid=-1786771276}, "\x0c\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x0a\x00\x06\x00\x70\x4f\x57\x37\x19\x65\x00\x00\x05\x00\x08\x00\x00\x00\x00\x00"}, iov_len=48}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 48
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587331, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587331, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587331, nlmsg_pid=-1786771276}, {error=-ENOLINK, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587331, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_gratuitous_arp", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unsolicited_na", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendto(5, {{nlmsg_len=40, nlmsg_type=RTM_SETLINK, nlmsg_flags=NLM_F_REQUEST, nlmsg_seq=17, nlmsg_pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=if_nametoindex("wlan1"), ifi_flags=0, ifi_change=0}, {{nla_len=5, nla_type=IFLA_OPERSTATE}, 5}}, 40, 0, NULL, 0) = 40
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587332, nlmsg_pid=-1786771276}, "\x3f\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x14\x00\x5e\x80\x08\x00\x01\x00\x00\x00\x00\x00\x08\x00\x02\x00\x00\x00\x00\x00"}, iov_len=48}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 48
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587332, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587332, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587332, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=48, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587332, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_gratuitous_arp", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unsolicited_na", O_RDWR) = 27
write(27, "0\n", 2)                     = 2
close(27)                               = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendto(5, {{nlmsg_len=40, nlmsg_type=RTM_SETLINK, nlmsg_flags=NLM_F_REQUEST, nlmsg_seq=18, nlmsg_pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=if_nametoindex("wlan1"), ifi_flags=0, ifi_change=0}, {{nla_len=5, nla_type=IFLA_OPERSTATE}, 5}}, 40, 0, NULL, 0) = 40
close(24)                               = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0013\0\0\0\322\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base=".\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=51}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 187
close(25)                               = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\323\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\324\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\325\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\326\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\327\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\330\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\331\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\332\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\333\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\334\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\335\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\336\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0010\0\0\0\337\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base="+\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=48}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0011\0\0\0\340\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base=",\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=49}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 185
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0011\0\0\0\341\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base=",\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=49}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 185
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\0011\0\0\0\342\2\0\0w\0\0\0\1\1o\0#\0\0\0/fi/w1/w"..., iov_len=136}, {iov_base=",\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=49}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 185
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 24
write(24, "0\n", 2)                     = 2
close(24)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unicast_in_l2_multicast", O_RDWR) = 24
write(24, "0\n", 2)                     = 2
close(24)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/wlan1/drop_gratuitous_arp", O_RDWR) = 24
write(24, "0\n", 2)                     = 2
close(24)                               = 0
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/wlan1/drop_unsolicited_na", O_RDWR) = 24
write(24, "0\n", 2)                     = 2
close(24)                               = 0
getpid()                                = 2228
sendto(3, "<29>Jun 13 14:49:08 wpa_supplica"..., 91, MSG_NOSIGNAL, NULL, 0) = 91
close(23)                               = 0
sendto(5, {{nlmsg_len=48, nlmsg_type=RTM_SETLINK, nlmsg_flags=NLM_F_REQUEST, nlmsg_seq=19, nlmsg_pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=if_nametoindex("wlan1"), ifi_flags=0, ifi_change=0}, [{{nla_len=5, nla_type=IFLA_LINKMODE}, 0}, {{nla_len=5, nla_type=IFLA_OPERSTATE}, 6}]}, 48, 0, NULL, 0) = 48
close(21)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587333, nlmsg_pid=-1786771276}, "\x06\x00\x00\x00\x08\x00\x03\x00\x04\x00\x00\x00\x08\x00\x05\x00\x02\x00\x00\x00"}, iov_len=36}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587333, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587333, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587333, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=36, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587333, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
close(20)                               = 0
close(22)                               = 0
sendmsg(4, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\1(\0\0\0\343\2\0\0g\0\0\0\1\1o\0\26\0\0\0/fi/w1/w"..., iov_len=120}, {iov_base="#\0\0\0/fi/w1/wpa_supplicant1/Inter"..., iov_len=40}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 160
getpid()                                = 2228
sendto(3, "<29>Jun 13 14:49:08 wpa_supplica"..., 72, MSG_NOSIGNAL, NULL, 0) = 72
getsockopt(26, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(26, TIOCOUTQ, [0])                = 0
close(26)                               = 0
unlink("/run/wpa_supplicant/wlan1")     = 0
rmdir("/run/wpa_supplicant")            = -1 ENOTEMPTY (Directory not empty)
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_gratuitous_arp", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/p2p-dev-wlan0/drop_unsolicited_na", O_RDWR) = -1 ENOENT (No such file or directory)
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
sendto(5, {{nlmsg_len=40, nlmsg_type=RTM_SETLINK, nlmsg_flags=NLM_F_REQUEST, nlmsg_seq=20, nlmsg_pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, {{nla_len=5, nla_type=IFLA_OPERSTATE}, 5}}, 40, 0, NULL, 0) = 40
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_gratuitous_arp", O_RDWR) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/net/ipv6/conf/p2p-dev-wlan0/drop_unsolicited_na", O_RDWR) = -1 ENOENT (No such file or directory)
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getsockopt(19, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
ioctl(19, TIOCOUTQ, [0])                = 0
getpid()                                = 2228
sendto(3, "<29>Jun 13 14:49:08 wpa_supplica"..., 99, MSG_NOSIGNAL, NULL, 0) = 99
close(18)                               = 0
sendto(5, {{nlmsg_len=48, nlmsg_type=RTM_SETLINK, nlmsg_flags=NLM_F_REQUEST, nlmsg_seq=21, nlmsg_pid=0}, {ifi_family=AF_UNSPEC, ifi_type=ARPHRD_NETROM, ifi_index=0, ifi_flags=0, ifi_change=0}, [{{nla_len=5, nla_type=IFLA_LINKMODE}, 0}, {{nla_len=5, nla_type=IFLA_OPERSTATE}, 6}]}, 48, 0, NULL, 0) = 48
close(17)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}, "\x05\x00\x00\x00\x0c\x00\x99\x00\x02\x00\x00\x00\x00\x00\x00\x00"}, iov_len=32}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=76, nlmsg_type=nl80211, nlmsg_flags=0, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}, "\x07\x01\x00\x00\x08\x00\x01\x00\x00\x00\x00\x00\x08\x00\x05\x00\x0a\x00\x00\x00\x0c\x00\x99\x00\x02\x00\x00\x00\x00\x00\x00\x00"...}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 76
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=76, nlmsg_type=nl80211, nlmsg_flags=0, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}, "\x07\x01\x00\x00\x08\x00\x01\x00\x00\x00\x00\x00\x08\x00\x05\x00\x0a\x00\x00\x00\x0c\x00\x99\x00\x02\x00\x00\x00\x00\x00\x00\x00"...}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 76
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587334, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587335, nlmsg_pid=-1786771276}, "\x5a\x00\x00\x00\x0c\x00\x99\x00\x02\x00\x00\x00\x00\x00\x00\x00"}, iov_len=32}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587335, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587335, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_PEEK|MSG_TRUNC) = 36
recvmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1623587335, nlmsg_pid=-1786771276}, {error=0, msg={nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587335, nlmsg_pid=-1786771276}}}, iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
close(16)                               = 0
setsockopt(6, SOL_NETLINK, NETLINK_EXT_ACK, [1], 4) = 0
setsockopt(6, SOL_NETLINK, NETLINK_CAP_ACK, [1], 4) = 0
sendmsg(6, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{nlmsg_len=32, nlmsg_type=nl80211, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1623587336, nlmsg_pid=-1786771276}, "\x08\x00\x00\x00\x0c\x00\x99\x00\x02\x00\x00\x00\x00\x00\x00\x00"}, iov_len=32}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0

and, for completeness, here is the corresponding log:

čen 13 14:49:08 eddie systemd[1]: Stopping WPA supplicant...
čen 13 14:49:08 eddie wpa_supplicant[2228]: wlan1: CTRL-EVENT-DISCONNECTED bssid=70:4f:57:37:19:65 reason=3 locally_generated=1
čen 13 14:49:08 eddie wpa_supplicant[2228]: nl80211: deinit ifname=wlan1 disabled_11b_rates=0
čen 13 14:49:08 eddie wpa_supplicant[2228]: wlan1: CTRL-EVENT-TERMINATING
čen 13 14:49:08 eddie wpa_supplicant[2228]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
čen 13 14:50:38 eddie systemd[1]: wpa_supplicant.service: State 'stop-sigterm' timed out. Killing.
čen 13 14:50:38 eddie systemd[1]: wpa_supplicant.service: Killing process 2228 (wpa_supplicant) with signal SIGKILL.
čen 13 14:52:08 eddie systemd[1]: wpa_supplicant.service: Processes still around after SIGKILL. Ignoring.
čen 13 14:53:38 eddie systemd[1]: wpa_supplicant.service: State 'final-sigterm' timed out. Killing.
čen 13 14:53:38 eddie systemd[1]: wpa_supplicant.service: Killing process 2228 (wpa_supplicant) with signal SIGKILL.
čen 13 14:55:09 eddie systemd[1]: wpa_supplicant.service: Processes still around after final SIGKILL. Entering failed mode.
čen 13 14:55:09 eddie systemd[1]: wpa_supplicant.service: Failed with result 'timeout'.
čen 13 14:55:09 eddie systemd[1]: wpa_supplicant.service: Unit process 2228 (wpa_supplicant) remains running after unit stopped.
čen 13 14:55:09 eddie systemd[1]: Stopped WPA supplicant.

Here is dmesg. The first entry is the fist one after the stop command, and I left it running for a while. It's from a different attempt than the strace as I just forgot to start dmesg the first time.

[  255.565435] audit: type=1100 audit(1623589363.290:261): pid=3074 uid=1000 auid=1000 ses=4 msg='op=PAM:authentication grantors=pam_faillock,pam_permit,pam_faillock acct="zegkljan" exe="/usr/lib/polkit-1/polkit-agent-helper-1" hostname=? addr=? terminal=? res=success'
[  255.567747] audit: type=1101 audit(1623589363.293:262): pid=3074 uid=1000 auid=1000 ses=4 msg='op=PAM:accounting grantors=pam_unix,pam_permit,pam_time acct="zegkljan" exe="/usr/lib/polkit-1/polkit-agent-helper-1" hostname=? addr=? terminal=? res=success'
[  255.578915] wlan1: deauthenticating from 70:4f:57:37:19:65 by local choice (Reason: 3=DEAUTH_LEAVING)
[  491.178548] INFO: task kworker/u8:1:78 blocked for more than 122 seconds.
[  491.178564]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.178570] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.178574] task:kworker/u8:1    state:D stack:    0 pid:   78 ppid:     2 flags:0x00004000
[  491.178588] Workqueue: events_power_efficient reg_check_chans_work [cfg80211]
[  491.178693] Call Trace:
[  491.178701]  __schedule+0x2ff/0x8b0
[  491.178727]  schedule+0x5b/0xc0
[  491.178737]  schedule_preempt_disabled+0x11/0x20
[  491.178747]  __mutex_lock.constprop.0+0x367/0x550
[  491.178763]  reg_check_chans_work+0x2d/0x3c0 [cfg80211]
[  491.178846]  process_one_work+0x214/0x3e0
[  491.178855]  worker_thread+0x4d/0x3d0
[  491.178862]  ? process_one_work+0x3e0/0x3e0
[  491.178869]  kthread+0x133/0x150
[  491.178878]  ? kthread_associate_blkcg+0xc0/0xc0
[  491.178889]  ret_from_fork+0x22/0x30
[  491.178912] INFO: task kworker/0:2:150 blocked for more than 122 seconds.
[  491.178917]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.178921] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.178923] task:kworker/0:2     state:D stack:    0 pid:  150 ppid:     2 flags:0x00004000
[  491.178933] Workqueue: ipv6_addrconf addrconf_verify_work
[  491.178948] Call Trace:
[  491.178952]  __schedule+0x2ff/0x8b0
[  491.178964]  schedule+0x5b/0xc0
[  491.178973]  schedule_preempt_disabled+0x11/0x20
[  491.178983]  __mutex_lock.constprop.0+0x367/0x550
[  491.178994]  ? __switch_to_asm+0x42/0x70
[  491.179006]  addrconf_verify_work+0xa/0x20
[  491.179017]  process_one_work+0x214/0x3e0
[  491.179024]  worker_thread+0x4d/0x3d0
[  491.179030]  ? process_one_work+0x3e0/0x3e0
[  491.179036]  kthread+0x133/0x150
[  491.179046]  ? kthread_associate_blkcg+0xc0/0xc0
[  491.179056]  ret_from_fork+0x22/0x30
[  491.179144] INFO: task Qt bearer threa:1650 blocked for more than 122 seconds.
[  491.179149]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.179152] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.179154] task:Qt bearer threa state:D stack:    0 pid: 1650 ppid:  1230 flags:0x00000000
[  491.179163] Call Trace:
[  491.179168]  __schedule+0x2ff/0x8b0
[  491.179179]  schedule+0x5b/0xc0
[  491.179188]  schedule_preempt_disabled+0x11/0x20
[  491.179197]  __mutex_lock.constprop.0+0x367/0x550
[  491.179208]  ? __netlink_lookup+0xc8/0x100
[  491.179219]  __netlink_dump_start+0xc2/0x2d0
[  491.179229]  ? rtnl_fill_ifinfo+0x13d0/0x13d0
[  491.179238]  rtnetlink_rcv_msg+0x298/0x3a0
[  491.179246]  ? rtnl_fill_ifinfo+0x13d0/0x13d0
[  491.179254]  ? rtnl_calcit.isra.0+0x150/0x150
[  491.179262]  netlink_rcv_skb+0x5b/0x100
[  491.179273]  netlink_unicast+0x23e/0x350
[  491.179283]  netlink_sendmsg+0x23a/0x470
[  491.179294]  sock_sendmsg+0x5e/0x60
[  491.179305]  __sys_sendto+0x124/0x190
[  491.179321]  __x64_sys_sendto+0x20/0x30
[  491.179331]  do_syscall_64+0x33/0x40
[  491.179341]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  491.179350] RIP: 0033:0x7f10dc8a0bac
[  491.179357] RSP: 002b:00007f1087ffd4d0 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[  491.179365] RAX: ffffffffffffffda RBX: 0000000000000015 RCX: 00007f10dc8a0bac
[  491.179371] RDX: 0000000000000020 RSI: 00007f1087ffd560 RDI: 0000000000000015
[  491.179375] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[  491.179379] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f1087ffd628
[  491.179384] R13: 00007f1087ffd530 R14: 00007f10aa87a490 R15: 0000000000000001
[  491.179419] INFO: task DNS Resolver #2:2074 blocked for more than 122 seconds.
[  491.179424]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.179427] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.179429] task:DNS Resolver #2 state:D stack:    0 pid: 2074 ppid:  1248 flags:0x00000000
[  491.179437] Call Trace:
[  491.179440]  __schedule+0x2ff/0x8b0
[  491.179452]  schedule+0x5b/0xc0
[  491.179461]  schedule_preempt_disabled+0x11/0x20
[  491.179470]  __mutex_lock.constprop.0+0x367/0x550
[  491.179481]  ? __netlink_lookup+0xc8/0x100
[  491.179491]  __netlink_dump_start+0xc2/0x2d0
[  491.179500]  ? rtnl_fill_link_ifmap+0xa0/0xa0
[  491.179507]  rtnetlink_rcv_msg+0x298/0x3a0
[  491.179514]  ? rtnl_fill_link_ifmap+0xa0/0xa0
[  491.179521]  ? rtnl_calcit.isra.0+0x150/0x150
[  491.179528]  netlink_rcv_skb+0x5b/0x100
[  491.179539]  netlink_unicast+0x23e/0x350
[  491.179549]  netlink_sendmsg+0x23a/0x470
[  491.179560]  sock_sendmsg+0x5e/0x60
[  491.179569]  __sys_sendto+0x124/0x190
[  491.179585]  __x64_sys_sendto+0x20/0x30
[  491.179594]  do_syscall_64+0x33/0x40
[  491.179603]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  491.179610] RIP: 0033:0x7fdda3427dc4
[  491.179614] RSP: 002b:00007fdd85954f70 EFLAGS: 00000293 ORIG_RAX: 000000000000002c
[  491.179620] RAX: ffffffffffffffda RBX: 00007fdd859560a0 RCX: 00007fdda3427dc4
[  491.179625] RDX: 0000000000000014 RSI: 00007fdd859560a0 RDI: 000000000000002a
[  491.179629] RBP: 0000000000000000 R08: 00007fdd85956044 R09: 000000000000000c
[  491.179632] R10: 0000000000000000 R11: 0000000000000293 R12: 00007fdd85956044
[  491.179636] R13: 00000000bfb4ddc5 R14: 000000000000002a R15: 0000000000000000
[  491.179687] INFO: task NetworkManager:2629 blocked for more than 122 seconds.
[  491.179691]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.179695] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.179697] task:NetworkManager  state:D stack:    0 pid: 2629 ppid:     1 flags:0x00000000
[  491.179704] Call Trace:
[  491.179708]  __schedule+0x2ff/0x8b0
[  491.179719]  schedule+0x5b/0xc0
[  491.179728]  schedule_preempt_disabled+0x11/0x20
[  491.179737]  __mutex_lock.constprop.0+0x367/0x550
[  491.179750]  ip6mr_sk_done+0x2e/0xd0
[  491.179759]  rawv6_close+0x19/0x30
[  491.179766]  inet_release+0x42/0x80
[  491.179778]  __sock_release+0x3d/0xa0
[  491.179787]  sock_close+0x11/0x20
[  491.179794]  __fput+0x8c/0x230
[  491.179806]  task_work_run+0x5c/0x90
[  491.179814]  exit_to_user_mode_prepare+0x14d/0x150
[  491.179828]  syscall_exit_to_user_mode+0x23/0x50
[  491.179841]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  491.179847] RIP: 0033:0x7fa8d290382b
[  491.179851] RSP: 002b:00007ffdcdd35040 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
[  491.179857] RAX: 0000000000000000 RBX: 0000562d3b43a830 RCX: 00007fa8d290382b
[  491.179861] RDX: 0000000000000002 RSI: 0000000562d3b4bb RDI: 0000000000000015
[  491.179865] RBP: 0000562d3b40ebd0 R08: 0000000000000000 R09: 0000000000000002
[  491.179868] R10: 0000000000000000 R11: 0000000000000293 R12: 0000562d3b441800
[  491.179872] R13: 0000000000000002 R14: 0000000000000064 R15: 000000000000000a
[  491.179881] INFO: task wpa_supplicant:2636 blocked for more than 122 seconds.
[  491.179885]       Tainted: P           OE     5.12.9-arch1-1 #1
[  491.179887] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  491.179889] task:wpa_supplicant  state:D stack:    0 pid: 2636 ppid:     1 flags:0x00004004
[  491.179896] Call Trace:
[  491.179899]  __schedule+0x2ff/0x8b0
[  491.179910]  schedule+0x5b/0xc0
[  491.179919]  schedule_preempt_disabled+0x11/0x20
[  491.179928]  __mutex_lock.constprop.0+0x367/0x550
[  491.179938]  ? sk_filter_trim_cap+0xdf/0x230
[  491.179954]  wil_p2p_wdev_free+0x55/0x80 [wil6210]
[  491.180010]  wil_cfg80211_del_iface+0xf2/0x160 [wil6210]
[  491.180055]  nl80211_del_interface+0x67/0x130 [cfg80211]
[  491.180153]  genl_family_rcv_msg_doit+0xfd/0x160
[  491.180167]  genl_rcv_msg+0xeb/0x1e0
[  491.180177]  ? parse_acl_data+0x160/0x160 [cfg80211]
[  491.180265]  ? genl_get_cmd+0xd0/0xd0
[  491.180275]  netlink_rcv_skb+0x5b/0x100
[  491.180286]  genl_rcv+0x24/0x40
[  491.180295]  netlink_unicast+0x23e/0x350
[  491.180305]  netlink_sendmsg+0x23a/0x470
[  491.180316]  sock_sendmsg+0x5e/0x60
[  491.180325]  ____sys_sendmsg+0x258/0x2a0
[  491.180337]  ___sys_sendmsg+0xa3/0xf0
[  491.180355]  __sys_sendmsg+0x81/0xd0
[  491.180368]  do_syscall_64+0x33/0x40
[  491.180377]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  491.180384] RIP: 0033:0x7fb73d338cc7
[  491.180388] RSP: 002b:00007ffde3459038 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
[  491.180394] RAX: ffffffffffffffda RBX: 00005562c35b77a0 RCX: 00007fb73d338cc7
[  491.180398] RDX: 0000000000000000 RSI: 00007ffde3459070 RDI: 0000000000000006
[  491.180402] RBP: 00005562c35b76b0 R08: 0000000000000004 R09: 00005562c35ad010
[  491.180405] R10: 00007ffde3459144 R11: 0000000000000246 R12: 00005562c35e1350
[  491.180409] R13: 00007ffde3459070 R14: 00007ffde3459144 R15: 00005562c35f2280
[  614.046803] INFO: task kworker/u8:1:78 blocked for more than 245 seconds.
[  614.046821]       Tainted: P           OE     5.12.9-arch1-1 #1
[  614.046829] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  614.046835] task:kworker/u8:1    state:D stack:    0 pid:   78 ppid:     2 flags:0x00004000
[  614.046855] Workqueue: events_power_efficient reg_check_chans_work [cfg80211]
[  614.046983] Call Trace:
[  614.046992]  __schedule+0x2ff/0x8b0
[  614.047013]  schedule+0x5b/0xc0
[  614.047025]  schedule_preempt_disabled+0x11/0x20
[  614.047037]  __mutex_lock.constprop.0+0x367/0x550
[  614.047055]  reg_check_chans_work+0x2d/0x3c0 [cfg80211]
[  614.047153]  process_one_work+0x214/0x3e0
[  614.047164]  worker_thread+0x4d/0x3d0
[  614.047172]  ? process_one_work+0x3e0/0x3e0
[  614.047180]  kthread+0x133/0x150
[  614.047191]  ? kthread_associate_blkcg+0xc0/0xc0
[  614.047203]  ret_from_fork+0x22/0x30
[  614.047231] INFO: task kworker/0:2:150 blocked for more than 245 seconds.
[  614.047237]       Tainted: P           OE     5.12.9-arch1-1 #1
[  614.047242] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  614.047244] task:kworker/0:2     state:D stack:    0 pid:  150 ppid:     2 flags:0x00004000
[  614.047256] Workqueue: ipv6_addrconf addrconf_verify_work
[  614.047273] Call Trace:
[  614.047278]  __schedule+0x2ff/0x8b0
[  614.047292]  schedule+0x5b/0xc0
[  614.047303]  schedule_preempt_disabled+0x11/0x20
[  614.047314]  __mutex_lock.constprop.0+0x367/0x550
[  614.047327]  ? __switch_to_asm+0x42/0x70
[  614.047341]  addrconf_verify_work+0xa/0x20
[  614.047354]  process_one_work+0x214/0x3e0
[  614.047363]  worker_thread+0x4d/0x3d0
[  614.047370]  ? process_one_work+0x3e0/0x3e0
[  614.047377]  kthread+0x133/0x150
[  614.047388]  ? kthread_associate_blkcg+0xc0/0xc0
[  614.047400]  ret_from_fork+0x22/0x30
[  614.047483] INFO: task Qt bearer threa:1650 blocked for more than 245 seconds.
[  614.047488]       Tainted: P           OE     5.12.9-arch1-1 #1
[  614.047492] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  614.047495] task:Qt bearer threa state:D stack:    0 pid: 1650 ppid:  1230 flags:0x00000000
[  614.047504] Call Trace:
[  614.047509]  __schedule+0x2ff/0x8b0
[  614.047522]  schedule+0x5b/0xc0
[  614.047533]  schedule_preempt_disabled+0x11/0x20
[  614.047544]  __mutex_lock.constprop.0+0x367/0x550
[  614.047558]  ? __netlink_lookup+0xc8/0x100
[  614.047570]  __netlink_dump_start+0xc2/0x2d0
[  614.047581]  ? rtnl_fill_ifinfo+0x13d0/0x13d0
[  614.047592]  rtnetlink_rcv_msg+0x298/0x3a0
[  614.047601]  ? rtnl_fill_ifinfo+0x13d0/0x13d0
[  614.047611]  ? rtnl_calcit.isra.0+0x150/0x150
[  614.047620]  netlink_rcv_skb+0x5b/0x100
[  614.047633]  netlink_unicast+0x23e/0x350
[  614.047645]  netlink_sendmsg+0x23a/0x470
[  614.047658]  sock_sendmsg+0x5e/0x60
[  614.047670]  __sys_sendto+0x124/0x190
[  614.047689]  __x64_sys_sendto+0x20/0x30
[  614.047700]  do_syscall_64+0x33/0x40
[  614.047712]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  614.047722] RIP: 0033:0x7f10dc8a0bac
[  614.047731] RSP: 002b:00007f1087ffd4d0 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[  614.047741] RAX: ffffffffffffffda RBX: 0000000000000015 RCX: 00007f10dc8a0bac
[  614.047747] RDX: 0000000000000020 RSI: 00007f1087ffd560 RDI: 0000000000000015
[  614.047752] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[  614.047757] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f1087ffd628
[  614.047762] R13: 00007f1087ffd530 R14: 00007f10aa87a490 R15: 0000000000000001
[  614.047799] INFO: task DNS Resolver #2:2074 blocked for more than 245 seconds.
[  614.047804]       Tainted: P           OE     5.12.9-arch1-1 #1
[  614.047808] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  614.047811] task:DNS Resolver #2 state:D stack:    0 pid: 2074 ppid:  1248 flags:0x00000000
[  614.047819] Call Trace:
[  614.047823]  __schedule+0x2ff/0x8b0
[  614.047837]  schedule+0x5b/0xc0
[  614.047847]  schedule_preempt_disabled+0x11/0x20
[  614.047858]  __mutex_lock.constprop.0+0x367/0x550
[  614.047872]  ? __netlink_lookup+0xc8/0x100
[  614.047883]  __netlink_dump_start+0xc2/0x2d0
[  614.047893]  ? rtnl_fill_link_ifmap+0xa0/0xa0
[  614.047902]  rtnetlink_rcv_msg+0x298/0x3a0
[  614.047910]  ? rtnl_fill_link_ifmap+0xa0/0xa0
[  614.047918]  ? rtnl_calcit.isra.0+0x150/0x150
[  614.047926]  netlink_rcv_skb+0x5b/0x100
[  614.047939]  netlink_unicast+0x23e/0x350
[  614.047950]  netlink_sendmsg+0x23a/0x470
[  614.047963]  sock_sendmsg+0x5e/0x60
[  614.047974]  __sys_sendto+0x124/0x190
[  614.047992]  __x64_sys_sendto+0x20/0x30
[  614.048003]  do_syscall_64+0x33/0x40
[  614.048013]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  614.048020] RIP: 0033:0x7fdda3427dc4
[  614.048025] RSP: 002b:00007fdd85954f70 EFLAGS: 00000293 ORIG_RAX: 000000000000002c
[  614.048033] RAX: ffffffffffffffda RBX: 00007fdd859560a0 RCX: 00007fdda3427dc4
[  614.048038] RDX: 0000000000000014 RSI: 00007fdd859560a0 RDI: 000000000000002a
[  614.048042] RBP: 0000000000000000 R08: 00007fdd85956044 R09: 000000000000000c
[  614.048046] R10: 0000000000000000 R11: 0000000000000293 R12: 00007fdd85956044
[  614.048051] R13: 00000000bfb4ddc5 R14: 000000000000002a R15: 0000000000000000
[  616.517538] audit: type=1131 audit(1623589724.290:263): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[  940.586079] audit: type=1130 audit(1623590048.396:264): 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'
[  940.586087] audit: type=1131 audit(1623590048.396:265): 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'

Offline

#12 2021-06-13 15:32:46

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

The context looks routing/filtering related…
Wild guess: disable docker & f@h and reboot - can you terminate wpa_supplicant now?

Though ultimately it's likely pipewire :-P

Online

#13 2021-06-13 17:48:22

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

Disabling docker and f@h did not help. Thinking about pipewire, I have a feeling that I first started to notice such problems some time around the switch to pipewire so it might be related. However, I disabled everything pipewire but wpa_supplicant still refuses to terminate when asked.

Offline

#14 2021-06-18 20:41:21

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

Can you

wpa_cli logoff
wpa_cli terminate

?
(and terminate wpa_supplicant afterwards?)

If you cannot sort this out, you may want to look into iwd as weorkaround.

Online

#15 2021-06-20 14:24:25

zegkljan
Member
Registered: 2017-12-30
Posts: 60

Re: wpa_supplicant service does not stop

Nope, still hangs the same way.

I know about iwd but I'd rather solve the problem. It did not happen before and it does happen now. So it has to be either a hardware problem (which I doubt since iwd works just fine from the little I tried before starting this issue) or a software problem. If it's a software problem, then it has to be either a bug, a configuration problem, or something regarding interaction with other subsystems. I doubt it is a bug (because more people would be complaining, I think). So something is probably wrong on my system.

I'm considering getting rid of everything wpa_supplicant and network manager related and reinstalling those from scratch. Or maybe reinstalling whole arch from scratch but that is only the last option.

Offline

#16 2021-06-20 14:28:00

seth
Member
Registered: 2012-09-03
Posts: 49,985

Re: wpa_supplicant service does not stop

You could try the lts kernel (to avoid the downgrade hassle) to see whether it's a regression in the kernel/module.

Online

Board footer

Powered by FluxBB