[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

wpa_supplicant, was Re: iwd + systemd-networkd + resolvconf wrinkles



On Sat 19 Mar 2022 at 10:18:49 (+1100), Charlie wrote:
> On Fri, 18 Mar 2022 14:32:40 +0000 Brian wrote:
> 
> > Regarding the installer: at present it provides an /e/n/i with wpa-*
> > lines. Changing wpasupplicant to iwd in d-i would requir some work.
> > No matter what the benefits of iwd are, I do not see that happening
> > in the near future. wpasupplicant remians as useful as it always has
> > been.

It wasn't my intention to suggest displacing /e/n/i&wpa from the d-i.
I only mentioned it to point out (a) that installing iwd is a
conversion process if the d-i has been run wirelessly, and (b) that
I know next to nothing about configuring or running wpa_supplicant
because wicd just took care of it all.

> Interesting, because I have always used wpasupplicant but since
> Bullseye has gone stable, have had this happen quite frequently:
> 
> root@wilder:~# ifup wlp2s0
> wpa_supplicant: /sbin/wpa_supplicant daemon failed to start
> run-parts: /etc/network/if-pre-up.d/wpasupplicant exited with return
> code 1 ifup: failed to bring up wlp2s0

It would be interesting to know why your wlp2s0 failed to come up.

For one of my systems in particular, it fails because the wifi
happens to be hard-blocked when the system boots. It's very
simple to unblock it: just by pressing a button on the front edge
of the keyboard. (What a design cock-up.)

Unfortunately, using systemd-networkd/ifupdown/wpa_s (and
sysv/ifupdown/wpa_s in the past), it's not clear to me
who's responsible for cranking up the network after I've
pressed that button.

(OTOH wicd appears to be able to detect that the interface has come
up, and to configure it, DHCP and all. In fact, I've found it more
reliable for wired interfaces as well, where I suspect glitches have
been caused by Powerline devices (ethernet through the mains power).)

So here's an illustration of the symptoms, starting with booting up
in a hard-blocked state:

$ sudo rfkill
ID TYPE DEVICE      SOFT    HARD
 0 wlan phy0   unblocked blocked
$ 

$ systemctl status wpa_supplicant.service --no-pager -l
● wpa_supplicant.service - WPA supplicant
     Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2022-03-22 14:19:41 CDT; 11min ago
   Main PID: 464 (wpa_supplicant)
      Tasks: 1 (limit: 1108)
     Memory: 572.0K
        CPU: 15ms
     CGroup: /system.slice/wpa_supplicant.service
             └─464 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant

Mar 22 14:19:35 acer systemd[1]: Starting WPA supplicant...
Mar 22 14:19:41 acer wpa_supplicant[464]: Successfully initialized wpa_supplicant
Mar 22 14:19:41 acer systemd[1]: Started WPA supplicant.
$ 

So wpa_s is happy, and remains that way throughout. I won't quote it again.

$ systemctl status ifup@wlp2s4.service --no-pager -l
● ifup@wlp2s4.service - ifup for wlp2s4
     Loaded: loaded (/lib/systemd/system/ifup@.service; static)
     Active: failed (Result: exit-code) since Tue 2022-03-22 14:20:40 CDT; 10min ago
    Process: 372 ExecStart=/bin/sh -ec ifup --allow=hotplug wlp2s4; ifquery --state wlp2s4 (code=exited, status=1/FAILURE)
   Main PID: 372 (code=exited, status=1/FAILURE)
        CPU: 277ms

Mar 22 14:20:40 acer sh[473]: No working leases in persistent database - sleeping.
Mar 22 14:20:40 acer dhclient[473]: No working leases in persistent database - sleeping.
Mar 22 14:20:40 acer avahi-autoipd(wlp2s4)[532]: SIOCSIFFLAGS failed: Operation not possible due to RF-kill
Mar 22 14:20:40 acer root[534]: /etc/dhcp/dhclient-exit-hooks.d/zzz_avahi-autoipd returned non-zero exit status 1
Mar 22 14:20:40 acer sh[540]: Error: Device for nexthop is not up.
Mar 22 14:20:40 acer sh[536]: run-parts: /etc/network/if-up.d/avahi-autoipd exited with return code 2
Mar 22 14:20:40 acer systemd[1]: ifup@wlp2s4.service: Main process exited, code=exited, status=1/FAILURE
Mar 22 14:20:40 acer sh[373]: ifup: failed to bring up wlp2s4
Mar 22 14:20:40 acer wpa_supplicant[429]: wlp2s4: CTRL-EVENT-TERMINATING
Mar 22 14:20:40 acer systemd[1]: ifup@wlp2s4.service: Failed with result 'exit-code'.
3 $ 

It tried, failed, gave up. (The little 3 before the prompt is the value of $?)

$ systemctl status systemd-networkd.service --no-pager -l
● systemd-networkd.service - Network Service
     Loaded: loaded (/lib/systemd/system/systemd-networkd.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2022-03-22 14:19:21 CDT; 11min ago
TriggeredBy: ● systemd-networkd.socket
       Docs: man:systemd-networkd.service(8)
   Main PID: 224 (systemd-network)
     Status: "Processing requests..."
      Tasks: 1 (limit: 1108)
     Memory: 3.3M
        CPU: 200ms
     CGroup: /system.slice/systemd-networkd.service
             └─224 /lib/systemd/systemd-networkd

Mar 22 14:19:19 acer systemd[1]: Starting Network Service...
Mar 22 14:19:21 acer systemd-networkd[224]: Enumeration completed
Mar 22 14:19:21 acer systemd[1]: Started Network Service.
Mar 22 14:19:27 acer systemd-networkd[224]: eth0: Interface name change detected, eth0 has been renamed to wlp2s4.
Mar 22 14:19:28 acer systemd-networkd[224]: wlp2s4: Could not bring up interface: Operation not possible due to RF-kill
$ 

So it's running, but apparently not watching, because when I press
the button …

$ sudo rfkill
ID TYPE DEVICE      SOFT      HARD
 0 wlan phy0   unblocked unblocked
$ 

… that "unblocked" is the only change that happens. None of the three
statuses above shows any difference. So, I type …

# systemctl restart systemd-networkd.service
# 

… and the only status above that changes is:

$ systemctl status systemd-networkd.service --no-pager -l
● systemd-networkd.service - Network Service
     Loaded: loaded (/lib/systemd/system/systemd-networkd.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2022-03-22 14:47:50 CDT; 1min 53s ago
TriggeredBy: ● systemd-networkd.socket
       Docs: man:systemd-networkd.service(8)
   Main PID: 2414 (systemd-network)
     Status: "Processing requests..."
      Tasks: 1 (limit: 1108)
     Memory: 2.6M
        CPU: 123ms
     CGroup: /system.slice/systemd-networkd.service
             └─2414 /lib/systemd/systemd-networkd

Mar 22 14:47:50 acer systemd[1]: Starting Network Service...
Mar 22 14:47:50 acer systemd-networkd[2414]: Enumeration completed
Mar 22 14:47:50 acer systemd[1]: Started Network Service.
Mar 22 14:47:50 acer systemd-networkd[2414]: wlp2s4: Link UP
$ 

I thought systemd-networkd might happen to prod ifupdown into action,
but it doesn't. So I type …

# systemctl restart ifup@wlp2s4.service
# 

… which results in …

$ systemctl status ifup@wlp2s4.service --no-pager -l
● ifup@wlp2s4.service - ifup for wlp2s4
     Loaded: loaded (/lib/systemd/system/ifup@.service; static)
     Active: active (exited) since Tue 2022-03-22 14:49:31 CDT; 19s ago
    Process: 2489 ExecStart=/bin/sh -ec ifup --allow=hotplug wlp2s4; ifquery --state wlp2s4 (code=exited, status=0/SUCCESS)
   Main PID: 2489 (code=exited, status=0/SUCCESS)
      Tasks: 5 (limit: 1108)
     Memory: 6.5M
        CPU: 311ms
     CGroup: /system.slice/ifup@wlp2s4.service
             ├─2501 /sbin/wpa_supplicant -s -B -P /run/wpa_supplicant.wlp2s4.pid -i wlp2s4 -D nl80211,wext -C /run/wpa_supplicant
             └─2514 /sbin/dhclient -4 -v -i -pf /run/dhclient.wlp2s4.pid -lf /var/lib/dhcp/dhclient.wlp2s4.leases -I -df /var/lib/dhcp/dhclient6.wlp2s4.leases wlp2s4

Mar 22 14:49:33 acer dhclient[2514]: Sending on   LPF/wlp2s4/00:11:22:33:44:55
Mar 22 14:49:33 acer dhclient[2514]: Sending on   Socket/fallback
Mar 22 14:49:33 acer dhclient[2514]: DHCPDISCOVER on wlp2s4 to 255.255.255.255 port 67 interval 3
Mar 22 14:49:33 acer sh[2514]: DHCPACK of 192.168.1.10 from 192.168.1.1
Mar 22 14:49:33 acer dhclient[2514]: DHCPOFFER of 192.168.1.10 from 192.168.1.1
Mar 22 14:49:33 acer dhclient[2514]: DHCPREQUEST for 192.168.1.10 on wlp2s4 to 255.255.255.255 port 67
Mar 22 14:49:33 acer dhclient[2514]: DHCPACK of 192.168.1.10 from 192.168.1.1
Mar 22 14:49:34 acer dhclient[2514]: bound to 192.168.1.10 -- renewal in 40992 seconds.
Mar 22 14:49:34 acer sh[2514]: bound to 192.168.1.10 -- renewal in 40992 seconds.
Mar 22 14:49:34 acer sh[2564]: wlp2s4=wlp2s4
$ 

… and these three lines are added to the end of the output from
systemctl status systemd-networkd.service …

[ … ]
Mar 22 14:49:33 acer systemd-networkd[2414]: wlp2s4: Gained carrier
Mar 22 14:49:34 acer systemd-networkd[2414]: wlp2s4: DHCPv4 address 192.168.1.10/24 via 192.168.1.1
Mar 22 14:49:35 acer systemd-networkd[2414]: wlp2s4: Gained IPv6LL
$ 

… which gives me networking.

FYI, the configuration files are:

$ cat /etc/network/interfaces.d/wlp2s4 
allow-hotplug wlp2s4
iface wlp2s4  inet dhcp
      wpa-ssid     mySSID
      wpa-key-mgmt WPA-PSK
      wpa-psk      secret
$ 

$ cat /etc/systemd/network/80-wireless.network 
[Match]
Name=wlp2s4
[Network]
DHCP=yes
$ 

What have I missed? Presumably it's something to do with “Interfaces
marked "allow-hotplug" are brought up when udev detects them. This can
either be during boot if the interface is already present, or at a
later time, for example when plugging in a USB network card. Please
note that this does not have anything to do with detecting a network
cable being plugged in.” (man interfaces).

How would I make an unblocking event look like a plugging-in event
to ifupdown?

Cheers,
David.


Reply to: