[PATCH] udevd - next round of fixes

Here is the next round. We have three queues now. All incoming messages
are queued in msg_list and if nothing is missing we move it to the
running_list and exec in the background.
If the exec comes back, it removes the message from the running_list and
frees the message.

Before we exec, we check the running_list if there is a udev running on
the same device path. If yes, we move the message to the delay_list. If
the former exec comes back, we move the message to the running_list and
exec it.

The very first event is delayed now to catch possible earlier sequences,
every following event is executed without delay if no sequence is missing.

The daemon doesn't exit by itself any longer, cause we don't want to
delay every first exec.

I've put a $(PWD) for now in the Makefile for testing this beast. Only
the local binaries are executed, not the /sbin/udev. We can change it
if we are ready for real testing.

And SIGKILL can't be cought, so I removed it from the handler :)


06:58:36 sig_handler: caught signal 15
06:58:36 main: using ipc queue 0x2d548
06:58:37 message is still in the ipc queue, starting daemon...
06:58:37 work: received sequence 3, expected sequence 0
06:58:37 msg_dump_queue: sequence 3 in queue
06:58:37 set_timeout: set timeout in 1 seconds
06:58:37 main: using ipc queue 0x2d548
06:58:37 main: using ipc queue 0x2d548
06:58:37 work: received sequence 1, expected sequence 1
06:58:37 msg_dump_queue: sequence 1 in queue
06:58:37 msg_dump_queue: sequence 3 in queue
06:58:37 msg_dump: sequence 1, 'add', '/block/sda', 'block'
06:58:37 msg_exec: child [8038] created
06:58:37 running_moveto_queue: move sequence 1 [8038] to running queue '/block/sda'
06:58:37 set_timeout: set timeout in 5 seconds
06:58:37 work: received sequence 2, expected sequence 2
06:58:37 msg_dump_queue: sequence 2 in queue
06:58:37 msg_dump_queue: sequence 3 in queue
06:58:37 msg_dump: sequence 2, 'add', '/block/sdb', 'block'
06:58:37 msg_exec: child [8039] created
06:58:37 running_moveto_queue: move sequence 2 [8039] to running queue '/block/sdb'
06:58:37 msg_dump: sequence 3, 'add', '/block/sdc', 'block'
06:58:37 msg_exec: child [8040] created
06:58:37 running_moveto_queue: move sequence 3 [8040] to running queue '/block/sdc'
06:58:37 main: using ipc queue 0x2d548
06:58:37 main: using ipc queue 0x2d548
06:58:37 work: received sequence 4, expected sequence 4
06:58:37 msg_dump_queue: sequence 4 in queue
06:58:37 msg_dump: sequence 4, 'remove', '/block/sdc', 'block'
06:58:37 msg_exec: delay exec of sequence 4, [8040] already working on '/block/sdc'
06:58:37 delayed_moveto_queue: move event to delayed queue '/block/sdc'
06:58:37 msg_exec: child [8043] created
06:58:37 running_moveto_queue: move sequence 4 [8043] to running queue '/block/sdc'
06:58:37 work: received sequence 5, expected sequence 5
06:58:37 msg_dump_queue: sequence 5 in queue
06:58:37 msg_dump: sequence 5, 'remove', '/block/sdb', 'block'
06:58:37 msg_exec: delay exec of sequence 5, [8039] already working on '/block/sdb'
06:58:37 delayed_moveto_queue: move event to delayed queue '/block/sdb'
06:58:37 msg_exec: child [8044] created
06:58:37 running_moveto_queue: move sequence 5 [8044] to running queue '/block/sdb'
06:58:37 main: using ipc queue 0x2d548
06:58:37 main: using ipc queue 0x2d548
06:58:37 work: received sequence 8, expected sequence 6
06:58:37 msg_dump_queue: sequence 8 in queue
06:58:37 set_timeout: set timeout in 5 seconds
06:58:37 work: received sequence 6, expected sequence 6
06:58:37 msg_dump_queue: sequence 6 in queue
06:58:37 msg_dump_queue: sequence 8 in queue
06:58:37 msg_dump: sequence 6, 'remove', '/block/sda', 'block'
06:58:37 msg_exec: delay exec of sequence 6, [8038] already working on '/block/sda'
06:58:37 delayed_moveto_queue: move event to delayed queue '/block/sda'
06:58:37 msg_exec: child [8047] created
06:58:37 running_moveto_queue: move sequence 6 [8047] to running queue '/block/sda'
06:58:37 set_timeout: set timeout in 5 seconds
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8038
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8039
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8040
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8043
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8044
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:38 sig_handler: caught signal 17
06:58:38 sig_handler: exec finished, pid 8047
06:58:38 set_timeout: set timeout in 4 seconds
06:58:38 msg_dump_queue: sequence 8 in queue
06:58:39 main: using ipc queue 0x2d548
06:58:39 main: using ipc queue 0x2d548
06:58:39 work: received sequence 9, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:39 work: received sequence 11, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 msg_dump_queue: sequence 11 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:39 main: using ipc queue 0x2d548
06:58:39 work: received sequence 10, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 msg_dump_queue: sequence 10 in queue
06:58:39 msg_dump_queue: sequence 11 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:39 main: using ipc queue 0x2d548
06:58:39 work: received sequence 13, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 msg_dump_queue: sequence 10 in queue
06:58:39 msg_dump_queue: sequence 11 in queue
06:58:39 msg_dump_queue: sequence 13 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:39 main: using ipc queue 0x2d548
06:58:39 work: received sequence 14, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 msg_dump_queue: sequence 10 in queue
06:58:39 msg_dump_queue: sequence 11 in queue
06:58:39 msg_dump_queue: sequence 13 in queue
06:58:39 msg_dump_queue: sequence 14 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:39 main: using ipc queue 0x2d548
06:58:39 work: received sequence 15, expected sequence 7
06:58:39 msg_dump_queue: sequence 8 in queue
06:58:39 msg_dump_queue: sequence 9 in queue
06:58:39 msg_dump_queue: sequence 10 in queue
06:58:39 msg_dump_queue: sequence 11 in queue
06:58:39 msg_dump_queue: sequence 13 in queue
06:58:39 msg_dump_queue: sequence 14 in queue
06:58:39 msg_dump_queue: sequence 15 in queue
06:58:39 set_timeout: set timeout in 3 seconds
06:58:41 main: using ipc queue 0x2d548
06:58:41 work: received sequence 12, expected sequence 7
06:58:41 msg_dump_queue: sequence 8 in queue
06:58:41 msg_dump_queue: sequence 9 in queue
06:58:41 msg_dump_queue: sequence 10 in queue
06:58:41 msg_dump_queue: sequence 11 in queue
06:58:41 msg_dump_queue: sequence 12 in queue
06:58:41 msg_dump_queue: sequence 13 in queue
06:58:41 msg_dump_queue: sequence 14 in queue
06:58:41 msg_dump_queue: sequence 15 in queue
06:58:41 set_timeout: set timeout in 1 seconds
06:58:42 sig_handler: caught signal 14
06:58:42 sig_handler: event timeout reached
06:58:42 event 8, age 5 seconds, skip event 7-7
06:58:42 msg_dump: sequence 8, 'add', '/block/sdb', 'block'
06:58:42 msg_exec: child [8057] created
06:58:42 running_moveto_queue: move sequence 8 [8057] to running queue '/block/sdb'
06:58:42 msg_dump: sequence 9, 'add', '/block/sdc', 'block'
06:58:42 msg_exec: child [8058] created
06:58:42 running_moveto_queue: move sequence 9 [8058] to running queue '/block/sdc'
06:58:42 msg_dump: sequence 10, 'remove', '/block/sdc', 'block'
06:58:42 msg_exec: delay exec of sequence 10, [8058] already working on '/block/sdc'
06:58:42 delayed_moveto_queue: move event to delayed queue '/block/sdc'
06:58:42 msg_exec: child [8059] created
06:58:42 running_moveto_queue: move sequence 10 [8059] to running queue '/block/sdc'
06:58:42 msg_dump: sequence 11, 'remove', '/block/sdb', 'block'
06:58:42 msg_exec: delay exec of sequence 11, [8057] already working on '/block/sdb'
06:58:42 delayed_moveto_queue: move event to delayed queue '/block/sdb'
06:58:42 msg_exec: child [8060] created
06:58:42 running_moveto_queue: move sequence 11 [8060] to running queue '/block/sdb'
06:58:42 msg_dump: sequence 12, 'remove', '/block/sda', 'block'
06:58:42 msg_exec: child [8061] created
06:58:42 running_moveto_queue: move sequence 12 [8061] to running queue '/block/sda'
06:58:42 msg_dump: sequence 13, 'add', '/block/sda', 'block'
06:58:42 msg_exec: delay exec of sequence 13, [8061] already working on '/block/sda'
06:58:42 delayed_moveto_queue: move event to delayed queue '/block/sda'
06:58:42 msg_exec: child [8062] created
06:58:42 running_moveto_queue: move sequence 13 [8062] to running queue '/block/sda'
06:58:42 msg_dump: sequence 14, 'add', '/block/sdb', 'block'
06:58:42 msg_exec: delay exec of sequence 14, [8057] already working on '/block/sdb'
06:58:42 delayed_moveto_queue: move event to delayed queue '/block/sdb'
06:58:42 msg_exec: child [8063] created
06:58:42 running_moveto_queue: move sequence 14 [8063] to running queue '/block/sdb'
06:58:42 msg_dump: sequence 15, 'add', '/block/sdc', 'block'
06:58:42 msg_exec: delay exec of sequence 15, [8058] already working on '/block/sdc'
06:58:42 delayed_moveto_queue: move event to delayed queue '/block/sdc'
06:58:42 msg_exec: child [8064] created
06:58:42 running_moveto_queue: move sequence 15 [8064] to running queue '/block/sdc'
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8057
06:58:43 sig_handler: exec finished, pid 8058
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8059
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8060
06:58:43 sig_handler: exec finished, pid 8061
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8062
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8063
06:58:43 sig_handler: caught signal 17
06:58:43 sig_handler: exec finished, pid 8064

1 files changed, 128 insertions, 60 deletions

diff --git a/udevd.c b/udevd.c
index 26e6b2348..a80da5b0d 100644
--- a/udevd.c
+++ b/udevd.c
@@ -38,27 +38,42 @@
 
 #include "list.h"
 #include "udev.h"
+#include "udev_version.h"
 #include "udevd.h"
 #include "logging.h"
 
+
 #define BUFFER_SIZE			1024
 
+static int running_remove_queue(pid_t pid);
+static int msg_exec(struct hotplug_msg *msg);
+
 static int expect_seqnum = 0;
 static int lock_file = -1;
 static char *lock_filename = ".udevd_lock";
 
 LIST_HEAD(msg_list);
+LIST_HEAD(running_list);
+LIST_HEAD(delayed_list);
 
 static void sig_handler(int signum)
 {
+	pid_t pid;
+
 	dbg("caught signal %d", signum);
 	switch (signum) {
 	case SIGALRM:
 		dbg("event timeout reached");
 		break;
+	case SIGCHLD:
+		/* catch signals from exiting childs */
+		while ( (pid = waitpid(-1, NULL, WNOHANG)) > 0) {
+			dbg("exec finished, pid %d", pid);
+			running_remove_queue(pid);
+		}
+		break;
 	case SIGINT:
 	case SIGTERM:
-	case SIGKILL:
 		if (lock_file >= 0) {
 			close(lock_file);
 			unlink(lock_filename);
@@ -70,34 +85,104 @@ static void sig_handler(int signum)
 	}
 }
 
-static void dump_queue(void)
+static void set_timeout(int seconds)
 {
-	struct hotplug_msg *msg;
+	alarm(seconds);
+	dbg("set timeout in %d seconds", seconds);
+}
 
-	list_for_each_entry(msg, &msg_list, list)
-		dbg("sequence %d in queue", msg->seqnum);
+static int running_moveto_queue(struct hotplug_msg *msg)
+{
+	dbg("move sequence %d [%d] to running queue '%s'",
+	    msg->seqnum, msg->pid, msg->devpath);
+	list_move_tail(&msg->list, &running_list);
+	return 0;
+}
+
+static int running_remove_queue(pid_t  pid)
+{
+	struct hotplug_msg *child;
+	struct hotplug_msg *tmp_child;
+
+	list_for_each_entry_safe(child, tmp_child, &running_list, list)
+		if (child->pid == pid) {
+			list_del_init(&child->list);
+			free(child);
+			return 0;
+		}
+	return -EINVAL;
+}
+
+static pid_t running_getpid_by_devpath(struct hotplug_msg *msg)
+{
+	struct hotplug_msg *child;
+	struct hotplug_msg *tmp_child;
+
+	list_for_each_entry_safe(child, tmp_child, &running_list, list)
+		if (strncmp(child->devpath, msg->devpath, sizeof(child->devpath)) == 0)
+			return child->pid;
+	return 0;
+}
+
+static void delayed_dump_queue(void)
+{
+	struct hotplug_msg *child;
+
+	list_for_each_entry(child, &delayed_list, list)
+		dbg("event for '%s' in queue", child->devpath);
+}
+
+static int delayed_moveto_queue(struct hotplug_msg *msg)
+{
+	dbg("move event to delayed queue '%s'", msg->devpath);
+	list_move_tail(&msg->list, &delayed_list);
+	return 0;
+}
+
+static void delayed_check_queue(void)
+{
+	struct hotplug_msg *delayed_child;
+	struct hotplug_msg *running_child;
+	struct hotplug_msg *tmp_child;
+
+	/* see if we have delayed exec's that can run now */
+	list_for_each_entry_safe(delayed_child, tmp_child, &delayed_list, list)
+		list_for_each_entry_safe(running_child, tmp_child, &running_list, list)
+			if (strncmp(delayed_child->devpath, running_child->devpath,
+			    sizeof(running_child->devpath)) == 0) {
+				dbg("delayed exec for '%s' can run now", delayed_child->devpath);
+				msg_exec(delayed_child);
+			}
 }
 
-static void dump_msg(struct hotplug_msg *msg)
+static void msg_dump(struct hotplug_msg *msg)
 {
 	dbg("sequence %d, '%s', '%s', '%s'",
 	    msg->seqnum, msg->action, msg->devpath, msg->subsystem);
 }
 
-static int dispatch_msg(struct hotplug_msg *msg)
+static int msg_exec(struct hotplug_msg *msg)
 {
 	pid_t pid;
 
-	dump_msg(msg);
+	msg_dump(msg);
 
 	setenv("ACTION", msg->action, 1);
 	setenv("DEVPATH", msg->devpath, 1);
 
+	/* delay exec, if we already have a udev working on the same devpath */
+	pid = running_getpid_by_devpath(msg);
+	if (pid != 0) {
+		dbg("delay exec of sequence %d, [%d] already working on '%s'",
+		    msg->seqnum, pid, msg->devpath);
+		delayed_moveto_queue(msg);
+	}
+
 	pid = fork();
 	switch (pid) {
 	case 0:
 		/* child */
-		execl(UDEV_EXEC, "udev", msg->subsystem, NULL);
+		execl(UDEV_BIN, "udev", msg->subsystem, NULL);
 		dbg("exec of child failed");
 		exit(1);
 		break;
@@ -105,18 +190,23 @@ static int dispatch_msg(struct hotplug_msg *msg)
 		dbg("fork of child failed");
 		return -1;
 	default:
-		wait(NULL);
+		/* exec in background, get the SIGCHLD with the sig handler */
+		msg->pid = pid;
+		running_moveto_queue(msg);
+		break;
 	}
 	return 0;
 }
 
-static void set_timeout(int seconds)
+static void msg_dump_queue(void)
 {
-	alarm(seconds);
-	dbg("set timeout in %d seconds", seconds);
+	struct hotplug_msg *msg;
+
+	list_for_each_entry(msg, &msg_list, list)
+		dbg("sequence %d in queue", msg->seqnum);
 }
 
-static void check_queue(void)
+static void msg_check_queue(void)
 {
 	struct hotplug_msg *msg;
 	struct hotplug_msg *tmp_msg;
@@ -127,30 +217,32 @@ recheck:
 	list_for_each_entry_safe(msg, tmp_msg, &msg_list, list) {
 		if (msg->seqnum != expect_seqnum)
 			break;
-		dispatch_msg(msg);
+		msg_exec(msg);
 		expect_seqnum++;
-		list_del_init(&msg->list);
-		free(msg);
 	}
 
-	/* recalculate timeout */
+	/* recalculate next timeout */
 	if (list_empty(&msg_list) == 0) {
 		msg_age = time(NULL) - msg->queue_time;
-		if (msg_age > EVENT_TIMEOUT_SECONDS-1) {
+		if (msg_age > EVENT_TIMEOUT_SEC-1) {
 			info("event %d, age %li seconds, skip event %d-%d",
 			     msg->seqnum, msg_age, expect_seqnum, msg->seqnum-1);
 			expect_seqnum = msg->seqnum;
 			goto recheck;
 		}
-		set_timeout(EVENT_TIMEOUT_SECONDS - msg_age);
+
+		/* the first sequence gets its own timeout */
+		if (expect_seqnum == 0) {
+			msg_age = EVENT_TIMEOUT_SEC - FIRST_EVENT_TIMEOUT_SEC;
+			expect_seqnum = 1;
+		}
+
+		set_timeout(EVENT_TIMEOUT_SEC - msg_age);
 		return;
 	}
-
-	/* queue is empty */
-	set_timeout(UDEVD_TIMEOUT_SECONDS);
 }
 
-static int queue_msg(struct hotplug_msg *msg)
+static int msg_add_queue(struct hotplug_msg *msg)
 {
 	struct hotplug_msg *new_msg;
 	struct hotplug_msg *tmp_msg;
@@ -182,7 +274,7 @@ static void work(void)
 	char buf[BUFFER_SIZE];
 	int ret;
 
-	key = ftok(UDEVD_EXEC, IPC_KEY_ID);
+	key = ftok(UDEVD_BIN, IPC_KEY_ID);
 	msg = (struct hotplug_msg *) buf;
 	msgid = msgget(key, IPC_CREAT);
 	if (msgid == -1) {
@@ -192,41 +284,20 @@ static void work(void)
 	while (1) {
 		ret = msgrcv(msgid, (struct msgbuf *) buf, BUFFER_SIZE-4, HOTPLUGMSGTYPE, 0);
 		if (ret != -1) {
-			/* init the expected sequence with value from first call */
-			if (expect_seqnum == 0) {
-				expect_seqnum = msg->seqnum;
-				dbg("init next expected sequence number to %d", expect_seqnum);
-			}
-			dbg("current sequence %d, expected sequence %d", msg->seqnum, expect_seqnum);
-			if (msg->seqnum == expect_seqnum) {
-				/* execute expected event */
-				dispatch_msg(msg);
-				expect_seqnum++;
-				check_queue();
-				dump_queue();
+			dbg("received sequence %d, expected sequence %d", msg->seqnum, expect_seqnum);
+			if (msg->seqnum >= expect_seqnum) {
+				msg_add_queue(msg);
+				msg_dump_queue();
+				msg_check_queue();
 				continue;
 			}
-			if (msg->seqnum > expect_seqnum) {
-				/* something missing, queue event*/
-				queue_msg(msg);
-				check_queue();
-				dump_queue();
-				continue;
-			}
-			dbg("too late for event with sequence %d, even skipped ", msg->seqnum);
+			dbg("too late for event with sequence %d, event skipped ", msg->seqnum);
 		} else {
 			if (errno == EINTR) {
-				/* timeout */
-				if (list_empty(&msg_list)) {
-					info("we have nothing to do, so daemon exits...");
-					if (lock_file >= 0) {
-						close(lock_file);
-						unlink(lock_filename);
-					}
-					exit(0);
-				}
-				check_queue();
-				dump_queue();
+				msg_check_queue();
+				msg_dump_queue();
+				delayed_check_queue();
+				delayed_dump_queue();
 				continue;
 			}
 			dbg("ipc message receive error '%s'", strerror(errno));
@@ -266,11 +337,8 @@ int main(int argc, char *argv[])
 	/* set up signal handler */
 	signal(SIGINT, sig_handler);
 	signal(SIGTERM, sig_handler);
-	signal(SIGKILL, sig_handler);
 	signal(SIGALRM, sig_handler);
-
-	/* we exit if we have nothing to do, next event will start us again */
-	set_timeout(UDEVD_TIMEOUT_SECONDS);
+	signal(SIGCHLD, sig_handler);
 
 	work();
 	exit(0);