GNU bug report logs - #35550
Installer: wpa_supplicant fails to start

Previous Next

Full log

Message #8 received at 35550 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: 35550 <at> debbugs.gnu.org
Cc: Ricardo Wurmus <rekado <at> elephly.net>, sirgazil <sirgazil <at> zoho.com>
Subject: Re: bug#35550: Installer: wpa_supplicant fails to start
Date: Fri, 03 May 2019 22:51:31 +0200

Ludovic Courtès <ludo <at> gnu.org> skribis:

> 678 May  3 16:03:40 localhost vmunix: [   10.221211] shepherd[1]: Service dbus-system has been started.
> 679 May  3 16:03:40 localhost vmunix: [   10.222093] shepherd[1]: Service loopback has been started.
> 680 May  3 16:03:40 localhost wpa_supplicant[398]: Successfully initialized wpa_supplicant
> 681 May  3 16:03:40 localhost shepherd[1]: Service wpa-supplicant could not be started.
> 682 May  3 16:03:40 localhost shepherd[1]: Service networking depends on wpa-supplicant.
> 683 May  3 16:03:40 localhost shepherd[1]: Service networking could not be started.
> 684 May  3 16:03:40 localhost wpa_supplicant[400]: dbus: Could not request service name: already registered
> 685 May  3 16:03:40 localhost wpa_supplicant[400]: Failed to initialize wpa_supplicant
> 686 May  3 16:03:45 localhost shepherd[1]: Service wpa-supplicant could not be started.

My guess is that it goes like this:

  1. shepherd starts ‘networking’, which triggers the start of
     ‘wpa-supplicant’ (PID 398), which immediately “fails”.  Thus
     ‘networking’ is not started.

  2. shepherd continues and starts ‘wpa-supplicant’ directly (PID 400).
     This time it fails for good; after 5 seconds, since the PID file
     didn’t show up, shepherd says again that it could not be started.

Indeed, by looking at shepherd.conf from:

  guix gc -R $(guix system build gnu/system/install.scm) | grep shepherd.conf

one can see that ‘networking’ comes before ‘wpa-supplicant’ in the expression:

  (for-each start '(… networking … wpa-supplicant …))

So why is ‘wpa-supplicant’ marked as failing to start on the first
attempt?

The only reason I can think of is if ‘read-pid-file’ from (shepherd
service) returns immediately and returns #f instead of a number.  That
can actually happen if the PID file exists but is empty (or contains
garbage).

You would expect wpa_supplicant to create its PID file atomically: write
it under a different name, then rename(2)… but no:

--8<---------------cut here---------------start------------->8---
int os_daemonize(const char *pid_file)
{
#if defined(__uClinux__) || defined(__sun__)
	return -1;
#else /* defined(__uClinux__) || defined(__sun__) */
	if (os_daemon(0, 0)) {
		perror("daemon");
		return -1;
	}

	if (pid_file) {
		FILE *f = fopen(pid_file, "w");
		if (f) {
			fprintf(f, "%u\n", getpid());
			fclose(f);
		}
	}

	return -0;
#endif /* defined(__uClinux__) || defined(__sun__) */
}
--8<---------------cut here---------------end--------------->8---

So there is a possibility, albeit unlikely, for shepherd to see the PID
file after it’s been open but before it’s been written to.  (This
problem is not limited to the installer.)

I’m not 100% convinced that this is what’s happening there but that’s
the only lead I have.  I’m surprised we haven’t seen other reports
before.

Thoughts?

Ludo’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.