allow logging of all output from executed tools

If USE_DEBUG=true and udev_log="debug", all output of the forked
programs to stdout and stderr is send to syslog.

Signed-off-by: Kay Sievers <kay.sievers@suse.de>

6 files changed, 132 insertions, 46 deletions

diff --git a/extras/run_directory/run_directory.c b/extras/run_directory/run_directory.c
index 770d8d84a1..5107f85aef 100644
--- a/extras/run_directory/run_directory.c
+++ b/extras/run_directory/run_directory.c
@@ -27,7 +27,7 @@
 #include "../../logging.h"
 #include "run_directory.h"
 
-static int run_program(const char *filename, const char *subsystem)
+static int exec_program(const char *filename, const char *subsystem)
 {
 	pid_t pid;
 
@@ -59,7 +59,7 @@ int run_directory(const char *dir, const char *suffix, const char *subsystem)
 	add_matching_files(&name_list, dir, suffix);
 
 	list_for_each_entry_safe(name_loop, name_tmp, &name_list, node) {
-		run_program(name_loop->name, subsystem);
+		exec_program(name_loop->name, subsystem);
 		list_del(&name_loop->node);
 	}
 
diff --git a/udev.c b/udev.c
index ecfd5644ec..d50f81ea5e 100644
--- a/udev.c
+++ b/udev.c
@@ -28,6 +28,7 @@
 #include <errno.h>
 #include <signal.h>
 #include <unistd.h>
+#include <syslog.h>
 
 #include "libsysfs/sysfs/libsysfs.h"
 #include "udev_libc_wrapper.h"
@@ -127,7 +128,7 @@ int main(int argc, char *argv[], char *envp[])
 			if (strncmp(name_loop->name, "socket:", strlen("socket:")) == 0)
 				pass_env_to_socket(&name_loop->name[strlen("socket:")], devpath, action);
 			else
-				execute_program(name_loop->name, udev.subsystem, NULL, 0, NULL);
+				run_program(name_loop->name, udev.subsystem, NULL, 0, NULL, (udev_log_priority >= LOG_DEBUG));
 		}
 	}
 
diff --git a/udev_rules.c b/udev_rules.c
index d42b219d7d..8587b02549 100644
--- a/udev_rules.c
+++ b/udev_rules.c
@@ -27,6 +27,7 @@
 #include <ctype.h>
 #include <unistd.h>
 #include <errno.h>
+#include <syslog.h>
 #include <sys/wait.h>
 #include <sys/stat.h>
 
@@ -221,7 +222,7 @@ static int import_program_into_env(struct udevice *udev, const char *program)
 	char result[1024];
 	size_t reslen;
 
-	if (execute_program(program, udev->subsystem, result, sizeof(result), &reslen) != 0)
+	if (run_program(program, udev->subsystem, result, sizeof(result), &reslen, (udev_log_priority >= LOG_DEBUG)) != 0)
 		return -1;
 	return import_keys_into_env(udev, result, reslen);
 }
@@ -833,8 +834,9 @@ try_parent:
 		strlcpy(program, key_val(rule, &rule->program), sizeof(program));
 		apply_format(udev, program, sizeof(program), class_dev, sysfs_device);
 		dbg("check for PROGRAM program='%s", program);
-		if (execute_program(program, udev->subsystem, result, sizeof(result), NULL) != 0) {
+		if (run_program(program, udev->subsystem, result, sizeof(result), NULL, (udev_log_priority >= LOG_DEBUG)) != 0) {
 			dbg("PROGRAM is false");
+			udev->program_result[0] = '\0';
 			if (rule->program.operation != KEY_OP_NOMATCH)
 				goto exit;
 		} else {
diff --git a/udev_utils.h b/udev_utils.h
index 5b223855b6..a3fc283203 100644
--- a/udev_utils.h
+++ b/udev_utils.h
@@ -24,6 +24,8 @@
 #include "udev.h"
 #include "list.h"
 
+#define UDEV_MAX(a,b) ((a) > (b) ? (a) : (b))
+
 struct name_entry {
 	struct list_head node;
 	char name[PATH_SIZE];
@@ -45,7 +47,7 @@ extern int name_list_add(struct list_head *name_list, const char *name, int sort
 extern int name_list_key_add(struct list_head *name_list, const char *key, const char *value);
 extern int add_matching_files(struct list_head *name_list, const char *dirname, const char *suffix);
 extern int pass_env_to_socket(const char *name, const char *devpath, const char *action);
-extern int execute_program(const char *command, const char *subsystem,
-			   char *result, size_t ressize, size_t *reslen);
+extern int run_program(const char *command, const char *subsystem,
+		       char *result, size_t ressize, size_t *reslen, int log);
 
 #endif
diff --git a/udev_utils_run.c b/udev_utils_run.c
index c2e77cbbcc..50b31781e7 100644
--- a/udev_utils_run.c
+++ b/udev_utils_run.c
@@ -29,6 +29,7 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 #include <sys/wait.h>
+#include <sys/select.h>
 
 #include "udev_libc_wrapper.h"
 #include "udev.h"
@@ -70,20 +71,19 @@ int pass_env_to_socket(const char *sockname, const char *devpath, const char *ac
 	return retval;
 }
 
-int execute_program(const char *command, const char *subsystem,
-		    char *result, size_t ressize, size_t *reslen)
+int run_program(const char *command, const char *subsystem,
+		char *result, size_t ressize, size_t *reslen, int dbg)
 {
 	int retval = 0;
-	int count;
 	int status;
-	int pipefds[2];
+	int outpipe[2] = {-1, -1};
+	int errpipe[2] = {-1, -1};
 	pid_t pid;
 	char *pos;
 	char arg[PATH_SIZE];
 	char *argv[(sizeof(arg) / 2) + 1];
 	int devnull;
 	int i;
-	size_t len;
 
 	strlcpy(arg, command, sizeof(arg));
 	i = 0;
@@ -102,7 +102,7 @@ int execute_program(const char *command, const char *subsystem,
 			dbg("arg[%i] '%s'", i, argv[i]);
 			i++;
 		}
-		argv[i] =  NULL;
+		argv[i] = NULL;
 		dbg("execute '%s' with parsed arguments", arg);
 	} else {
 		argv[0] = arg;
@@ -111,8 +111,15 @@ int execute_program(const char *command, const char *subsystem,
 		dbg("execute '%s' with subsystem '%s' argument", arg, argv[1]);
 	}
 
-	if (result) {
-		if (pipe(pipefds) != 0) {
+	/* prepare pipes from child to parent */
+	if (result || dbg) {
+		if (pipe(outpipe) != 0) {
+			err("pipe failed");
+			return -1;
+		}
+	}
+	if (dbg) {
+		if (pipe(errpipe) != 0) {
 			err("pipe failed");
 			return -1;
 		}
@@ -121,53 +128,127 @@ int execute_program(const char *command, const char *subsystem,
 	pid = fork();
 	switch(pid) {
 	case 0:
-		/* child dup2 write side of pipe to STDOUT */
+		/* child closes parent ends of pipes */
+		if (outpipe[0] > 0)
+			close(outpipe[0]);
+		if (errpipe[0] > 0)
+			close(errpipe[0]);
+
+		/* discard child output or connect to pipe */
 		devnull = open("/dev/null", O_RDWR);
-		if (devnull >= 0) {
-			dup2(devnull, STDIN_FILENO);
-			if (!result)
-				dup2(devnull, STDOUT_FILENO);
-			dup2(devnull, STDERR_FILENO);
-			close(devnull);
+		if (devnull < 0) {
+			err("open /dev/null failed");
+			exit(1);
 		}
-		if (result)
-			dup2(pipefds[1], STDOUT_FILENO);
+		dup2(devnull, STDIN_FILENO);
+
+		if (outpipe[1] > 0)
+			dup2(outpipe[1], STDOUT_FILENO);
+		else
+			dup2(devnull, STDOUT_FILENO);
+
+		if (errpipe[1] > 0)
+			dup2(errpipe[1], STDERR_FILENO);
+		else
+			dup2(devnull, STDERR_FILENO);
+
+		close(devnull);
 		execv(arg, argv);
+
+		/* we should never reach this */
 		err("exec of program failed");
 		_exit(1);
 	case -1:
 		err("fork of '%s' failed", arg);
 		return -1;
 	default:
-		/* parent reads from pipefds[0] */
-		if (result) {
-			close(pipefds[1]);
-			len = 0;
-			while (1) {
-				count = read(pipefds[0], result + len, ressize - len-1);
-				if (count < 0) {
-					err("read failed with '%s'", strerror(errno));
+		/* read from child if requested */
+		if (outpipe[0] > 0 || errpipe[0] > 0) {
+			size_t count;
+			size_t respos = 0;
+
+			/* parent closes child ends of pipes */
+			if (outpipe[1] > 0)
+				close(outpipe[1]);
+			if (errpipe[1] > 0)
+				close(errpipe[1]);
+
+			/* read child output */
+			while (outpipe[0] > 0 || errpipe[0] > 0) {
+				int fdcount;
+				fd_set readfds;
+
+				FD_ZERO(&readfds);
+				if (outpipe[0] > 0)
+					FD_SET(outpipe[0], &readfds);
+				if (errpipe[0] > 0)
+					FD_SET(errpipe[0], &readfds);
+				fdcount = select(UDEV_MAX(outpipe[0], errpipe[0])+1, &readfds, NULL, NULL, NULL);
+				if (fdcount < 0) {
+					if (errno == EINTR)
+						continue;
 					retval = -1;
 					break;
 				}
 
-				if (count == 0)
-					break;
+				/* get stdout */
+				if (outpipe[0] > 0 && FD_ISSET(outpipe[0], &readfds)) {
+					char inbuf[1024];
 
-				len += count;
-				if (len >= ressize-1) {
-					err("ressize %ld too short", (long)ressize);
-					retval = -1;
-					break;
+					count = read(outpipe[0], inbuf, sizeof(inbuf)-1);
+					if (count <= 0) {
+						close(outpipe[0]);
+						outpipe[0] = -1;
+						if (count < 0) {
+							err("stdin read failed with '%s'", strerror(errno));
+							retval = -1;
+						}
+						continue;
+					}
+					inbuf[count] = '\0';
+					dbg("stdout: '%s'", inbuf);
+
+					if (result) {
+						if (respos + count >= ressize) {
+							err("ressize %ld too short", (long)ressize);
+							retval = -1;
+							continue;
+						}
+						memcpy(&result[respos], inbuf, count);
+						respos += count;
+					}
+				}
+
+				/* get stderr */
+				if (errpipe[0] > 0 && FD_ISSET(errpipe[0], &readfds)) {
+					char errbuf[1024];
+
+					count = read(errpipe[0], errbuf, sizeof(errbuf)-1);
+					if (count <= 0) {
+						close(errpipe[0]);
+						errpipe[0] = -1;
+						if (count < 0)
+							err("stderr read failed with '%s'", strerror(errno));
+						continue;
+					}
+					errbuf[count] = '\0';
+					dbg("stderr: '%s'", errbuf);
 				}
 			}
-			result[len] = '\0';
-			close(pipefds[0]);
-			if (reslen)
-				*reslen = len;
+			if (outpipe[0] > 0)
+				close(outpipe[0]);
+			if (errpipe[0] > 0)
+				close(errpipe[0]);
+
+			/* return the childs stdout string */
+			if (result) {
+				result[respos] = '\0';
+				dbg("result='%s'", result);
+				if (reslen)
+					*reslen = respos;
+			}
 		}
 		waitpid(pid, &status, 0);
-
 		if (!WIFEXITED(status) || (WEXITSTATUS(status) != 0)) {
 			dbg("exec program status 0x%x", status);
 			retval = -1;
@@ -176,4 +257,3 @@ int execute_program(const char *command, const char *subsystem,
 
 	return retval;
 }
-
diff --git a/udevstart.c b/udevstart.c
index 23a13e08ff..90b87b8377 100644
--- a/udevstart.c
+++ b/udevstart.c
@@ -33,6 +33,7 @@
 #include <ctype.h>
 #include <dirent.h>
 #include <signal.h>
+#include <syslog.h>
 #include <sys/wait.h>
 #include <sys/stat.h>
 #include <sys/types.h>
@@ -164,7 +165,7 @@ run:
 			if (strncmp(name_loop->name, "socket:", strlen("socket:")) == 0)
 				pass_env_to_socket(&name_loop->name[strlen("socket:")], devpath, "add");
 			else
-				execute_program(name_loop->name, udev.subsystem, NULL, 0, NULL);
+				run_program(name_loop->name, udev.subsystem, NULL, 0, NULL, (udev_log_priority >= LOG_DEBUG));
 		}
 	}
 exit: