Table of Contents
Raspberry Pi problem: dhcpcd not starting wpa_supplicant
I got a problem with a Realtek RTL8188EUS UBS WiFi dongle, into a Raspberry Pi Model A+, running Rasbpian 2017-11-29 Stretch Lite (based on Debian 9.1).
The new method used by Raspbian to configure the network interfaces involves dhcpcd, so the /etc/network/interfaces should be almost empty, with just the following:
source-directory /etc/network/interfaces.d
There are no allow-hotplug or auto sections anymore; everything should be managed by dhcpcd, even the start of wpa_supplicant. Which indeed was failing.
First of all I added some debug to dhcpcd: just adding the option -d to the dhcpcd ExecStart into /etc/systemd/system/dhcpcd.service.d/wait.conf. After executing systemctl daemon-reload and a reboot, this was the log:
daemon.debug dhcpcd[772]: dhcpcd-6.11.5 starting daemon.debug dhcpcd[772]: udev: starting daemon.info dhcpcd[772]: dev: loaded udev daemon.debug dhcpcd[772]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT daemon.debug dhcpcd[772]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER daemon.info dhcpcd[772]: wlan0: waiting for carrier daemon.err dhcpcd[772]: timed out daemon.debug dhcpcd[772]: forking to background
So no wpa_supplicant was fired, the wlan0 interface does not sense the carrier and dhcpcd refuses to configure it. It seems that dhcpcd does not aknowledge that it is a WiFi adapter, so we have to force it. Just add an interface section into /etc/dhcpcd.conf:
interface wlan0 env ifwireless=1 env wpa_supplicant_driver=nl80211,wext
the driver specification is required, otherwise wpa_supplicant will die with the error message
nl80211: Driver does not support authentication/association or connect commands nl80211: deinit ifname=wlan0 disabled_11b_rates=0 wlan0: Failed to initialize driver interface
After a reboot everything worked as expected, which is confirmed by the wpa_supplicant process running:
wpa_supplicant -B -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 -Dnl80211,wext
Notice that the configuration file used is /etc/wpa_supplicant/wpa_supplicant.conf, but if one named wpa_supplicant-wlan0.conf exists, it will be preferred.
Alternative: wpa_supplicant started by systemd
The default is to start wpa_supplicant via dhcpcd, as seen above. But if you want, you can force systemd to start the service independently.
You have to start the interface-specific service against the name wlan0, so make the following:
mv /etc/wpa_supplicant/wpa_supplicant.conf /etc/wpa_supplicant/wpa_supplicant-wlan0.conf systemctl enable wpa_supplicant@wlan0.service
After a reboot you should see the wpa_supplicant process running, and dhcpcd will configure wlan0 happily.
dhcpcd process dies without configuring wlan0
This is a similar problem encountered on a Raspberry Pi Model B Rev 2 running Raspbian GNU/Linux 11 Bullseye. The wlan0 interface is an USB dongle Realtek RTL8188CUS, the eth0 interface is not used and dhcpcd is instructed to ignore it (via the denyinterfaces eth0
option in /etc/dhcpcd.conf).
At first I decided to disable the Systemd wpa_supplicant.service and let dhcpcd to manage the interface starting wpa_supplicant on its own, as seen above. Suddendly the system started to have random problems on bootstrap: sometimes the host resulted having the wpa_supplicant process running (lanched by dhcpcd), but the dhcpcd process itself was die and did not configured the IP address on the wlan0 interface.
To trace the problem I had to enable the debugging option of dhcpcd, adding the -d parameter in /etc/systemd/system/dhcpcd.service.d/wait.conf; the log can be read with journalctl -b -t dhcpcd.
A typical log when the problem arises is the following:
Nov 15 00:17:48 rpi dhcpcd[255]: dhcpcd-8.1.2 starting Nov 15 00:17:48 rpi dhcpcd[255]: udev: starting Nov 15 00:17:48 rpi dhcpcd[255]: dev: loaded udev Nov 15 00:17:53 rpi dhcpcd[255]: no valid interfaces found Nov 15 00:17:53 rpi dhcpcd[255]: lo: libudev: add Nov 15 00:18:00 rpi dhcpcd[255]: eth0: libudev: add Nov 15 00:18:13 rpi dhcpcd[255]: wlan0: libudev: add Nov 15 00:18:13 rpi dhcpcd[255]: wlan0: interface added Nov 15 00:18:13 rpi dhcpcd[255]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT Nov 15 00:18:13 rpi dhcpcd[443]: wlan0: starting wpa_supplicant Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: connected to Access Point `' Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: waiting for carrier Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: carrier acquired Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER Nov 15 00:18:22 rpi dhcpcd[255]: DUID 00:01:00:01:29:0f:e9:4b:e8:4e:06:0e:08:90 Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: IAID 02:f5:16:df Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: adding address fe80::ae69:a5aa:2c1d:2190 Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: pltime infinity, vltime infinity Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: delaying IPv6 router solicitation for 0.5 seconds Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: delaying IPv4 for 0.5 seconds Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: carrier lost Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: delaying IPv6 router solicitation for 0.5 seconds Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: delaying IPv4 for 0.5 seconds Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: carrier lost Nov 15 00:18:22 rpi dhcpcd[255]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER Nov 15 00:18:23 rpi dhcpcd[255]: wlan0: deleting address fe80::ae69:a5aa:2c1d:2190 Nov 15 00:18:23 rpi dhcpcd[255]: timed out Nov 15 00:18:23 rpi dhcpcd[255]: forking to background Nov 15 00:18:23 rpi dhcpcd[478]: main: eloop_start: Invalid argument Nov 15 00:18:23 rpi dhcpcd[478]: dev: unloaded udev Nov 15 00:18:23 rpi dhcpcd[478]: dhcpcd exited Nov 15 00:18:23 rpi dhcpcd[255]: forked to background, child pid 478
The error that causes dhcpcd to die is eloop_start: Invalid argument; it happens after that dhcpcd has forked. The wlan0 interface instead is activated by dhcpcd launching an instance of wpa_suppplicant before forking. The forked process is probably working with an invalid interface descriptor (see this post dhcpcd Intermittently Fails).
It results that wlan0 gets a sqeuence of wlan0: carrier acquired
and wlan0: carrier lost
, after that the fatal error main: eloop_start: Invalid argument kills dhcpcd. Maybe this problem is triggered by the autoconfiguration of IPv6.
I solved the problem by letting Systemd to start wpa_supplicant on the specific wlan0 interface. This is achieved renaming the wpa_supplicant.conf file and enabling only the interface-specific version service:
mv /etc/wpa_supplicant/wpa_supplicant.conf /etc/wpa_supplicant/wpa_supplicant-wlan0.conf systemctl enable wpa_supplicant@wlan0.service systemctl disable wpa_supplicant.service
At reboot, dhcpcd will fail to start its own instance of wpa_supplicant on the same device, as seen in the following debug log:
dhcpcd[415]: wlan0: Successfully initialized wpa_supplicant dhcpcd[415]: nl80211: kernel reports: Match already configured dhcpcd[415]: ctrl_iface exists and seems to be in use - cannot override it dhcpcd[415]: Delete '/var/run/wpa_supplicant/wlan0' manually if it is not used anymore dhcpcd[415]: Failed to initialize control interface 'DIR=/var/run/wpa_supplicant GROUP=netdev'. dhcpcd[415]: You may have another wpa_supplicant process already running or the file was dhcpcd[415]: left by an unclean termination of wpa_supplicant in which case you will need dhcpcd[415]: to manually remove this file before starting wpa_supplicant again. dhcpcd[415]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Nevertehless dhcpcd is informed by udev when the wlan0 interface is activated and then it can configure it using DHCP.
NOTICE: The default systemd configuration shipped with Raspbian 11 Bullseye does not ensure that the wpa_supplicant@..service is started before dhcpcd.service, thus ensuring that the above startup sequence is respected. You can generate the SVG graphic detailing which system services have been started at what time using the command:
systemd-analyze plot > services-start-graph.svg
Indeed you can see that dhcpcd.service becomes active after the wpa_supplicant@wlan0.service, but nothing is ensuring this behaviour. We should actually customize the dhcpcd.service unit adding an After=wpa_supplicant@..service option. For this purpose we use the command systemctl edit:
systemctl edit dhcpcd.service
this will launch an editor to create the file /etc/systemd/system/dhcpcd.service.d/override.conf; this is a drop-in snippet to extend or override the definition of the unit. Here we write:
[Unit] After=wpa_supplicant@..service
The systemd daemon will be automatically reloaded, se we can reboot.