[launchd-changes] [23470] trunk/launchd/src

source_changes at macosforge.org source_changes at macosforge.org
Wed Dec 19 10:13:22 PST 2007


Revision: 23470
          http://trac.macosforge.org/projects/launchd/changeset/23470
Author:   zarzycki at apple.com
Date:     2007-12-19 10:13:19 -0800 (Wed, 19 Dec 2007)

Log Message:
-----------
Better shutdown logging.

Modified Paths:
--------------
    trunk/launchd/src/launchd.c
    trunk/launchd/src/launchd.h
    trunk/launchd/src/launchd_core_logic.c
    trunk/launchd/src/launchd_runtime.c
    trunk/launchd/src/launchd_runtime.h

Modified: trunk/launchd/src/launchd.c
===================================================================
--- trunk/launchd/src/launchd.c	2007-12-19 17:40:56 UTC (rev 23469)
+++ trunk/launchd/src/launchd.c	2007-12-19 18:13:19 UTC (rev 23470)
@@ -95,12 +95,13 @@
 static void handle_pid1_crashes_separately(void);
 static void prep_shutdown_log_dir(void);
 
-static bool re_exec_in_single_user_mode = false;
+static bool re_exec_in_single_user_mode;
 static void *crash_addr;
 static pid_t crash_pid;
 
-bool shutdown_in_progress = false;
-bool network_up = false;
+bool shutdown_in_progress;
+bool fake_shutdown_in_progress;
+bool network_up;
 
 int
 main(int argc, char *const *argv)
@@ -261,12 +262,12 @@
 		prep_shutdown_log_dir();
 	}
 
+	runtime_log_push();
+
 	if (launchd_assumes(gettimeofday(&tvnow, NULL) != -1)) {
 		runtime_syslog(LOG_NOTICE, "Shutdown began at: %lu.%06u", tvnow.tv_sec, tvnow.tv_usec);
 	}
 
-	launchd_log_vm_stats();
-
 	launchd_assert(jobmgr_shutdown(root_jobmgr) != NULL);
 }
 

Modified: trunk/launchd/src/launchd.h
===================================================================
--- trunk/launchd/src/launchd.h	2007-12-19 17:40:56 UTC (rev 23469)
+++ trunk/launchd/src/launchd.h	2007-12-19 18:13:19 UTC (rev 23470)
@@ -32,6 +32,7 @@
 struct conncb;
 
 extern bool shutdown_in_progress;
+extern bool fake_shutdown_in_progress;
 extern bool network_up;
 
 bool init_check_pid(pid_t);

Modified: trunk/launchd/src/launchd_core_logic.c
===================================================================
--- trunk/launchd/src/launchd_core_logic.c	2007-12-19 17:40:56 UTC (rev 23469)
+++ trunk/launchd/src/launchd_core_logic.c	2007-12-19 18:13:19 UTC (rev 23470)
@@ -2481,7 +2481,9 @@
 void
 jobmgr_callback(void *obj, struct kevent *kev)
 {
+	struct timeval tvnow;
 	jobmgr_t jm = obj;
+	job_t ji;
 
 	switch (kev->filter) {
 	case EVFILT_PROC:
@@ -2496,6 +2498,24 @@
 			return launchd_shutdown();
 		case SIGUSR1:
 			return calendarinterval_callback();
+		case SIGUSR2:
+			fake_shutdown_in_progress = true;
+			runtime_setlogmask(LOG_UPTO(LOG_DEBUG));
+
+			runtime_closelog(); /* HACK -- force 'start' time to be set */
+
+			if (getpid() == 1 && jobmgr_assumes(jm, gettimeofday(&tvnow, NULL) != -1)) {
+				jobmgr_log(jm, LOG_NOTICE, "Anticipatory shutdown began at: %lu.%06u", tvnow.tv_sec, tvnow.tv_usec);
+				LIST_FOREACH(ji, &root_jobmgr->jobs, sle) {
+					if (ji->per_user && ji->p) {
+						job_assumes(ji, runtime_kill(ji->p, SIGUSR2) != -1);
+					}
+				}
+			} else {
+				jobmgr_log(jm, LOG_NOTICE, "Anticipatory per-user launchd shutdown");
+			}
+
+			return;
 		default:
 			return (void)jobmgr_assumes(jm, false);
 		}
@@ -4453,6 +4473,7 @@
 	if (!jm) {
 		jobmgr_assumes(jmr, kevent_mod(SIGTERM, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
 		jobmgr_assumes(jmr, kevent_mod(SIGUSR1, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
+		jobmgr_assumes(jmr, kevent_mod(SIGUSR2, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
 		jobmgr_assumes(jmr, kevent_mod(0, EVFILT_FS, EV_ADD, VQ_MOUNT|VQ_UNMOUNT|VQ_UPDATE, 0, jmr) != -1);
 	}
 
@@ -5749,7 +5770,6 @@
 kern_return_t
 job_mig_check_in(job_t j, name_t servicename, mach_port_t *serviceportp)
 {
-	static pid_t last_warned_pid = 0;
 	struct machservice *ms;
 	struct ldcred ldc;
 	job_t jo;
@@ -5768,11 +5788,14 @@
 	}
 
 	if ((jo = machservice_job(ms)) != j) {
+		static pid_t last_warned_pid;
+
 		if (last_warned_pid != ldc.pid) {
 			job_log(j, LOG_NOTICE, "Check-in of Mach service failed. The service \"%s\" is owned by: %s", servicename, jo->label);
 			last_warned_pid = ldc.pid;
 		}
-		 return BOOTSTRAP_NOT_PRIVILEGED;
+
+		return BOOTSTRAP_NOT_PRIVILEGED;
 	}
 	if (machservice_active(ms)) {
 		job_log(j, LOG_WARNING, "Check-in of Mach service failed. Already active: %s", servicename);

Modified: trunk/launchd/src/launchd_runtime.c
===================================================================
--- trunk/launchd/src/launchd_runtime.c	2007-12-19 17:40:56 UTC (rev 23469)
+++ trunk/launchd/src/launchd_runtime.c	2007-12-19 18:13:19 UTC (rev 23470)
@@ -105,7 +105,6 @@
 static mach_port_t drain_reply_port;
 static void runtime_log_uncork_pending_drain(void);
 static kern_return_t runtime_log_pack(vm_offset_t *outval, mach_msg_type_number_t *outvalCnt);
-static void runtime_log_push(void);
 
 static bool logmsg_add(struct runtime_syslog_attr *attr, int err_num, const char *msg);
 static void logmsg_remove(struct logmsg_s *lm);
@@ -116,7 +115,9 @@
 	SIGXFSZ, SIGVTALRM, SIGPROF, SIGWINCH, SIGINFO, SIGUSR1, SIGUSR2
 };
 static sigset_t sigign_set;
+static FILE *ourlogfile;
 
+
 mach_port_t
 runtime_get_kernel_port(void)
 {
@@ -1117,11 +1118,11 @@
 	return close(fd);
 }
 
-static FILE *ourlogfile;
-
 void
 runtime_closelog(void)
 {
+	runtime_log_push();
+
 	if (ourlogfile) {
 		launchd_assumes(fflush(ourlogfile) == 0);
 		launchd_assumes(runtime_fsync(fileno(ourlogfile)) != -1);
@@ -1131,11 +1132,15 @@
 int
 runtime_fsync(int fd)
 {
+#if 0
 	if (do_apple_internal_logging()) {
 		return fcntl(fd, F_FULLFSYNC, NULL);
 	} else {
 		return fsync(fd);
 	}
+#else
+	return fsync(fd);
+#endif
 }
 
 int
@@ -1166,13 +1171,8 @@
 void
 runtime_vsyslog(struct runtime_syslog_attr *attr, const char *message, va_list args)
 {
-	static pthread_mutex_t ourlock = PTHREAD_MUTEX_INITIALIZER;
-	static struct timeval shutdown_start;
-	static struct timeval prev_msg;
-	struct timeval tvnow, tvd_total, tvd_msg_delta = { 0, 0 };
 	int saved_errno = errno;
 	char newmsg[10000];
-	size_t i, j;
 
 	if (attr->priority == LOG_APPLEONLY) {
 		if (do_apple_internal_logging()) {
@@ -1186,70 +1186,11 @@
 		return;
 	}
 
-	if (getpid() != 1 || !shutdown_in_progress) {
-		vsnprintf(newmsg, sizeof(newmsg), message, args);
-		logmsg_add(attr, saved_errno, newmsg);
-		return;
-	}
-
-	if (shutdown_start.tv_sec == 0) {
-		gettimeofday(&shutdown_start, NULL);
-	}
-
-	if (gettimeofday(&tvnow, NULL) == -1) {
-		tvnow.tv_sec = 0;
-		tvnow.tv_usec = 0;
-	}
-
-	pthread_mutex_lock(&ourlock);
-
-	if (ourlogfile == NULL) {
-		rename("/var/log/launchd-shutdown.log", "/var/log/launchd-shutdown.log.1");
-		ourlogfile = fopen("/var/log/launchd-shutdown.log", "a");
-	}
-
-	pthread_mutex_unlock(&ourlock);
-
-	if (ourlogfile == NULL) {
-		return;
-	}
-
-	if (message == NULL) {
-		return;
-	}
-
-	timersub(&tvnow, &shutdown_start, &tvd_total);
-
-	if (prev_msg.tv_sec != 0) {
-		timersub(&tvnow, &prev_msg, &tvd_msg_delta);
-	}
-
-	prev_msg = tvnow;
-
-	snprintf(newmsg, sizeof(newmsg), "%3ld.%06d%4ld.%06d%6u %-40s%6u %-40s ",
-			tvd_total.tv_sec, tvd_total.tv_usec,
-			tvd_msg_delta.tv_sec, tvd_msg_delta.tv_usec,
-			attr->from_pid, attr->from_name,
-			attr->about_pid, attr->about_name);
-
-	for (i = 0, j = strlen(newmsg); message[i];) {
-		if (message[i] == '%' && message[i + 1] == 'm') {
-			char *errs = strerror(saved_errno);
-			strcpy(newmsg + j, errs ? errs : "unknown error");
-			j += strlen(newmsg + j);
-			i += 2;
-		} else {
-			newmsg[j] = message[i];
-			j++;
-			i++;
-		}
-	}
-
-	strcpy(newmsg + j, "\n");
-
-	vfprintf(ourlogfile, newmsg, args);
+	vsnprintf(newmsg, sizeof(newmsg), message, args);
+	logmsg_add(attr, saved_errno, newmsg);
 }
 
+
 bool
 logmsg_add(struct runtime_syslog_attr *attr, int err_num, const char *msg)
 {
@@ -1365,24 +1306,62 @@
 void
 runtime_log_push(void)
 {
+	static pthread_mutex_t ourlock = PTHREAD_MUTEX_INITIALIZER;
+	static struct timeval shutdown_start;
+	struct timeval tvd;
 	mach_msg_type_number_t outvalCnt;
+	struct logmsg_s *lm;
 	vm_offset_t outval;
 
 	if (logmsg_queue_cnt == 0) {
 		launchd_assumes(STAILQ_EMPTY(&logmsg_queue));
 		return;
-	} else if (getpid() == 1) {
+	} else if (getpid() != 1) {
+		if (runtime_log_pack(&outval, &outvalCnt) == 0) {
+			launchd_assumes(_vprocmgr_log_forward(inherited_bootstrap_port, (void *)outval, outvalCnt) == NULL);
+			mig_deallocate(outval, outvalCnt);
+		}
+		return;
+	}
+
+	if (!shutdown_in_progress && !fake_shutdown_in_progress) {
 		runtime_log_uncork_pending_drain();
 		return;
 	}
 
-	if (runtime_log_pack(&outval, &outvalCnt) != 0) {
+	if (shutdown_start.tv_sec == 0) {
+		gettimeofday(&shutdown_start, NULL);
+		launchd_log_vm_stats();
+	}
+
+
+	pthread_mutex_lock(&ourlock);
+
+	if (ourlogfile == NULL) {
+		rename("/var/log/launchd-shutdown.log", "/var/log/launchd-shutdown.log.1");
+		ourlogfile = fopen("/var/log/launchd-shutdown.log", "a");
+	}
+
+	pthread_mutex_unlock(&ourlock);
+
+	if (!ourlogfile) {
 		return;
 	}
 
-	launchd_assumes(_vprocmgr_log_forward(inherited_bootstrap_port, (void *)outval, outvalCnt) == NULL);
+	while ((lm = STAILQ_FIRST(&logmsg_queue))) {
+		timersub(&lm->when, &shutdown_start, &tvd);
 
-	mig_deallocate(outval, outvalCnt);
+		/* don't ask */
+		if (tvd.tv_sec < 0) {
+			tvd.tv_sec = 0;
+			tvd.tv_usec = 0;
+		}
+
+		fprintf(ourlogfile, "%3ld.%06d%6u %-40s%6u %-40s %s\n", tvd.tv_sec, tvd.tv_usec,
+				lm->from_pid, lm->from_name, lm->about_pid, lm->about_name, lm->msg);
+
+		logmsg_remove(lm);
+	}
 }
 
 kern_return_t
@@ -1424,10 +1403,9 @@
 kern_return_t
 runtime_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
 {
-	if (logmsg_queue_cnt == 0) {
-		launchd_assumes(STAILQ_EMPTY(&logmsg_queue));
-		launchd_assumes(drain_reply_port == 0);
+	launchd_assumes(drain_reply_port == 0);
 
+	if ((logmsg_queue_cnt == 0) || shutdown_in_progress || fake_shutdown_in_progress) {
 		drain_reply_port = srp;
 		launchd_assumes(launchd_mport_notify_req(drain_reply_port, MACH_NOTIFY_DEAD_NAME) == KERN_SUCCESS);
 

Modified: trunk/launchd/src/launchd_runtime.h
===================================================================
--- trunk/launchd/src/launchd_runtime.h	2007-12-19 17:40:56 UTC (rev 23469)
+++ trunk/launchd/src/launchd_runtime.h	2007-12-19 18:13:19 UTC (rev 23470)
@@ -149,6 +149,7 @@
 void runtime_closelog(void);
 void runtime_syslog(int pri, const char *message, ...) __attribute__((format(printf, 2, 3)));
 void runtime_vsyslog(struct runtime_syslog_attr *attr, const char *message, va_list args) __attribute__((format(printf, 2, 0)));
+void runtime_log_push(void);
 
 
 kern_return_t launchd_set_bport(mach_port_t name);

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.macosforge.org/pipermail/launchd-changes/attachments/20071219/f832de8c/attachment-0001.html


More information about the launchd-changes mailing list