<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
"http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head><meta http-equiv="content-type" content="text/html; charset=utf-8" /><style type="text/css"><!--
#msg dl { border: 1px #006 solid; background: #369; padding: 6px; color: #fff; }
#msg dt { float: left; width: 6em; font-weight: bold; }
#msg dt:after { content:':';}
#msg dl, #msg dt, #msg ul, #msg li, #header, #footer { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; }
#msg dl a { font-weight: bold}
#msg dl a:link { color:#fc3; }
#msg dl a:active { color:#ff0; }
#msg dl a:visited { color:#cc6; }
h3 { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; font-weight: bold; }
#msg pre, #msg p { overflow: auto; background: #ffc; border: 1px #fc0 solid; padding: 6px; }
#msg ul { overflow: auto; }
#header, #footer { color: #fff; background: #636; border: 1px #300 solid; padding: 6px; }
#patch { width: 100%; }
#patch h4 {font-family: verdana,arial,helvetica,sans-serif;font-size:10pt;padding:8px;background:#369;color:#fff;margin:0;}
#patch .propset h4, #patch .binary h4 {margin:0;}
#patch pre {padding:0;line-height:1.2em;margin:0;}
#patch .diff {width:100%;background:#eee;padding: 0 0 10px 0;overflow:auto;}
#patch .propset .diff, #patch .binary .diff {padding:10px 0;}
#patch span {display:block;padding:0 10px;}
#patch .modfile, #patch .addfile, #patch .delfile, #patch .propset, #patch .binary, #patch .copfile {border:1px solid #ccc;margin:10px 0;}
#patch ins {background:#dfd;text-decoration:none;display:block;padding:0 10px;}
#patch del {background:#fdd;text-decoration:none;display:block;padding:0 10px;}
#patch .lines, .info {color:#888;background:#fff;}
--></style>
<title>[23470] trunk/launchd/src</title>
</head>
<body>
<div id="msg">
<dl>
<dt>Revision</dt> <dd><a href="http://trac.macosforge.org/projects/launchd/changeset/23470">23470</a></dd>
<dt>Author</dt> <dd>zarzycki@apple.com</dd>
<dt>Date</dt> <dd>2007-12-19 10:13:19 -0800 (Wed, 19 Dec 2007)</dd>
</dl>
<h3>Log Message</h3>
<pre>Better shutdown logging.</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#trunklaunchdsrclaunchdc">trunk/launchd/src/launchd.c</a></li>
<li><a href="#trunklaunchdsrclaunchdh">trunk/launchd/src/launchd.h</a></li>
<li><a href="#trunklaunchdsrclaunchd_core_logicc">trunk/launchd/src/launchd_core_logic.c</a></li>
<li><a href="#trunklaunchdsrclaunchd_runtimec">trunk/launchd/src/launchd_runtime.c</a></li>
<li><a href="#trunklaunchdsrclaunchd_runtimeh">trunk/launchd/src/launchd_runtime.h</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="trunklaunchdsrclaunchdc"></a>
<div class="modfile"><h4>Modified: trunk/launchd/src/launchd.c (23469 => 23470)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -95,12 +95,13 @@
</span><span class="cx"> static void handle_pid1_crashes_separately(void);
</span><span class="cx"> static void prep_shutdown_log_dir(void);
</span><span class="cx">
</span><del>-static bool re_exec_in_single_user_mode = false;
</del><ins>+static bool re_exec_in_single_user_mode;
</ins><span class="cx"> static void *crash_addr;
</span><span class="cx"> static pid_t crash_pid;
</span><span class="cx">
</span><del>-bool shutdown_in_progress = false;
-bool network_up = false;
</del><ins>+bool shutdown_in_progress;
+bool fake_shutdown_in_progress;
+bool network_up;
</ins><span class="cx">
</span><span class="cx"> int
</span><span class="cx"> main(int argc, char *const *argv)
</span><span class="lines">@@ -261,12 +262,12 @@
</span><span class="cx"> prep_shutdown_log_dir();
</span><span class="cx"> }
</span><span class="cx">
</span><ins>+ runtime_log_push();
+
</ins><span class="cx"> if (launchd_assumes(gettimeofday(&tvnow, NULL) != -1)) {
</span><span class="cx"> runtime_syslog(LOG_NOTICE, "Shutdown began at: %lu.%06u", tvnow.tv_sec, tvnow.tv_usec);
</span><span class="cx"> }
</span><span class="cx">
</span><del>- launchd_log_vm_stats();
-
</del><span class="cx"> launchd_assert(jobmgr_shutdown(root_jobmgr) != NULL);
</span><span class="cx"> }
</span><span class="cx">
</span></span></pre></div>
<a id="trunklaunchdsrclaunchdh"></a>
<div class="modfile"><h4>Modified: trunk/launchd/src/launchd.h (23469 => 23470)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -32,6 +32,7 @@
</span><span class="cx"> struct conncb;
</span><span class="cx">
</span><span class="cx"> extern bool shutdown_in_progress;
</span><ins>+extern bool fake_shutdown_in_progress;
</ins><span class="cx"> extern bool network_up;
</span><span class="cx">
</span><span class="cx"> bool init_check_pid(pid_t);
</span></span></pre></div>
<a id="trunklaunchdsrclaunchd_core_logicc"></a>
<div class="modfile"><h4>Modified: trunk/launchd/src/launchd_core_logic.c (23469 => 23470)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -2481,7 +2481,9 @@
</span><span class="cx"> void
</span><span class="cx"> jobmgr_callback(void *obj, struct kevent *kev)
</span><span class="cx"> {
</span><ins>+ struct timeval tvnow;
</ins><span class="cx"> jobmgr_t jm = obj;
</span><ins>+ job_t ji;
</ins><span class="cx">
</span><span class="cx"> switch (kev->filter) {
</span><span class="cx"> case EVFILT_PROC:
</span><span class="lines">@@ -2496,6 +2498,24 @@
</span><span class="cx"> return launchd_shutdown();
</span><span class="cx"> case SIGUSR1:
</span><span class="cx"> return calendarinterval_callback();
</span><ins>+ 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;
</ins><span class="cx"> default:
</span><span class="cx"> return (void)jobmgr_assumes(jm, false);
</span><span class="cx"> }
</span><span class="lines">@@ -4453,6 +4473,7 @@
</span><span class="cx"> if (!jm) {
</span><span class="cx"> jobmgr_assumes(jmr, kevent_mod(SIGTERM, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
</span><span class="cx"> jobmgr_assumes(jmr, kevent_mod(SIGUSR1, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
</span><ins>+ jobmgr_assumes(jmr, kevent_mod(SIGUSR2, EVFILT_SIGNAL, EV_ADD, 0, 0, jmr) != -1);
</ins><span class="cx"> jobmgr_assumes(jmr, kevent_mod(0, EVFILT_FS, EV_ADD, VQ_MOUNT|VQ_UNMOUNT|VQ_UPDATE, 0, jmr) != -1);
</span><span class="cx"> }
</span><span class="cx">
</span><span class="lines">@@ -5749,7 +5770,6 @@
</span><span class="cx"> kern_return_t
</span><span class="cx"> job_mig_check_in(job_t j, name_t servicename, mach_port_t *serviceportp)
</span><span class="cx"> {
</span><del>- static pid_t last_warned_pid = 0;
</del><span class="cx"> struct machservice *ms;
</span><span class="cx"> struct ldcred ldc;
</span><span class="cx"> job_t jo;
</span><span class="lines">@@ -5768,11 +5788,14 @@
</span><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> if ((jo = machservice_job(ms)) != j) {
</span><ins>+ static pid_t last_warned_pid;
+
</ins><span class="cx"> if (last_warned_pid != ldc.pid) {
</span><span class="cx"> job_log(j, LOG_NOTICE, "Check-in of Mach service failed. The service \"%s\" is owned by: %s", servicename, jo->label);
</span><span class="cx"> last_warned_pid = ldc.pid;
</span><span class="cx"> }
</span><del>- return BOOTSTRAP_NOT_PRIVILEGED;
</del><ins>+
+ return BOOTSTRAP_NOT_PRIVILEGED;
</ins><span class="cx"> }
</span><span class="cx"> if (machservice_active(ms)) {
</span><span class="cx"> job_log(j, LOG_WARNING, "Check-in of Mach service failed. Already active: %s", servicename);
</span></span></pre></div>
<a id="trunklaunchdsrclaunchd_runtimec"></a>
<div class="modfile"><h4>Modified: trunk/launchd/src/launchd_runtime.c (23469 => 23470)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -105,7 +105,6 @@
</span><span class="cx"> static mach_port_t drain_reply_port;
</span><span class="cx"> static void runtime_log_uncork_pending_drain(void);
</span><span class="cx"> static kern_return_t runtime_log_pack(vm_offset_t *outval, mach_msg_type_number_t *outvalCnt);
</span><del>-static void runtime_log_push(void);
</del><span class="cx">
</span><span class="cx"> static bool logmsg_add(struct runtime_syslog_attr *attr, int err_num, const char *msg);
</span><span class="cx"> static void logmsg_remove(struct logmsg_s *lm);
</span><span class="lines">@@ -116,7 +115,9 @@
</span><span class="cx"> SIGXFSZ, SIGVTALRM, SIGPROF, SIGWINCH, SIGINFO, SIGUSR1, SIGUSR2
</span><span class="cx"> };
</span><span class="cx"> static sigset_t sigign_set;
</span><ins>+static FILE *ourlogfile;
</ins><span class="cx">
</span><ins>+
</ins><span class="cx"> mach_port_t
</span><span class="cx"> runtime_get_kernel_port(void)
</span><span class="cx"> {
</span><span class="lines">@@ -1117,11 +1118,11 @@
</span><span class="cx"> return close(fd);
</span><span class="cx"> }
</span><span class="cx">
</span><del>-static FILE *ourlogfile;
-
</del><span class="cx"> void
</span><span class="cx"> runtime_closelog(void)
</span><span class="cx"> {
</span><ins>+ runtime_log_push();
+
</ins><span class="cx"> if (ourlogfile) {
</span><span class="cx"> launchd_assumes(fflush(ourlogfile) == 0);
</span><span class="cx"> launchd_assumes(runtime_fsync(fileno(ourlogfile)) != -1);
</span><span class="lines">@@ -1131,11 +1132,15 @@
</span><span class="cx"> int
</span><span class="cx"> runtime_fsync(int fd)
</span><span class="cx"> {
</span><ins>+#if 0
</ins><span class="cx"> if (do_apple_internal_logging()) {
</span><span class="cx"> return fcntl(fd, F_FULLFSYNC, NULL);
</span><span class="cx"> } else {
</span><span class="cx"> return fsync(fd);
</span><span class="cx"> }
</span><ins>+#else
+ return fsync(fd);
+#endif
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> int
</span><span class="lines">@@ -1166,13 +1171,8 @@
</span><span class="cx"> void
</span><span class="cx"> runtime_vsyslog(struct runtime_syslog_attr *attr, const char *message, va_list args)
</span><span class="cx"> {
</span><del>- 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 };
</del><span class="cx"> int saved_errno = errno;
</span><span class="cx"> char newmsg[10000];
</span><del>- size_t i, j;
</del><span class="cx">
</span><span class="cx"> if (attr->priority == LOG_APPLEONLY) {
</span><span class="cx"> if (do_apple_internal_logging()) {
</span><span class="lines">@@ -1186,70 +1186,11 @@
</span><span class="cx"> return;
</span><span class="cx"> }
</span><span class="cx">
</span><del>- 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);
</del><ins>+ vsnprintf(newmsg, sizeof(newmsg), message, args);
+ logmsg_add(attr, saved_errno, newmsg);
</ins><span class="cx"> }
</span><span class="cx">
</span><ins>+
</ins><span class="cx"> bool
</span><span class="cx"> logmsg_add(struct runtime_syslog_attr *attr, int err_num, const char *msg)
</span><span class="cx"> {
</span><span class="lines">@@ -1365,24 +1306,62 @@
</span><span class="cx"> void
</span><span class="cx"> runtime_log_push(void)
</span><span class="cx"> {
</span><ins>+ static pthread_mutex_t ourlock = PTHREAD_MUTEX_INITIALIZER;
+ static struct timeval shutdown_start;
+ struct timeval tvd;
</ins><span class="cx"> mach_msg_type_number_t outvalCnt;
</span><ins>+ struct logmsg_s *lm;
</ins><span class="cx"> vm_offset_t outval;
</span><span class="cx">
</span><span class="cx"> if (logmsg_queue_cnt == 0) {
</span><span class="cx"> launchd_assumes(STAILQ_EMPTY(&logmsg_queue));
</span><span class="cx"> return;
</span><del>- } else if (getpid() == 1) {
</del><ins>+ } 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) {
</ins><span class="cx"> runtime_log_uncork_pending_drain();
</span><span class="cx"> return;
</span><span class="cx"> }
</span><span class="cx">
</span><del>- if (runtime_log_pack(&outval, &outvalCnt) != 0) {
</del><ins>+ 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) {
</ins><span class="cx"> return;
</span><span class="cx"> }
</span><span class="cx">
</span><del>- launchd_assumes(_vprocmgr_log_forward(inherited_bootstrap_port, (void *)outval, outvalCnt) == NULL);
</del><ins>+ while ((lm = STAILQ_FIRST(&logmsg_queue))) {
+ timersub(&lm->when, &shutdown_start, &tvd);
</ins><span class="cx">
</span><del>- mig_deallocate(outval, outvalCnt);
</del><ins>+ /* 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);
+ }
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> kern_return_t
</span><span class="lines">@@ -1424,10 +1403,9 @@
</span><span class="cx"> kern_return_t
</span><span class="cx"> runtime_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
</span><span class="cx"> {
</span><del>- if (logmsg_queue_cnt == 0) {
- launchd_assumes(STAILQ_EMPTY(&logmsg_queue));
- launchd_assumes(drain_reply_port == 0);
</del><ins>+ launchd_assumes(drain_reply_port == 0);
</ins><span class="cx">
</span><ins>+ if ((logmsg_queue_cnt == 0) || shutdown_in_progress || fake_shutdown_in_progress) {
</ins><span class="cx"> drain_reply_port = srp;
</span><span class="cx"> launchd_assumes(launchd_mport_notify_req(drain_reply_port, MACH_NOTIFY_DEAD_NAME) == KERN_SUCCESS);
</span><span class="cx">
</span></span></pre></div>
<a id="trunklaunchdsrclaunchd_runtimeh"></a>
<div class="modfile"><h4>Modified: trunk/launchd/src/launchd_runtime.h (23469 => 23470)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -149,6 +149,7 @@
</span><span class="cx"> void runtime_closelog(void);
</span><span class="cx"> void runtime_syslog(int pri, const char *message, ...) __attribute__((format(printf, 2, 3)));
</span><span class="cx"> void runtime_vsyslog(struct runtime_syslog_attr *attr, const char *message, va_list args) __attribute__((format(printf, 2, 0)));
</span><ins>+void runtime_log_push(void);
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> kern_return_t launchd_set_bport(mach_port_t name);
</span></span></pre>
</div>
</div>
</body>
</html>