some timings with/without hotplug scripts and udev

some timings with/without hotplug scripts and udev

[Patrick Mansfield]

Times running without hotplug scripts, hotplug scripts without udev, and
with udev using 512 scsi_debug LUNs.

insmod was really this:

	modprobe scsi_debug num_tgts2 max_luns\x16 delay=0

No hotplug scripts means using /bin/true for the kernel hotplug.

			insmod		rmmod
no hotplug scripts	0:05.46		0:04.63
hotplug no udev		0:30.95		0:26.40
udev w/glibc current	0:40.84		0:36.20

So hotplug scripts take about 25 seconds, and udev adds about 10 seconds
on top of that.

-- Patrick Mansfield


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id\x1470&alloc_id638&op=click
_______________________________________________
Linux-hotplug-devel mailing list  http://linux-hotplug.sourceforge.net
Linux-hotplug-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linux-hotplug-devel

Re: some timings with/without hotplug scripts and udev

[Kay Sievers]

[-- Attachment #1: Type: text/plain, Size: 975 bytes --]

On Tue, Mar 16, 2004 at 09:06:13AM -0800, Patrick Mansfield wrote:
> Times running without hotplug scripts, hotplug scripts without udev, and
> with udev using 512 scsi_debug LUNs.
> 
> insmod was really this:
> 
> 	modprobe scsi_debug num_tgts=32 max_luns=16 delay=0
> 
> No hotplug scripts means using /bin/true for the kernel hotplug.
> 
> 			insmod		rmmod
> no hotplug scripts	0:05.46		0:04.63
> hotplug no udev		0:30.95		0:26.40
> udev w/glibc current	0:40.84		0:36.20
> 
> So hotplug scripts take about 25 seconds, and udev adds about 10 seconds
> on top of that.

Are you running udevsend/udevd in the test?

Any chance to run the same test with the applied patch, which lets
udevsend wait until the real udev comes back?

I'm interested if this takes much longer. If we ensure that udevsend is
the first program that runs by /sbin/hotplug, we can be sure to know any
node name and attribute in any of the following scripts.


again, much thanks for the numbers,
Kay


[-- Attachment #2: 90-udevsend-wait.patch --]
[-- Type: text/plain, Size: 6847 bytes --]

===== udevd.c 1.23 vs edited =====
--- 1.23/udevd.c	Wed Mar  3 22:05:10 2004
+++ edited/udevd.c	Fri Mar 12 15:49:10 2004
@@ -222,6 +222,15 @@
 	}
 }
 
+static void send_ack_msg(int sock, struct hotplug_msg *msg)
+{
+	int retval;
+	dbg("sending ack msg for seq %i", msg->seqnum);
+	retval = sendto(sock, msg, sizeof(struct hotplug_msg), 0, (struct sockaddr*) &msg->addr, msg->addrlen);
+	if (retval == -1)
+		dbg("error sending ack msg");
+}
+
 /* receive the msg, do some basic sanity checks, and queue it */
 static void handle_msg(int sock)
 {
@@ -232,6 +241,7 @@
 	struct iovec iov;
 	struct ucred *cred;
 	char cred_msg[CMSG_SPACE(sizeof(struct ucred))];
+	struct sockaddr_un addr;
 
 	msg = msg_create();
 	if (msg == NULL) {
@@ -247,29 +257,39 @@
 	smsg.msg_iovlen = 1;
 	smsg.msg_control = cred_msg;
 	smsg.msg_controllen = sizeof(cred_msg);
+	smsg.msg_name = &addr;
+	smsg.msg_namelen = sizeof(addr);
 
 	retval = recvmsg(sock, &smsg, 0);
 	if (retval <  0) {
 		if (errno != EINTR)
 			dbg("unable to receive message");
-		return;
+		goto skip;
 	}
+
+	if (retval != sizeof(struct hotplug_msg)) {
+		dbg("wrong message size");
+		goto skip;
+	}
+
 	cmsg = CMSG_FIRSTHDR(&smsg);
 	cred = (struct ucred *) CMSG_DATA(cmsg);
+	memcpy(&msg->addr, smsg.msg_name, smsg.msg_namelen);
+	msg->addrlen = smsg.msg_namelen;
+
+	if (strncmp(msg->magic, UDEV_MAGIC, sizeof(UDEV_MAGIC)) != 0 ) {
+		dbg("message magic '%s' doesn't match, ignore it", msg->magic);
+		goto skip;
+	}
 
 	if (cmsg == NULL || cmsg->cmsg_type != SCM_CREDENTIALS) {
 		dbg("no sender credentials received, message ignored");
-		goto skip;
+		goto refuse;
 	}
 
 	if (cred->uid != 0) {
 		dbg("sender uid=%i, message ignored", cred->uid);
-		goto skip;
-	}
-
-	if (strncmp(msg->magic, UDEV_MAGIC, sizeof(UDEV_MAGIC)) != 0 ) {
-		dbg("message magic '%s' doesn't match, ignore it", msg->magic);
-		goto skip;
+		goto refuse;
 	}
 
 	/* if no seqnum is given, we move straight to exec queue */
@@ -281,6 +301,10 @@
 	}
 	return;
 
+refuse:
+	msg->rc = EMSG_REFUSED;
+	send_ack_msg(sock, msg);
+
 skip:
 	free(msg);
 	return;
@@ -304,7 +328,7 @@
 	}
 }
 
-static void udev_done(int pid)
+static void udev_done(int pid, int rc, int sock)
 {
 	/* find msg associated with pid and delete it */
 	struct hotplug_msg *msg;
@@ -312,6 +336,9 @@
 	list_for_each_entry(msg, &running_list, list) {
 		if (msg->pid == pid) {
 			dbg("<== exec seq %d came back", msg->seqnum);
+			msg->rc = rc;
+			send_ack_msg(sock, msg);
+
 			run_queue_delete(msg);
 			return;
 		}
@@ -326,6 +353,8 @@
 	int retval;
 	const int on = 1;
 	struct sigaction act;
+	int status;
+	int rc;
 
 	init_logging("udevd");
 	dbg("version %s", UDEV_VERSION);
@@ -381,10 +410,16 @@
 			children_waiting = 0;
 			/* reap all dead children */
 			while(1) {
-				int pid = waitpid(-1, 0, WNOHANG);
+				int pid = waitpid(-1, &status, WNOHANG);
 				if ((pid == -1) || (pid == 0))
 					break;
-				udev_done(pid);
+
+				if (WIFEXITED(status))
+					rc = WEXITSTATUS(status);
+				else
+					rc = 0;
+
+				udev_done(pid, rc, ssock);
 			}
 		}
 	}
===== udevd.h 1.8 vs edited =====
--- 1.8/udevd.h	Thu Feb 26 04:09:18 2004
+++ edited/udevd.h	Fri Mar 12 16:09:17 2004
@@ -25,16 +25,26 @@
 #include "list.h"
 
 #define UDEV_MAGIC			"udevd_" UDEV_VERSION
-#define EVENT_TIMEOUT_SEC		5
 #define UDEVSEND_CONNECT_RETRY		20 /* x 100 millisec */
 #define UDEVD_SOCK_PATH			"udevd"
 
+#define EVENT_TIMEOUT_SEC		5
+#define ACK_TIMEOUT_SEC			(EVENT_TIMEOUT_SEC + 5)
+
+#define ETIMEOUT_RCV_ACK		16
+#define EMSG_REFUSED			17
+#define EMSG_SEND			18
+
+
 struct hotplug_msg {
-	char magic[20];
 	struct list_head list;
 	pid_t pid;
-	int seqnum;
 	time_t queue_time;
+	struct sockaddr_un addr;
+	socklen_t addrlen;
+	char magic[20];
+	int seqnum;
+	int rc;
 	char action[ACTION_SIZE];
 	char devpath[DEVPATH_SIZE];
 	char subsystem[SUBSYSTEM_SIZE];
===== udevsend.c 1.27 vs edited =====
--- 1.27/udevsend.c	Wed Mar  3 22:07:05 2004
+++ edited/udevsend.c	Fri Mar 12 16:05:43 2004
@@ -22,6 +22,7 @@
  *
  */
 
+#include <sys/select.h>
 #include <sys/types.h>
 #include <sys/socket.h>
 #include <sys/wait.h>
@@ -95,6 +96,7 @@
 	default:
 		wait(NULL);
 	}
+
 	return 0;
 }
 
@@ -106,7 +108,7 @@
 	char *subsystem;
 	char *seqnum;
 	int seq;
-	int retval = 1;
+	int retval;
 	int size;
 	int loop;
 	struct timespec tspec;
@@ -114,6 +116,7 @@
 	struct sockaddr_un saddr;
 	socklen_t addrlen;
 	int started_daemon = 0;
+	int rc = EMSG_SEND;
 
 #ifdef DEBUG
 	init_logging("udevsend");
@@ -156,6 +159,14 @@
 
 	memset(&saddr, 0x00, sizeof(saddr));
 	saddr.sun_family = AF_LOCAL;
+	sprintf(&saddr.sun_path[1], "%d", getpid());
+	addrlen = offsetof(struct sockaddr_un, sun_path) + strlen(saddr.sun_path+1) + 1;
+	
+	if (bind(sock, (struct sockaddr*)&saddr, addrlen) < 0) {
+		dbg("error binding socket");
+		goto exit;
+	}
+		
 	/* use abstract namespace for socket path */
 	strcpy(&saddr.sun_path[1], UDEVD_SOCK_PATH);
 	addrlen = offsetof(struct sockaddr_un, sun_path) + strlen(saddr.sun_path+1) + 1;
@@ -164,11 +175,54 @@
 
 	/* If we can't send, try to start daemon and resend message */
 	loop = UDEVSEND_CONNECT_RETRY;
+
 	while (loop--) {
+		dbg("sending message for seq %i", msg.seqnum);
 		retval = sendto(sock, &msg, size, 0, (struct sockaddr *)&saddr, addrlen);
 		if (retval != -1) {
-			retval = 0;
-			goto close_and_exit;
+			/* wait for ack */
+			fd_set rdset;
+			int count;
+			struct timeval tv = {ACK_TIMEOUT_SEC, 0};
+
+			while(1) {
+				FD_ZERO(&rdset);
+				FD_SET(sock, &rdset);
+				count = select(sock+1, &rdset, NULL, NULL, &tv);
+				if (count == 0) {
+					dbg("timeout waiting for ack msg");
+					rc = ETIMEOUT_RCV_ACK;
+					goto close_and_exit;
+					
+				}
+
+				if (FD_ISSET(sock, &rdset)) {
+					struct hotplug_msg ack;
+
+					retval = recv(sock, &ack, sizeof(ack), MSG_DONTWAIT);
+					if (retval <= 0) {
+						dbg("no ack msg received");
+						continue;
+					}
+
+					if (strncmp(ack.magic, msg.magic, sizeof(UDEV_MAGIC)) != 0 ) {
+						dbg("wrong ack msg magic '%s'", ack.magic);
+						continue;
+					}
+
+					if (ack.rc == EMSG_REFUSED) {
+						dbg("seq %i is refused", ack.seqnum);
+						rc = EMSG_REFUSED;
+						goto close_and_exit;
+					}
+
+					if (ack.seqnum == msg.seqnum) {
+						dbg("seq %i returned with %i", ack.seqnum, ack.rc);
+						rc = ack.rc;
+						goto close_and_exit;
+					}
+				}
+			}
 		}
 		
 		if (errno != ECONNREFUSED) {
@@ -179,11 +233,10 @@
 		if (!started_daemon) {
 			dbg("connect failed, try starting daemon...");
 			retval = start_daemon();
-			if (retval) {
+			if (retval != 0) {
 				dbg("error starting daemon");
 				goto exit;
 			}
-			
 			dbg("daemon started");
 			started_daemon = 1;
 		} else {
@@ -193,9 +246,9 @@
 			nanosleep(&tspec, NULL);
 		}
 	}
-	
+
 close_and_exit:
 	close(sock);
 exit:
-	return retval;
+	return rc;
 }

Re: some timings with/without hotplug scripts and udev

[Patrick Mansfield]

On Tue, Mar 16, 2004 at 11:33:00PM +0100, Kay Sievers wrote:
> On Tue, Mar 16, 2004 at 09:06:13AM -0800, Patrick Mansfield wrote:
> > Times running without hotplug scripts, hotplug scripts without udev, and
> > with udev using 512 scsi_debug LUNs.
> > 
> > insmod was really this:
> > 
> > 	modprobe scsi_debug num_tgts2 max_luns\x16 delay=0
> > 
> > No hotplug scripts means using /bin/true for the kernel hotplug.
> > 
> > 			insmod		rmmod
> > no hotplug scripts	0:05.46		0:04.63
> > hotplug no udev		0:30.95		0:26.40
> > udev w/glibc current	0:40.84		0:36.20
> > 
> > So hotplug scripts take about 25 seconds, and udev adds about 10 seconds
> > on top of that.

> Are you running udevsend/udevd in the test?

Yes, I assume udevsend per the link installed by udev:

[elm3b79 misc-io]$ ls -l /etc/hotplug.d/default/udev.hotplug 
lrwxr-xr-x    1 root     root           14 Mar 16 16:02 /etc/hotplug.d/default/udev.hotplug -> /sbin/udevsend

> Any chance to run the same test with the applied patch, which lets
> udevsend wait until the real udev comes back?
> 
> I'm interested if this takes much longer. If we ensure that udevsend is
> the first program that runs by /sbin/hotplug, we can be sure to know any
> node name and attribute in any of the following scripts.

Not much change, so I guess that is a good for your idea, though I prefer
udev running scripts under /etc/udev.d. 

Ran on top of your previous mmap patch (that should not matter for glibc),
using glibc + scsi_debug LUNs, and ran with 1024 LUNs (did not measure
that before):

			insmod		rmmod
512 LUNs 		0:42.09		0:32.94
1024 LUNs		1:31.25		1:05.94

Figuring out what is run when with the current hotplug scripts is
confusing.

-- Patrick Mansfield


-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials
Free Linux tutorial presented by Daniel Robbins, President and CEO of
GenToo technologies. Learn everything from fundamentals to system
administration.http://ads.osdn.com/?ad_id\x1470&alloc_id638&op=click
_______________________________________________
Linux-hotplug-devel mailing list  http://linux-hotplug.sourceforge.net
Linux-hotplug-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linux-hotplug-devel