Package: ifupdown
Version: 0.8.41
Severity: normal
X-Debbugs-Cc: aa...@bugher.net
Dear Maintainer,
I use ifup to connect to various wifi networks. It is successful at my home
and at most locations. I see the following problem on one network and no
others. Others on the same network (on various non-Debian-like platforms)
report no such problem.
When I use ifup to connect to "michiganders", after output indicates DHCP
succeeds, output indicates wpa_supplicant has failed. The interface gets an
address briefly (visible in i3 status bar), but there is no address configured
after ifup exits. syslog from that time indicates two instances of
wpa_supplicant get started rapidly, and at least one of them notices the
concurrency and gets unhappy about that.
When I configure the same interface to use a static address on the same
network, ifup still fails. syslog indicates multiple wpa_supplicant instances,
again. Running ifup one more time, though, causes different output. The
second run still returns a failure code, but the network comes up and I can use
it. syslog from that time does not show the lines about multiple
wpa_supplicant instances.
Some quick web searches are telling me that this can happen on systems that
have been through a major OS version upgrade, specifically Jessie to Stretch.
I am currently on Devuan 5, Daedalus. I think the install date was more recent
than Stretch (or ASCII), but the system has probably gone through a Chimaera to
Daedalus uprade.
It also looked like a common cause of this type of issue is that the DHCP
client starts a second wpa_supplicant instance, in addition to the one started
by ifup. Since I can observe similar results with a static address, I am
guessing that is not the specific problem in this case.
Situational note: I am visiting the home of the problematic network, right
now. I can make further observations while I am here. Soon I will head home,
and I won't be back here for at least a few months. I may take a long time to
answer questions.
Netwok name: michiganders
Access point: Google home with mesh nodes (set up by others)
Client hardware: ThinkPad T530, Wireless-N 2200 (rev c4)
Client OS: Devuan 5 (Daedalus)
ifupdown configuration:
0 aaron@mawg:~/notes/ifupdown_bug$ sudo grep -vE 'passphrase|^#'
/etc/network/interfaces.d/michiganders
iface michiganders inet dhcp
wpa-essid michiganders
iface michiganders-static inet static
wpa-essid michiganders
address 192.168.86.69
gateway 192.168.86.1
dns-nameservers 8.8.8.8 8.8.4.4
0 aaron@mawg:~/notes/ifupdown_bug$
ifup running and calling dhclient:
0 aaron@mawg:~/notes/ifupdown_bug$ sudo ifup wlan0=michiganders
Internet Systems Consortium DHCP Client 4.4.3-P1
Copyright 2004-2022 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/
Listening on LPF/wlan0/9c:4e:36:c0:d6:00
Sending on LPF/wlan0/9c:4e:36:c0:d6:00
Sending on Socket/fallback
DHCPREQUEST for 192.168.86.43 on wlan0 to 255.255.255.255 port 67
DHCPREQUEST for 192.168.86.43 on wlan0 to 255.255.255.255 port 67
DHCPACK of 192.168.86.43 from 192.168.86.1
bound to 192.168.86.43 -- renewal in 33316 seconds.
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 michiganders
1 aaron@mawg:~/notes/ifupdown_bug$
syslog excerpt from that time (tail -F /var/log/syslog | grep wpa_supplicant):
2024-03-27T18:56:06.370732-04:00 mawg wpa_supplicant[23214]: Successfully
initialized wpa_supplicant
2024-03-27T18:56:06.428755-04:00 mawg wpa_supplicant[23111]: wlan0:
CTRL-EVENT-DISCONNECTED bssid=cc:f4:11:7a:c3:cd reason=3 locally_generated=1
2024-03-27T18:56:06.428983-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429014-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429037-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429052-04:00 mawg wpa_supplicant[23111]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:56:06.429059-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429081-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429102-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429143-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429164-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429215-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429238-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429286-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429312-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429334-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429355-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429403-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429436-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429457-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429477-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429498-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429518-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429579-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429599-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429619-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429641-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429663-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429684-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.429738-04:00 mawg wpa_supplicant[23214]: nl80211: kernel
reports: Match already configured
2024-03-27T18:56:06.463444-04:00 mawg wpa_supplicant[23214]: ctrl_iface exists
and seems to be in use - cannot override it
2024-03-27T18:56:06.463451-04:00 mawg wpa_supplicant[23214]: Delete
'/run/wpa_supplicant/wlan0' manually if it is not used anymore
2024-03-27T18:56:06.463472-04:00 mawg wpa_supplicant[23214]: Failed to
initialize control interface '/run/wpa_supplicant'.#012You may have another
wpa_supplicant process already running or the file was#012left by an unclean
termination of wpa_supplicant in which case you will need#012to manually remove
this file before starting wpa_supplicant again.
2024-03-27T18:56:06.463595-04:00 mawg wpa_supplicant[23214]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:56:06.476370-04:00 mawg wpa_supplicant[23111]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:56:06.476395-04:00 mawg wpa_supplicant[23111]: nl80211: deinit
ifname=wlan0 disabled_11b_rates=0
2024-03-27T18:56:06.476625-04:00 mawg wpa_supplicant[23111]: wlan0:
CTRL-EVENT-TERMINATING
2024-03-27T18:56:06.508469-04:00 mawg wpa_supplicant[23214]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:56:06.508523-04:00 mawg wpa_supplicant[23214]: nl80211: deinit
ifname=wlan0 disabled_11b_rates=0
ifup running and configuring a static address (first try):
0 aaron@mawg:~/notes/ifupdown_bug$ sudo ifup wlan0=michiganders-static
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 michiganders-static
1 aaron@mawg:~/notes/ifupdown_bug$
syslog excerpt from that time:
2024-03-27T18:48:28.889321-04:00 mawg wpa_supplicant[22387]: Successfully
initialized wpa_supplicant
2024-03-27T18:48:28.979488-04:00 mawg wpa_supplicant[22388]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:48:28.983438-04:00 mawg wpa_supplicant[22472]: Successfully
initialized wpa_supplicant
2024-03-27T18:48:28.983923-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.983947-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.983968-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984061-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984089-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984107-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984124-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984167-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984190-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984234-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984277-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984318-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984340-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984384-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984404-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984423-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984442-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984461-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984481-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984501-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984522-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984543-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984562-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984582-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984601-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984622-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:28.984644-04:00 mawg wpa_supplicant[22472]: nl80211: kernel
reports: Match already configured
2024-03-27T18:48:29.015338-04:00 mawg wpa_supplicant[22472]: ctrl_iface exists
and seems to be in use - cannot override it
2024-03-27T18:48:29.015344-04:00 mawg wpa_supplicant[22472]: Delete
'/run/wpa_supplicant/wlan0' manually if it is not used anymore
2024-03-27T18:48:29.015356-04:00 mawg wpa_supplicant[22472]: Failed to
initialize control interface '/run/wpa_supplicant'.#012You may have another
wpa_supplicant process already running or the file was#012left by an unclean
termination of wpa_supplicant in which case you will need#012to manually remove
this file before starting wpa_supplicant again.
2024-03-27T18:48:29.015526-04:00 mawg wpa_supplicant[22472]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:48:29.024312-04:00 mawg wpa_supplicant[22388]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:48:29.024335-04:00 mawg wpa_supplicant[22388]: nl80211: deinit
ifname=wlan0 disabled_11b_rates=0
2024-03-27T18:48:29.024580-04:00 mawg wpa_supplicant[22388]: wlan0:
CTRL-EVENT-TERMINATING
2024-03-27T18:48:29.068301-04:00 mawg wpa_supplicant[22472]: wlan0:
CTRL-EVENT-DSCP-POLICY clear_all
2024-03-27T18:48:29.068312-04:00 mawg wpa_supplicant[22472]: nl80211: deinit
ifname=wlan0 disabled_11b_rates=0
ifup running and configuring a static address (second try):
1 aaron@mawg:~/notes/ifupdown_bug$ sudo ifup wlan0=michiganders-static
RTNETLINK answers: File exists
ifup: failed to bring up michiganders-static
1 aaron@mawg:~/notes/ifupdown_bug$ # Command failed but network is online.
syslog excerpt from that time:
2024-03-27T18:48:35.663368-04:00 mawg wpa_supplicant[22489]: Successfully
initialized wpa_supplicant
2024-03-27T18:48:36.229024-04:00 mawg wpa_supplicant[22490]: wlan0: SME: Trying
to authenticate with cc:f4:11:7a:c3:cd (SSID='michiganders' freq=2462 MHz)
2024-03-27T18:48:36.236763-04:00 mawg wpa_supplicant[22490]: wlan0: Trying to
associate with cc:f4:11:7a:c3:cd (SSID='michiganders' freq=2462 MHz)
2024-03-27T18:48:36.283847-04:00 mawg wpa_supplicant[22490]: wlan0: Associated
with cc:f4:11:7a:c3:cd
2024-03-27T18:48:36.284623-04:00 mawg wpa_supplicant[22490]: wlan0:
CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
2024-03-27T18:48:36.328399-04:00 mawg wpa_supplicant[22490]: wlan0: WPA: Key
negotiation completed with cc:f4:11:7a:c3:cd [PTK=CCMP GTK=CCMP]
2024-03-27T18:48:36.328472-04:00 mawg wpa_supplicant[22490]: wlan0:
CTRL-EVENT-CONNECTED - Connection to cc:f4:11:7a:c3:cd completed [id=0 id_str=]
-- Package-specific info:
--- /etc/network/interfaces:
cat: /etc/network/interfaces: Permission denied
/usr/share/bug/ifupdown: 20: cannot open /etc/network/interfaces: Permission
denied
--- up and down scripts installed:
/etc/network/if-down.d:
total 4
-rwxr-xr-x 1 root root 759 Sep 27 2022 resolved
lrwxrwxrwx 1 root root 32 Feb 24 2023 wpasupplicant ->
../../wpa_supplicant/ifupdown.sh
/etc/network/if-post-down.d:
total 4
lrwxrwxrwx 1 root root 25 Oct 19 2021 hostapd -> ../../hostapd/ifupdown.sh
-rwxr-xr-x 1 root root 1409 Jun 5 2018 wireless-tools
lrwxrwxrwx 1 root root 32 Feb 24 2023 wpasupplicant ->
../../wpa_supplicant/ifupdown.sh
/etc/network/if-pre-up.d:
total 12
-rwxr-xr-x 1 root root 344 Jun 30 2016 ethtool
lrwxrwxrwx 1 root root 25 Oct 19 2021 hostapd -> ../../hostapd/ifupdown.sh
-rwxr-xr-x 1 root root 4191 Sep 15 2018 wireless-tools
lrwxrwxrwx 1 root root 32 Feb 24 2023 wpasupplicant ->
../../wpa_supplicant/ifupdown.sh
/etc/network/if-up.d:
total 24
-rwxr-xr-x 1 root root 1685 Jun 30 2016 ethtool
-rwxr-xr-x 1 root root 4938 Oct 19 2021 mountnfs
-rwxr-xr-x 1 root root 198 Oct 16 2022 openntpd
-rwxr-xr-x 1 root root 4663 Sep 27 2022 resolved
lrwxrwxrwx 1 root root 32 Feb 24 2023 wpasupplicant ->
../../wpa_supplicant/ifupdown.sh
-- System Information:
Debian Release: 12.0
merged-usr: no
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 6.1.0-18-amd64 (SMP w/4 CPU threads; PREEMPT)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)
LSM: AppArmor: enabled
Versions of packages ifupdown depends on:
ii adduser 3.134
ii iproute2 6.1.0-3
ii libc6 2.36-9+deb12u4
Versions of packages ifupdown recommends:
ii isc-dhcp-client [dhcp-client] 4.4.3-P1-2
Versions of packages ifupdown suggests:
pn ppp <none>
pn rdnssd <none>
-- no debconf information
