You can now log baselayout-2 again, through the RC_LOGGER conf.d/rc

setting. The log is temp stored in /lib/rc/init.d/rc.log and appended
to /var/log/rc.log if it's writeable. sysinit cannot be logged in Linux
as we rely on sysinit to bring the system up to a point where we can log.
single user cannot be logged on FreeBSD due to waitpid(0,0,0) incorrectly
waiting for the log daemon in another process group.

ChangeLog

@@ -1,6 +1,15 @@
 # ChangeLog for Gentoo System Intialization ("rc") scripts
 # Copyright 1999-2007 Gentoo Foundation; Distributed under the GPLv2
 
+  31 Oct 2007; Roy Marples <uberlord@gentoo.org>:
+
+    You can now log baselayout-2 again, through the RC_LOGGER conf.d/rc
+    setting. The log is temp stored in /lib/rc/init.d/rc.log and appended
+    to /var/log/rc.log if it's writeable. sysinit cannot be logged in Linux
+    as we rely on sysinit to bring the system up to a point where we can log.
+    single user cannot be logged on FreeBSD due to waitpid(0,0,0) incorrectly
+    waiting for the log daemon in another process group.
+
   30 Oct 2007; Roy Marples <uberlord@gentoo.org>:
 
     You can now spoof the source address for arping as the third parameter

conf.d/rc

@@ -60,6 +60,9 @@ RC_PLUG_SERVICES=""
 # hooked up is a huge pita.
 RC_FORCE_AUTO="no"
 
+# RC_LOGGER launches a logging daemon to log the entire rc process to
+# /var/log/rc.log
+RC_LOGGER="no"
 
 ##############################################################################
 # SERVICE CONFIGURATION VARIABLES

init.d/halt.sh

@@ -44,15 +44,18 @@ if mountinfo -q "${RC_SVCDIR}" && [ -w "${RC_LIBDIR}" ] ; then
 	fi
 	cp -p "${RC_SVCDIR}"/deptree "${RC_SVCDIR}"/depconfig \
 		"${RC_SVCDIR}"/softlevel "${RC_SVCDIR}"/nettree \
+		"${RC_SVCDIR}"/rc.log \
 		"${RC_LIBDIR}" 2>/dev/null
 	umount "${RC_SVCDIR}"
 	rm -rf "${RC_SVCDIR}"/*
 	# Pipe errors to /dev/null as we may have future timestamps
 	cp -p "${RC_LIBDIR}"/deptree "${RC_LIBDIR}"/depconfig \
 		"${RC_LIBDIR}"/softlevel "${RC_LIBDIR}"/nettree \
+		"${RC_LIBDIR}"/rc.log \
 		"${RC_SVCDIR}" 2>/dev/null
 	rm -f "${RC_LIBDIR}"/deptree "${RC_LIBDIR}"/depconfig \
-		"${RC_LIBDIR}"/softlevel "${RC_LIBDIR}"/nettree
+		"${RC_LIBDIR}"/softlevel "${RC_LIBDIR}"/nettree \
+		"${RC_LIBDIR}"/rc.log
 	# Release the memory disk if we used it
 	case "${mnt}" in
 		"/dev/md"[0-9]*) mdconfig -d -u "${mnt#/dev/md*}" ;;

sh/init-common-post.sh

@@ -7,7 +7,7 @@
 if mkdir "${RC_SVCDIR}/.test.$$" 2>/dev/null ; then
 	rmdir "${RC_SVCDIR}/.test.$$"
 	rm -rf $(ls -d1 "${RC_SVCDIR:-/lib/rcscripts/init.d}"/* 2>/dev/null | \
-		grep -Ev "/(deptree|ksoftlevel)$")
+		grep -Ev "/(deptree|ksoftlevel|rc.log)$")
 else
 	mount_svcdir
 fi

src/Makefile

@@ -57,7 +57,8 @@ LIBRCOBJS = librc.o librc-depend.o librc-daemon.o librc-misc.o librc-strlist.o
 LDLIBS_LIBRC =
 
 RCOBJS = checkown.o env-update.o fstabinfo.o mountinfo.o \
-		 rc-depend.o rc-misc.o rc-plugin.o rc-status.o rc-update.o \
+		 rc-depend.o rc-logger.o rc-misc.o rc-plugin.o rc-status.o \
+		 rc-update.o \
 		 runscript.o  start-stop-daemon.o rc.o
 LDLIBS_RC = -leinfo -lrc -lutil
 

src/rc-logger.c

@@ -0,0 +1,235 @@
+/*
+   rc-logger.c
+   Spawns a logging daemon to capture stdout and stderr so we can log
+   them to a buffer and/or files.
+
+   Copyright 2007 Gentoo Foundation
+   Released under the GPLv2
+   */
+
+#include <sys/types.h>
+#include <sys/wait.h>
+#include <ctype.h>
+#include <fcntl.h>
+#include <signal.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <termios.h>
+#include <time.h>
+#include <unistd.h>
+
+#ifdef __linux__
+# include <pty.h>
+#else
+# include <libutil.h>
+#endif
+
+#include "einfo.h"
+#include "rc-logger.h"
+#include "rc-misc.h"
+#include "rc.h"
+
+#define LOGFILE RC_SVCDIR "/rc.log"
+#define PERMLOG "/var/log/rc.log"
+#define MOVELOG "mv " LOGFILE " " PERMLOG ".$$.tmp && cat " PERMLOG \
+	".$$.tmp >>" PERMLOG " 2>/dev/null && rm -f " PERMLOG ".$$.tmp"
+
+static int signal_pipe[2] = { -1, -1 };
+static int fd_stdout = -1;
+static int fd_stderr = -1;
+static const char *runlevel = NULL;
+static bool in_escape = false;
+static bool in_term = false;
+
+static char *logbuf = NULL;
+static size_t logbuf_size = 0;
+static size_t logbuf_len = 0;
+
+pid_t rc_logger_pid = -1;
+int rc_logger_tty = -1;
+bool rc_in_logger = false;
+
+static void write_log (int logfd, const char *buffer, size_t bytes)
+{
+	const char *p = buffer;
+
+	while ((size_t) (p - buffer) < bytes) {
+		switch (*p) {
+			case '\r':
+				goto cont;
+			case '\033':
+				in_escape = true;
+				in_term = false;
+				goto cont;
+			case '\n':
+				in_escape = in_term = false;
+				break;
+			case '[':
+				if (in_escape)
+					in_term = true;
+				break;
+		}
+		
+		if (! in_escape) {
+			write (logfd, p++, 1);
+			continue;
+		}
+
+		if (! in_term || isalpha (*p))
+			in_escape = in_term = false;
+cont:
+		p++;
+	}
+}
+
+static void write_time (FILE *f, const char *s)
+{
+	time_t now = time (NULL);
+	struct tm *tm = localtime (&now);
+
+	fprintf (f, "\nrc %s logging %s at %s\n", runlevel, s, asctime (tm));
+	fflush (f);
+}
+
+void rc_logger_close ()
+{
+	if (signal_pipe[1] > -1) {
+		int sig = SIGTERM;
+		write (signal_pipe[1], &sig, sizeof (sig));
+		close (signal_pipe[1]);
+		signal_pipe[1] = -1;
+	}
+
+	if (rc_logger_pid > 0)
+		waitpid (rc_logger_pid, 0, 0);
+
+	if (fd_stdout > -1)
+		dup2 (fd_stdout, STDOUT_FILENO);
+	if (fd_stderr > -1)
+		dup2 (fd_stderr, STDERR_FILENO);
+}
+
+void rc_logger_open (const char *level)
+{
+	int slave_tty;
+	struct termios tt;
+	struct winsize ws;
+	char *buffer;
+	fd_set rset;
+	int s;
+	size_t bytes;
+	int selfd;
+	int i;
+	FILE *log = NULL;
+
+	if (! isatty (STDOUT_FILENO))
+		return;
+
+	if (! rc_env_bool ("RC_LOGGER"))
+		return;
+
+	if (pipe (signal_pipe) == -1)
+		eerrorx ("pipe: %s", strerror (errno));
+	for (i = 0; i < 2; i++)
+		if ((s = fcntl (signal_pipe[i], F_GETFD, 0) == -1 ||
+			 fcntl (signal_pipe[i], F_SETFD, s | FD_CLOEXEC) == -1))
+			eerrorx ("fcntl: %s", strerror (errno));
+
+	tcgetattr (STDOUT_FILENO, &tt);
+	ioctl (STDOUT_FILENO, TIOCGWINSZ, &ws);
+
+	/* /dev/pts may not be available yet */
+	if (openpty (&rc_logger_tty, &slave_tty, NULL, &tt, &ws))
+		return;
+
+	rc_logger_pid = fork ();
+	switch (rc_logger_pid) {
+		case -1:
+			eerror ("forkpty: %s", strerror (errno));
+			break;
+		case 0:
+			rc_in_logger = true;
+			close (signal_pipe[1]);
+			signal_pipe[1] = -1;
+
+			runlevel = level;
+			if ((log = fopen (LOGFILE, "a")))
+				write_time (log, "started");
+			else {
+				free (logbuf);
+				logbuf_size = RC_LINEBUFFER * 10;
+				logbuf = xmalloc (sizeof (char) * logbuf_size);
+				logbuf_len = 0;
+			}
+
+			buffer = xmalloc (sizeof (char) * RC_LINEBUFFER);
+			selfd = rc_logger_tty > signal_pipe[0] ? rc_logger_tty : signal_pipe[0];
+			while (1) {
+				FD_ZERO (&rset);
+				FD_SET (rc_logger_tty, &rset);
+				FD_SET (signal_pipe[0], &rset);
+
+				if ((s = select (selfd + 1, &rset, NULL, NULL, NULL)) == -1) {
+					eerror ("select: %s", strerror (errno));
+					break;
+				}
+
+				if (s > 0) {
+					if (FD_ISSET (rc_logger_tty, &rset)) {
+						memset (buffer, 0, RC_LINEBUFFER);
+						bytes = read (rc_logger_tty, buffer, RC_LINEBUFFER);
+						write (STDOUT_FILENO, buffer, bytes);
+
+						if (log)
+							write_log (fileno (log), buffer, bytes);
+						else {
+							if (logbuf_size - logbuf_len < bytes) {
+								logbuf_size += RC_LINEBUFFER * 10;
+								logbuf = xrealloc (logbuf, sizeof (char ) *
+												   logbuf_size);
+							}
+
+							memcpy (logbuf + logbuf_len, buffer, bytes);
+							logbuf_len += bytes;
+						}
+					}
+
+					/* Only SIGTERMS signals come down this pipe */
+					if (FD_ISSET (signal_pipe[0], &rset))
+						break;
+				}
+			}
+			free (buffer);
+			if (logbuf) { 
+				if ((log = fopen (LOGFILE, "a"))) {
+					write_time (log, "started");
+					write_log (fileno (log), logbuf, logbuf_len);
+				}
+				free (logbuf);
+			}
+			if (log) {
+				write_time (log, "stopped");
+				fclose (log);
+			}
+
+			/* Try and cat our new logfile to a more permament location and then
+			 * punt it */
+			system (MOVELOG);
+			
+			exit (0);
+		default:
+			setpgid (rc_logger_pid, 0);
+			fd_stdout = dup (STDOUT_FILENO);
+			fd_stderr = dup (STDERR_FILENO);
+			dup2 (slave_tty, STDOUT_FILENO);
+			dup2 (slave_tty, STDERR_FILENO);
+			if (slave_tty != STDIN_FILENO &&
+				slave_tty != STDOUT_FILENO &&
+				slave_tty != STDERR_FILENO)
+				close (slave_tty);
+			close (signal_pipe[0]);
+			signal_pipe[0] = -1;
+			break;
+	}
+}

src/rc-logger.h

@@ -0,0 +1,11 @@
+/*
+   rc-logger.h
+   Copyright 2007 Gentoo Foundation
+   */
+
+pid_t rc_logger_pid;
+int rc_logger_tty;
+extern bool rc_in_logger;
+
+void rc_logger_open (const char *runlevel);
+void rc_logger_close ();

src/rc.c

@@ -16,6 +16,7 @@
 #define SYSLOG_NAMES
 
 #include <sys/types.h>
+#include <sys/ioctl.h>
 #include <sys/stat.h>
 #include <sys/utsname.h>
 #include <sys/wait.h>
@@ -38,6 +39,7 @@
 #include "builtins.h"
 #include "einfo.h"
 #include "rc.h"
+#include "rc-logger.h"
 #include "rc-misc.h"
 #include "rc-plugin.h"
 #include "strlist.h"
@@ -112,15 +114,18 @@ static void cleanup (void)
 		rc_deptree_free (deptree);
 
 		/* Clean runlevel start, stop markers */
-		if (! rc_in_plugin) {
+		if (! rc_in_plugin && ! rc_in_logger) {
 			rmdir (RC_STARTING);
 			rmdir (RC_STOPPING);
+
+			rc_logger_close ();
 		}
 
 		free (runlevel);
 	}
 
 	free (applet);
+	applet = NULL;
 }
 
 static int syslog_decode (char *name, CODE *codetab)
@@ -484,7 +489,7 @@ static void sulogin (bool cont)
 #ifdef __linux__
 	char *e = getenv ("RC_SYS");
 
-	/* VPS systems cannot do an sulogin */
+	/* VPS systems cannot do a sulogin */
 	if (e && strcmp (e, "VPS") == 0) {
 		execl ("/sbin/halt", "/sbin/halt", "-f", (char *) NULL);
 		eerrorx ("%s: unable to exec `/sbin/halt': %s", applet, strerror (errno));
@@ -496,7 +501,7 @@ static void sulogin (bool cont)
 	if (cont) {
 		int status = 0;
 #ifdef __linux__
-		char *tty = ttyname (fileno (stdout));
+		char *tty = ttyname (STDOUT_FILENO);
 #endif
 
 		pid_t pid = vfork ();
@@ -521,6 +526,8 @@ static void sulogin (bool cont)
 		}
 		waitpid (pid, &status, 0);
 	} else {
+		rc_logger_close ();
+
 #ifdef __linux__
 		execle ("/sbin/sulogin", "/sbin/sulogin", (char *) NULL, newenv);
 		eerrorx ("%s: unable to exec `/sbin/sulogin': %s", applet, strerror (errno));
@@ -532,6 +539,8 @@ static void sulogin (bool cont)
 
 static void single_user (void)
 {
+	rc_logger_close ();
+
 #ifdef __linux__
 	execl ("/sbin/telinit", "/sbin/telinit", "S", (char *) NULL);
 	eerrorx ("%s: unable to exec `/sbin/telinit': %s",
@@ -592,12 +601,6 @@ static int get_ksoftlevel (char *buffer, int buffer_len)
 	return (i);
 }
 
-static void wait_for_services ()
-{
-	int status = 0;
-	while (wait (&status) != -1);
-}
-
 static void add_pid (pid_t pid)
 {
 	pidlist_t *sp = service_pids;
@@ -630,6 +633,11 @@ static void remove_pid (pid_t pid)
 	}
 }
 
+static void wait_for_services ()
+{
+	while (waitpid (0, 0, 0) != -1);
+}
+
 static void handle_signal (int sig)
 {
 	int serrno = errno;
@@ -637,6 +645,7 @@ static void handle_signal (int sig)
 	pidlist_t *pl;
 	pid_t pid;
 	int status = 0;
+	struct winsize ws;
 
 	switch (sig) {
 		case SIGCHLD:
@@ -654,6 +663,13 @@ static void handle_signal (int sig)
 				remove_pid (pid);
 			break;
 
+		case SIGWINCH:
+			if (rc_logger_tty >= 0) {
+				ioctl (STDIN_FILENO, TIOCGWINSZ, &ws);
+				ioctl (rc_logger_tty, TIOCSWINSZ, &ws);
+			}
+			break;
+
 		case SIGINT:
 			if (! signame[0])
 				snprintf (signame, sizeof (signame), "SIGINT");
@@ -695,7 +711,8 @@ static void handle_signal (int sig)
 	errno = serrno;
 }
 
-static void run_script (const char *script) {
+static void run_script (const char *script)
+{
 	int status = 0;
 	pid_t pid = vfork ();
 
@@ -824,12 +841,6 @@ int main (int argc, char **argv)
 	RUNLEVEL = getenv ("RUNLEVEL");
 	PREVLEVEL = getenv ("PREVLEVEL");
 
-	/* Setup a signal handler */
-	signal (SIGINT, handle_signal);
-	signal (SIGQUIT, handle_signal);
-	signal (SIGTERM, handle_signal);
-	signal (SIGUSR1, handle_signal);
-
 	/* Ensure our environment is pure
 	   Also, add our configuration to it */
 	env = env_filter ();
@@ -895,13 +906,22 @@ int main (int argc, char **argv)
 	snprintf (pidstr, sizeof (pidstr), "%d", getpid ());
 	setenv ("RC_PID", pidstr, 1);
 
-	interactive = exists (INTERACTIVE);
-	rc_plugin_load ();
-
 	/* Load current softlevel */
 	bootlevel = getenv ("RC_BOOTLEVEL");
 	runlevel = rc_runlevel_get ();
 
+	rc_logger_open (newlevel ? newlevel : runlevel);
+
+	/* Setup a signal handler */
+	signal (SIGINT, handle_signal);
+	signal (SIGQUIT, handle_signal);
+	signal (SIGTERM, handle_signal);
+	signal (SIGUSR1, handle_signal);
+	signal (SIGWINCH, handle_signal);
+
+	interactive = exists (INTERACTIVE);
+	rc_plugin_load ();
+
 	/* Check we're in the runlevel requested, ie from
 	   rc single
 	   rc shutdown
@@ -949,8 +969,8 @@ int main (int argc, char **argv)
 				set_ksoftlevel (cmd);
 				free (cmd);
 			}
-
 #endif
+
 			rc_plugin_run (RC_HOOK_RUNLEVEL_START_OUT, newlevel);
 
 			if (want_interactive ())
@@ -970,6 +990,7 @@ int main (int argc, char **argv)
 			if (! RUNLEVEL ||
 				strcmp (RUNLEVEL, "6") != 0)
 			{
+				rc_logger_close ();
 				execl (SHUTDOWN, SHUTDOWN, "-r", "now", (char *) NULL);
 				eerrorx ("%s: unable to exec `" SHUTDOWN "': %s",
 						 applet, strerror (errno));
@@ -978,6 +999,7 @@ int main (int argc, char **argv)
 			if (! RUNLEVEL ||
 				strcmp (RUNLEVEL, "0") != 0)
 			{
+				rc_logger_close ();
 				execl (SHUTDOWN, SHUTDOWN,
 #ifdef __linux__
 					   "-h",
@@ -1022,6 +1044,15 @@ int main (int argc, char **argv)
 		going_down = true;
 		rc_runlevel_set (newlevel);
 		setenv ("RC_SOFTLEVEL", newlevel, 1);
+
+#ifdef __FreeBSD__
+		/* FIXME: we shouldn't have todo this */
+		/* For some reason, wait_for_services waits for the logger proccess
+		 * to finish as well, but only on FreeBSD. We cannot allow this so
+		 * we stop logging now. */
+		rc_logger_close ();
+#endif
+
 		rc_plugin_run (RC_HOOK_RUNLEVEL_STOP_IN, newlevel);
 	} else {
 		rc_plugin_run (RC_HOOK_RUNLEVEL_STOP_IN, runlevel);
@@ -1283,9 +1314,16 @@ int main (int argc, char **argv)
 
 		/* After all that we can finally stop the blighter! */
 		if (! found) {
-			pid_t pid = rc_service_stop (service);
+			pid_t pid;
-			if (pid > 0 && ! rc_env_bool ("RC_PARALLEL"))
+
-				rc_waitpid (pid);
+			if ((pid = rc_service_stop (service)) > 0) {
+				add_pid (pid);
+
+				if (! rc_env_bool ("RC_PARALLEL")) {
+					rc_waitpid (pid);
+					remove_pid (pid);
+				}
+			}
 		}
 	}
 
@@ -1309,6 +1347,7 @@ int main (int argc, char **argv)
 	if (strcmp (runlevel, RC_LEVEL_SHUTDOWN) == 0 ||
 		strcmp (runlevel, RC_LEVEL_REBOOT) == 0)
 	{
+		rc_logger_close ();
 		execl (HALTSH, HALTSH, runlevel, (char *) NULL);
 		eerrorx ("%s: unable to exec `%s': %s",
 				 applet, HALTSH, strerror (errno));
@@ -1377,12 +1416,13 @@ interactive_option:
 			}
 
 			/* Remember the pid if we're running in parallel */
-			if ((pid = rc_service_start (service)))
+			if ((pid = rc_service_start (service)) > 0) {
 				add_pid (pid);
 
-			if (! rc_env_bool ("RC_PARALLEL")) {
+				if (! rc_env_bool ("RC_PARALLEL")) {
-				rc_waitpid (pid);
+					rc_waitpid (pid);
-				remove_pid (pid);
+					remove_pid (pid);
+				}
 			}
 		}
 	}