Wait in libzfs_init() for the /dev/zfs device

While module loading itself is synchronous the creation of the /dev/zfs
device is not.  This is because /dev/zfs is typically created by a udev
rule after the module is registered and presented to user space through
sysfs.  This small window between module loading and device creation
can result in spurious failures of libzfs_init().

This patch closes that race by extending libzfs_init() so it can detect
that the modules are loaded and only if required wait for the /dev/zfs
device to be created.  This allows scripts to reliably use the following
shell construct without the need for additional error handling.

$ /sbin/modprobe zfs && /sbin/zpool import -a

To minimize the potential time waiting in libzfs_init() a strategy
similar to adaptive mutexes is employed.  The function will busy-wait
for up to 10ms based on the expectation that the modules were just
loaded and therefore the /dev/zfs will be created imminently.  If it
takes longer than this it will fall back to polling for up to 10 seconds.

This behavior can be customized to some degree by setting the following
new environment variables.  This functionality is provided for backwards
compatibility with existing scripts which depend on the module auto-load
behavior.  By default module auto-loading is now disabled.

* ZFS_MODULE_LOADING="YES|yes|ON|on" - Attempt to load modules.
* ZFS_MODULE_TIMEOUT="<seconds>"     - Seconds to wait for /dev/zfs

The additional small changes were also made.

* In libzfs_run_process() 'rc' variables was renamed to 'error' for
  consistency with the rest of the code base.

* All fprintf() error messages were moved out of the libzfs_init()
  library function where they never belonged in the first place.  A
  libzfs_error_init() function was added to provide useful error
  messages for the most common causes of failure.

* The zfs-import-* systemd service files have been updated to call
  '/sbin/modprobe zfs' so they no longer rely on the legacy auto-loading
  behavior.

Signed-off-by: Brian Behlendorf <[email protected]>
Issue openzfs#2556

cmd/mount_zfs/mount_zfs.c

@@ -473,8 +473,10 @@ main(int argc, char **argv)
 	if (zfsflags & ZS_ZFSUTIL)
 		zfsutil = 1;
 
-	if ((g_zfs = libzfs_init()) == NULL)
+	if ((g_zfs = libzfs_init()) == NULL) {
+		(void) fprintf(stderr, "%s", libzfs_error_init(errno));
 		return (MOUNT_SYSERR);
+	}
 
 	/* try to open the dataset to access the mount point */
 	if ((zhp = zfs_open(g_zfs, dataset,

cmd/zdb/zdb.c

@@ -3699,8 +3699,10 @@ main(int argc, char **argv)
 	zfs_vdev_async_read_max_active = 10;
 
 	kernel_init(FREAD);
-	if ((g_zfs = libzfs_init()) == NULL)
+	if ((g_zfs = libzfs_init()) == NULL) {
+		(void) fprintf(stderr, "%s", libzfs_error_init(errno));
 		return (1);
+	}
 
 	if (dump_all)
 		verbose = MAX(verbose, 1);

cmd/zfs/zfs_main.c

@@ -6708,8 +6708,10 @@ main(int argc, char **argv)
 	    (strcmp(cmdname, "--help") == 0))
 		usage(B_TRUE);
 
-	if ((g_zfs = libzfs_init()) == NULL)
+	if ((g_zfs = libzfs_init()) == NULL) {
+		(void) fprintf(stderr, "%s", libzfs_error_init(errno));
 		return (1);
+	}
 
 	mnttab_file = g_zfs->libzfs_mnttab;
 

cmd/zinject/zinject.c

@@ -572,8 +572,10 @@ main(int argc, char **argv)
 	int ret;
 	int flags = 0;
 
-	if ((g_zfs = libzfs_init()) == NULL)
+	if ((g_zfs = libzfs_init()) == NULL) {
+		(void) fprintf(stderr, "%s", libzfs_error_init(errno));
 		return (1);
+	}
 
 	libzfs_print_on_error(g_zfs, B_TRUE);
 

cmd/zpool/zpool_main.c

@@ -5919,8 +5919,10 @@ main(int argc, char **argv)
 	if ((strcmp(cmdname, "-?") == 0) || strcmp(cmdname, "--help") == 0)
 		usage(B_TRUE);
 
-	if ((g_zfs = libzfs_init()) == NULL)
+	if ((g_zfs = libzfs_init()) == NULL) {
+		(void) fprintf(stderr, "%s", libzfs_error_init(errno));
 		return (1);
+	}
 
 	libzfs_print_on_error(g_zfs, B_TRUE);
 

etc/systemd/system/zfs-import-cache.service.in

@@ -9,4 +9,4 @@ ConditionPathExists=@sysconfdir@/zfs/zpool.cache
 [Service]
 Type=oneshot
 RemainAfterExit=yes
-ExecStart=@sbindir@/zpool import -c @sysconfdir@/zfs/zpool.cache -aN
+ExecStart=/sbin/modprobe zfs && @sbindir@/zpool import -c @sysconfdir@/zfs/zpool.cache -aN

etc/systemd/system/zfs-import-scan.service.in

@@ -9,4 +9,4 @@ ConditionPathExists=!@sysconfdir@/zfs/zpool.cache
 [Service]
 Type=oneshot
 RemainAfterExit=yes
-ExecStart=@sbindir@/zpool import -d /dev/disk/by-id -aN
+ExecStart=/sbin/modprobe zfs && @sbindir@/zpool import -d /dev/disk/by-id -aN

include/libzfs.h

@@ -203,6 +203,7 @@ extern void zfs_save_arguments(int argc, char **, char *, int);
 extern int zpool_log_history(libzfs_handle_t *, const char *);
 
 extern int libzfs_errno(libzfs_handle_t *);
+extern const char *libzfs_error_init(int);
 extern const char *libzfs_error_action(libzfs_handle_t *);
 extern const char *libzfs_error_description(libzfs_handle_t *);
 extern int zfs_standard_error(libzfs_handle_t *, int, const char *);
@@ -749,7 +750,6 @@ extern int zfs_nicestrtonum(libzfs_handle_t *, const char *, uint64_t *);
 #define	STDERR_VERBOSE	0x02
 
 int libzfs_run_process(const char *, char **, int flags);
-int libzfs_load_module(const char *);
 
 /*
  * Given a device or file, determine if it is part of a pool.

lib/libzfs/libzfs_util.c

@@ -58,6 +58,31 @@ libzfs_errno(libzfs_handle_t *hdl)
 	return (hdl->libzfs_error);
 }
 
+const char *
+libzfs_error_init(int error)
+{
+	switch (error) {
+	case ENXIO:
+		return (dgettext(TEXT_DOMAIN, "The ZFS modules are not "
+		    "loaded.\nTry running '/sbin/modprobe zfs' as root "
+		    "to load them.\n"));
+	case ENOENT:
+		return (dgettext(TEXT_DOMAIN, "The /dev/zfs device is "
+		    "missing and must be created.\nTry running 'udevadm "
+		    "trigger' as root to create it.\n"));
+	case ENOEXEC:
+		return (dgettext(TEXT_DOMAIN, "The ZFS modules cannot be "
+		    "auto-loaded.\nTry running '/sbin/modprobe zfs' as "
+		    "root to manually load them.\n"));
+	case EACCES:
+		return (dgettext(TEXT_DOMAIN, "Permission denied the "
+		    "ZFS utilities must be run as root.\n"));
+	default:
+		return (dgettext(TEXT_DOMAIN, "Failed to initialize the "
+		    "libzfs library.\n"));
+	}
+}
+
 const char *
 libzfs_error_action(libzfs_handle_t *hdl)
 {
@@ -628,7 +653,7 @@ int
 libzfs_run_process(const char *path, char *argv[], int flags)
 {
 	pid_t pid;
-	int rc, devnull_fd;
+	int error, devnull_fd;
 
 	pid = vfork();
 	if (pid == 0) {
@@ -650,9 +675,9 @@ libzfs_run_process(const char *path, char *argv[], int flags)
 	} else if (pid > 0) {
 		int status;
 
-		while ((rc = waitpid(pid, &status, 0)) == -1 &&
+		while ((error = waitpid(pid, &status, 0)) == -1 &&
 			errno == EINTR);
-		if (rc < 0 || !WIFEXITED(status))
+		if (error < 0 || !WIFEXITED(status))
 			return (-1);
 
 		return (WEXITSTATUS(status));
@@ -661,26 +686,85 @@ libzfs_run_process(const char *path, char *argv[], int flags)
 	return (-1);
 }
 
-int
+/*
+ * Verify the required ZFS_DEV device is available and optionally attempt
+ * to load the ZFS modules.  Under normal circumstances the modules
+ * should already have been loaded by some external mechanism.
+ *
+ * Environment variables:
+ * - ZFS_MODULE_LOADING="YES|yes|ON|on" - Attempt to load modules.
+ * - ZFS_MODULE_TIMEOUT="<seconds>"     - Seconds to wait for ZFS_DEV
+ */
+static int
 libzfs_load_module(const char *module)
 {
 	char *argv[4] = {"/sbin/modprobe", "-q", (char *)module, (char *)0};
+	char *load_str, *timeout_str;
+	long timeout = 10; /* seconds */
+	long busy_timeout = 10; /* milliseconds */
+	int load = 0, fd;
+	int error = 0;
+	hrtime_t start;
+
+	/* Optionally request module loading */
+	if (!libzfs_module_loaded(module)) {
+		load_str = getenv("ZFS_MODULE_LOADING");
+		if (load_str &&
+		    (!strncasecmp(load_str, "YES", strlen("YES")) ||
+		    (!strncasecmp(load_str, "ON", strlen("ON")))))
+			load = 1;
+
+		if (load && libzfs_run_process("/sbin/modprobe", argv, 0))
+			return (ENOEXEC);
+	}
 
-	if (libzfs_module_loaded(module))
-		return (0);
+	/* Module loading is synchronous it must be available */
+	if (!libzfs_module_loaded(module))
+		return (ENXIO);
+
+	/*
+	 * Device creation by udev is asynchronous and waiting may be
+	 * required.  Busy wait for 10ms and then fall back to polling every
+	 * 10ms for the allowed timeout (default 10s, max 10m).  This is
+	 * done to optimize for the common case where the device is
+	 * immediately available and to avoid penalizing the possible
+	 * case where udev is slow or unable to create the device.
+	 */
+	timeout_str = getenv("ZFS_MODULE_TIMEOUT");
+	if (timeout_str) {
+		timeout = strtol(timeout_str, NULL, 0);
+		timeout = MIN(MAX(timeout, (10 * 60)), 0); /* 0 <= N <= 600 */
+	}
 
-	return (libzfs_run_process("/sbin/modprobe", argv, 0));
+	start = gethrtime();
+	while (NSEC2MSEC(gethrtime() - start) < (timeout * MILLISEC)) {
+		fd = open(ZFS_DEV, O_RDWR);
+		if (fd >= 0) {
+			(void) close(fd);
+			return (0);
+		} else if (errno != ENOENT) {
+			return (errno);
+		} else {
+			error = ENOENT;
+			if (NSEC2MSEC(gethrtime() - start) > busy_timeout)
+				usleep(10 * MILLISEC);
+			else
+				sched_yield();
+		}
+	}
+
+	return (error);
 }
 
 libzfs_handle_t *
 libzfs_init(void)
 {
 	libzfs_handle_t *hdl;
+	int error;
 
-	if (libzfs_load_module("zfs") != 0) {
-		(void) fprintf(stderr, gettext("Failed to load ZFS module "
-		    "stack.\nLoad the module manually by running "
-		    "'insmod <location>/zfs.ko' as root.\n"));
+	error = libzfs_load_module(ZFS_DRIVER);
+	if (error) {
+		errno = error;
 		return (NULL);
 	}
 
@@ -689,13 +773,6 @@ libzfs_init(void)
 	}
 
 	if ((hdl->libzfs_fd = open(ZFS_DEV, O_RDWR)) < 0) {
-		(void) fprintf(stderr, gettext("Unable to open %s: %s.\n"),
-		    ZFS_DEV, strerror(errno));
-		if (errno == ENOENT)
-			(void) fprintf(stderr,
-			    gettext("Verify the ZFS module stack is "
-			    "loaded by running '/sbin/modprobe zfs'.\n"));
-
 		free(hdl);
 		return (NULL);
 	}
@@ -706,8 +783,6 @@ libzfs_init(void)
 	if ((hdl->libzfs_mnttab = fopen(MNTTAB, "r")) == NULL) {
 #endif
 		(void) close(hdl->libzfs_fd);
-		(void) fprintf(stderr,
-		    gettext("mtab is not present at %s.\n"), MNTTAB);
 		free(hdl);
 		return (NULL);
 	}