[launchd-changes] [23087] trunk/launchd/src
source_changes at macosforge.org
source_changes at macosforge.org
Mon Feb 19 15:21:02 PST 2007
Revision: 23087
http://trac.macosforge.org/projects/launchd/changeset/23087
Author: zarzycki at apple.com
Date: 2007-02-19 15:21:02 -0800 (Mon, 19 Feb 2007)
Log Message:
-----------
More debugging goo.
Modified Paths:
--------------
trunk/launchd/src/launchd.c
trunk/launchd/src/launchd_core_logic.c
trunk/launchd/src/launchd_runtime.c
trunk/launchd/src/launchd_runtime.h
trunk/launchd/src/launchd_unix_ipc.c
trunk/launchd/src/liblaunch_private.h
Modified: trunk/launchd/src/launchd.c
===================================================================
--- trunk/launchd/src/launchd.c 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/launchd.c 2007-02-19 23:21:02 UTC (rev 23087)
@@ -50,7 +50,6 @@
#include <unistd.h>
#include <signal.h>
#include <errno.h>
-#include <syslog.h>
#include <libgen.h>
#include <stdio.h>
#include <stdlib.h>
@@ -137,9 +136,6 @@
launchd_runtime_init();
- openlog(getprogname(), LOG_PID|LOG_CONS, LOG_LAUNCHD);
- setlogmask(LOG_UPTO(/* LOG_DEBUG */ LOG_NOTICE));
-
for (i = 0; i < (sizeof(sigigns) / sizeof(int)); i++) {
launchd_assumes(signal(sigigns[i], SIG_IGN) != SIG_ERR);
}
@@ -217,7 +213,7 @@
doom_why = "trying to read/write";
case SIGILL:
case SIGFPE:
- syslog(LOG_EMERG, "We crashed %s: %p (sent by PID %u)", doom_why, crash_addr, crash_pid);
+ runtime_syslog(LOG_EMERG, "We crashed %s: %p (sent by PID %u)", doom_why, crash_addr, crash_pid);
sync();
sleep(3);
/* the kernel will panic() when PID 1 exits */
@@ -280,7 +276,7 @@
void
launchd_single_user(void)
{
- syslog(LOG_NOTICE, "Going to single-user mode");
+ runtime_syslog(LOG_NOTICE, "Going to single-user mode");
re_exec_in_single_user_mode = true;
@@ -314,7 +310,7 @@
launchd_assumes(close(tmpfd) == 0);
} else {
if (-1 == (tmpfd = open(path, flags | O_NOCTTY, DEFFILEMODE))) {
- syslog(LOG_ERR, "open(\"%s\", ...): %m", path);
+ runtime_syslog(LOG_ERR, "open(\"%s\", ...): %m", path);
} else if (tmpfd != fd) {
launchd_assumes(dup2(tmpfd, fd) != -1);
launchd_assumes(close(tmpfd) == 0);
@@ -433,5 +429,5 @@
}
}
- syslog(LOG_NOTICE, "Bug: %s:%u (%s):%u: %s", file, line, buf, saved_errno, test);
+ runtime_syslog(LOG_NOTICE, "Bug: %s:%u (%s):%u: %s", file, line, buf, saved_errno, test);
}
Modified: trunk/launchd/src/launchd_core_logic.c
===================================================================
--- trunk/launchd/src/launchd_core_logic.c 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/launchd_core_logic.c 2007-02-19 23:21:02 UTC (rev 23087)
@@ -57,7 +57,6 @@
#include <unistd.h>
#include <signal.h>
#include <errno.h>
-#include <syslog.h>
#include <libgen.h>
#include <stdio.h>
#include <stdlib.h>
@@ -225,7 +224,7 @@
static pid_t jobmgr_fork(jobmgr_t jm);
static void jobmgr_setup_env_from_other_jobs(jobmgr_t jm);
static struct machservice *jobmgr_lookup_service(jobmgr_t jm, const char *name, bool check_parent);
-static void jobmgr_logv(jobmgr_t jm, int pri, int err, const char *msg, va_list ap);
+static void jobmgr_logv(jobmgr_t jm, int pri, int err, const char *msg, va_list ap) __attribute__((format(printf, 4, 0)));
static void jobmgr_log(jobmgr_t jm, int pri, const char *msg, ...) __attribute__((format(printf, 3, 4)));
/* static void jobmgr_log_error(jobmgr_t jm, int pri, const char *msg, ...) __attribute__((format(printf, 3, 4))); */
static void jobmgr_log_bug(jobmgr_t jm, const char *rcs_rev, const char *path, unsigned int line, const char *test);
@@ -274,7 +273,7 @@
mode_t mask;
unsigned int globargv:1, wait4debugger:1, unload_at_exit:1, stall_before_exec:1, only_once:1,
currently_ignored:1, forced_peers_to_demand_mode:1, setnice:1, hopefully_exits_last:1, removal_pending:1,
- wait4pipe_eof:1, sent_sigkill:1;
+ wait4pipe_eof:1, sent_sigkill:1, debug_before_kill:1;
char label[0];
};
@@ -317,7 +316,7 @@
static void job_kill(job_t j);
static void job_uncork_fork(job_t j);
static void job_log_stdouterr(job_t j);
-static void job_logv(job_t j, int pri, int err, const char *msg, va_list ap);
+static void job_logv(job_t j, int pri, int err, const char *msg, va_list ap) __attribute__((format(printf, 4, 0)));
static void job_log_error(job_t j, int pri, const char *msg, ...) __attribute__((format(printf, 3, 4)));
static void job_log_bug(job_t j, const char *rcs_rev, const char *path, unsigned int line, const char *test);
static kern_return_t job_handle_mpm_wait(job_t j, mach_port_t srp, int *waitstatus);
@@ -536,6 +535,10 @@
}
}
+ if (debug_shutdown_hangs && jm->parentmgr == NULL && getpid() == 1) {
+ jobmgr_assumes(jm, kevent_mod((uintptr_t)jm, EVFILT_TIMER, EV_ADD, NOTE_SECONDS, 3, jm) != -1);
+ }
+
return jobmgr_do_garbage_collection(jm);
}
@@ -577,8 +580,10 @@
if (jm->parentmgr) {
SLIST_REMOVE(&jm->parentmgr->submgrs, jm, jobmgr_s, sle);
} else if (getpid() == 1) {
+ jobmgr_log(jm, LOG_DEBUG, "About to call reboot(0x%x).", jm->reboot_flags);
jobmgr_assumes(jm, reboot(jm->reboot_flags) != -1);
} else {
+ jobmgr_log(jm, LOG_DEBUG, "About to exit.");
exit(EXIT_SUCCESS);
}
@@ -1081,6 +1086,8 @@
case 'E':
if (strcasecmp(key, LAUNCH_JOBKEY_ENABLEGLOBBING) == 0) {
j->globargv = value;
+ } else if (strcasecmp(key, LAUNCH_JOBKEY_ENTERKERNELDEBUGGERBEFOREKILL) == 0) {
+ j->debug_before_kill = value;
}
break;
case 'w':
@@ -1459,7 +1466,7 @@
return NULL;
} else if (label[0] == '\0' || (strncasecmp(label, "", strlen("com.apple.launchd")) == 0) ||
(strtol(label, NULL, 10) != 0)) {
- syslog(LOG_ERR, "Somebody attempted to use a reserved prefix for a label: %s", label);
+ jobmgr_log(root_jobmgr, LOG_ERR, "Somebody attempted to use a reserved prefix for a label: %s", label);
/* the empty string, com.apple.launchd and number prefixes for labels are reserved */
errno = EINVAL;
return NULL;
@@ -1810,18 +1817,16 @@
} else if (&j->exit_timeout == ident) {
if (j->sent_sigkill) {
struct timeval tvd, tve;
- double delta;
job_assumes(j, gettimeofday(&tve, NULL) != -1);
timersub(&tve, &j->sent_sigterm_time, &tvd);
- delta = (double)tvd.tv_sec + (double)tvd.tv_usec / (double)1000000;
- delta -= (double)j->exit_timeout;
- job_log(j, LOG_ERR, "Did not die after sending SIGKILL %f seconds ago...", delta);
- if (debug_shutdown_hangs && delta > 60) {
+ job_log(j, LOG_ERR, "Did not die after sending SIGKILL %lu seconds ago...", tvd.tv_sec);
+ } else {
+ job_force_sampletool(j);
+ if (j->debug_before_kill) {
+ job_log(j, LOG_NOTICE, "Exit timeout elapsed. Entering the kernel debugger.");
job_assumes(j, host_reboot(mach_host_self(), HOST_REBOOT_DEBUGGER) == KERN_SUCCESS);
}
- } else {
- job_force_sampletool(j);
job_log(j, LOG_WARNING, "Exit timeout elapsed (%u seconds). Killing.", j->exit_timeout);
job_kill(j);
}
@@ -1854,6 +1859,9 @@
return (void)jobmgr_assumes(jm, false);
}
break;
+ case EVFILT_TIMER:
+ jobmgr_log(jm, LOG_NOTICE, "Still alive with %u children.", total_children);
+ break;
default:
return (void)jobmgr_assumes(jm, false);
}
@@ -2512,7 +2520,7 @@
if (jm->parentmgr) {
jobmgr_logv(jm->parentmgr, pri, 0, newmsg, ap);
} else {
- vsyslog(pri, newmsg, ap);
+ runtime_vsyslog(pri, newmsg, ap);
}
}
@@ -3749,11 +3757,16 @@
goto out;
}
+ job_log(j, LOG_DEBUG, "Waiting for 'sample' to finish.");
+
if (!job_assumes(j, waitpid(sp, &wstatus, 0) != -1)) {
goto out;
}
- sync();
+ /*
+ * This won't work if the VFS or filesystems are sick:
+ * sync();
+ */
if (!job_assumes(j, WIFEXITED(wstatus) && WEXITSTATUS(wstatus) == 0)) {
goto out;
@@ -3789,12 +3802,15 @@
}
if (logfile_fd != -1) {
+ job_assumes(j, fcntl(logfile_fd, F_FULLFSYNC, 0) != -1);
job_assumes(j, close(logfile_fd) != -1);
}
if (console_fd != -1) {
job_assumes(j, close(console_fd) != -1);
}
+
+ job_log(j, LOG_DEBUG, "Finished sampling.");
}
bool
Modified: trunk/launchd/src/launchd_runtime.c
===================================================================
--- trunk/launchd/src/launchd_runtime.c 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/launchd_runtime.c 2007-02-19 23:21:02 UTC (rev 23087)
@@ -124,6 +124,9 @@
pthread_attr_setstacksize(&attr, PTHREAD_STACK_MIN);
launchd_assert(pthread_create(&demand_thread, &attr, mport_demand_loop, NULL) == 0);
pthread_attr_destroy(&attr);
+
+ openlog(getprogname(), LOG_PID|LOG_CONS, LOG_LAUNCHD);
+ setlogmask(LOG_UPTO(/* LOG_DEBUG */ LOG_NOTICE));
}
void *
@@ -352,7 +355,7 @@
break;
}
- syslog(level, "KEVENT: ident = %s filter = %s flags = %s fflags = %s data = 0x%x udata = %p",
+ runtime_syslog(level, "KEVENT: ident = %s filter = %s flags = %s fflags = %s data = 0x%lx udata = %p",
ident_buf, filter_str, flags_buf, fflags_buf, kev->data, kev->udata);
}
@@ -849,70 +852,78 @@
}
}
-#if 0
-
-/* For ugly debug scenarios where syslogd is long gone (for example, during system shutdown). */
-
void
-closelog(void)
+runtime_openlog(const char *ident, int logopt, int facility)
{
+ openlog(ident, logopt, facility);
}
-void
-openlog(const char *ident, int logopt, int facility)
-{
- ident = 0;
- logopt = 0;
- facility = 0;
-}
-
int
-setlogmask(int maskpri)
+runtime_setlogmask(int maskpri)
{
- return maskpri;
+ return setlogmask(maskpri);
}
void
-syslog(int priority, const char *message, ...)
+runtime_syslog(int priority, const char *message, ...)
{
va_list ap;
va_start(ap, message);
- vsyslog(priority, message, ap);
+ runtime_vsyslog(priority, message, ap);
va_end(ap);
}
void
-vsyslog(int priority, const char *message, va_list args)
+runtime_vsyslog(int priority, const char *message, va_list args)
{
static pthread_mutex_t ourlock = PTHREAD_MUTEX_INITIALIZER;
static FILE *ourlogfile = NULL;
+ static struct timeval shutdown_start = { 0, 0 };
+ struct timeval tvnow, tvd;
int saved_errno = errno;
char newmsg[10000];
+ double float_time;
size_t i, j;
+ if (!(debug_shutdown_hangs && getpid() == 1)) {
+ return vsyslog(priority, message, args);
+ }
+
+ 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_raw.log", "/var/log/launchd_raw-old.log");
- ourlogfile = fopen("/var/log/launchd_raw.log", "a");
- chmod("/var/log/launchd_raw.log", DEFFILEMODE);
+ 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;
+ syslog(LOG_ERR, "Couldn't open alternate log file!");
+ return vsyslog(priority, message, args);
}
if (message == NULL) {
return;
}
- snprintf(newmsg, sizeof(newmsg), "p%u pp%u\t", getpid(), getppid());
+ timersub(&tvnow, &shutdown_start, &tvd);
+ float_time = (double)tvd.tv_sec + (double)tvd.tv_usec / (double)1000000;
+ snprintf(newmsg, sizeof(newmsg), "%f\t", float_time);
+
for (i = 0, j = strlen(newmsg); message[i];) {
if (message[i] == '%' && message[i + 1] == 'm') {
char *errs = strerror(saved_errno);
@@ -932,5 +943,3 @@
fflush(ourlogfile);
}
-
-#endif
Modified: trunk/launchd/src/launchd_runtime.h
===================================================================
--- trunk/launchd/src/launchd_runtime.h 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/launchd_runtime.h 2007-02-19 23:21:02 UTC (rev 23087)
@@ -24,6 +24,7 @@
#include <sys/types.h>
#include <bsm/libbsm.h>
#include <stdbool.h>
+#include <syslog.h>
struct ldcred {
uid_t euid;
@@ -68,6 +69,12 @@
int kevent_mod(uintptr_t ident, short filter, u_short flags, u_int fflags, intptr_t data, void *udata);
+void runtime_openlog(const char *ident, int logopt, int facility);
+int runtime_setlogmask(int maskpri);
+void runtime_syslog(int priority, const char *message, ...) __attribute__((format(printf, 2, 3)));
+void runtime_vsyslog(int priority, const char *message, va_list args) __attribute__((format(printf, 2, 0)));
+
+
kern_return_t launchd_set_bport(mach_port_t name);
kern_return_t launchd_get_bport(mach_port_t *name);
kern_return_t launchd_mport_notify_req(mach_port_t name, mach_msg_id_t which);
Modified: trunk/launchd/src/launchd_unix_ipc.c
===================================================================
--- trunk/launchd/src/launchd_unix_ipc.c 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/launchd_unix_ipc.c 2007-02-19 23:21:02 UTC (rev 23087)
@@ -39,7 +39,6 @@
#include <unistd.h>
#include <signal.h>
#include <errno.h>
-#include <syslog.h>
#include <libgen.h>
#include <stdio.h>
#include <stdlib.h>
@@ -81,9 +80,9 @@
}
if (-1 == unlink(sockpath)) {
- syslog(LOG_WARNING, "unlink(\"%s\"): %m", sockpath);
+ runtime_syslog(LOG_WARNING, "unlink(\"%s\"): %m", sockpath);
} else if (-1 == rmdir(sockdir)) {
- syslog(LOG_WARNING, "rmdir(\"%s\"): %m", sockdir);
+ runtime_syslog(LOG_WARNING, "rmdir(\"%s\"): %m", sockdir);
}
}
@@ -115,11 +114,11 @@
stat(ourdir, &sb);
if (!S_ISDIR(sb.st_mode)) {
errno = EEXIST;
- syslog(LOG_ERR, "mkdir(\"%s\"): %m", LAUNCHD_SOCK_PREFIX);
+ runtime_syslog(LOG_ERR, "mkdir(\"%s\"): %m", LAUNCHD_SOCK_PREFIX);
goto out_bad;
}
} else {
- syslog(LOG_ERR, "mkdir(\"%s\"): %m", ourdir);
+ runtime_syslog(LOG_ERR, "mkdir(\"%s\"): %m", ourdir);
goto out_bad;
}
}
@@ -133,7 +132,7 @@
if (unlink(sun.sun_path) == -1 && errno != ENOENT) {
if (errno != EROFS) {
- syslog(LOG_ERR, "unlink(\"thesocket\"): %m");
+ runtime_syslog(LOG_ERR, "unlink(\"thesocket\"): %m");
}
goto out_bad;
}
@@ -148,18 +147,18 @@
if (r == -1) {
if (errno != EROFS) {
- syslog(LOG_ERR, "bind(\"thesocket\"): %m");
+ runtime_syslog(LOG_ERR, "bind(\"thesocket\"): %m");
}
goto out_bad;
}
if (listen(fd, SOMAXCONN) == -1) {
- syslog(LOG_ERR, "listen(\"thesocket\"): %m");
+ runtime_syslog(LOG_ERR, "listen(\"thesocket\"): %m");
goto out_bad;
}
if (kevent_mod(fd, EVFILT_READ, EV_ADD, 0, 0, &kqipc_listen_callback) == -1) {
- syslog(LOG_ERR, "kevent_mod(\"thesocket\", EVFILT_READ): %m");
+ runtime_syslog(LOG_ERR, "kevent_mod(\"thesocket\", EVFILT_READ): %m");
goto out_bad;
}
@@ -213,7 +212,7 @@
if (kev->filter == EVFILT_READ) {
if (launchd_msg_recv(c->conn, ipc_readmsg, c) == -1 && errno != EAGAIN) {
if (errno != ECONNRESET) {
- syslog(LOG_DEBUG, "%s(): recv: %m", __func__);
+ runtime_syslog(LOG_DEBUG, "%s(): recv: %m", __func__);
}
ipc_close(c);
}
@@ -221,14 +220,14 @@
r = launchd_msg_send(c->conn, NULL);
if (r == -1) {
if (errno != EAGAIN) {
- syslog(LOG_DEBUG, "%s(): send: %m", __func__);
+ runtime_syslog(LOG_DEBUG, "%s(): send: %m", __func__);
ipc_close(c);
}
} else if (r == 0) {
kevent_mod(launchd_getfd(c->conn), EVFILT_WRITE, EV_DELETE, 0, 0, NULL);
}
} else {
- syslog(LOG_DEBUG, "%s(): unknown filter type!", __func__);
+ runtime_syslog(LOG_DEBUG, "%s(): unknown filter type!", __func__);
ipc_close(c);
}
}
@@ -310,7 +309,7 @@
if (errno == EAGAIN) {
kevent_mod(launchd_getfd(rmc.c->conn), EVFILT_WRITE, EV_ADD, 0, 0, &rmc.c->kqconn_callback);
} else {
- syslog(LOG_DEBUG, "launchd_msg_send() == -1: %m");
+ runtime_syslog(LOG_DEBUG, "launchd_msg_send() == -1: %m");
ipc_close(rmc.c);
}
}
@@ -332,7 +331,7 @@
if (rmc->c->j) {
job_log(rmc->c->j, LOG_DEBUG, "Unix IPC request: %s", cmd);
} else {
- syslog(LOG_DEBUG, "Unix IPC request: %s", cmd);
+ runtime_syslog(LOG_DEBUG, "Unix IPC request: %s", cmd);
}
if (data == NULL) {
@@ -471,7 +470,7 @@
ltmpsz = launch_data_get_opaque_size(in);
if (ltmpsz > sizeof(l)) {
- syslog(LOG_WARNING, "Too much rlimit data sent!");
+ runtime_syslog(LOG_WARNING, "Too much rlimit data sent!");
ltmpsz = sizeof(l);
}
@@ -507,12 +506,12 @@
if (gval > 0) {
launchd_assumes(sysctl(gmib, 2, NULL, NULL, &gval, sizeof(gval)) != -1);
} else {
- syslog(LOG_WARNING, "sysctl(\"%s\"): can't be zero", gstr);
+ runtime_syslog(LOG_WARNING, "sysctl(\"%s\"): can't be zero", gstr);
}
if (pval > 0) {
launchd_assumes(sysctl(pmib, 2, NULL, NULL, &pval, sizeof(pval)) != -1);
} else {
- syslog(LOG_WARNING, "sysctl(\"%s\"): can't be zero", pstr);
+ runtime_syslog(LOG_WARNING, "sysctl(\"%s\"): can't be zero", pstr);
}
}
launchd_assumes(setrlimit(i, ltmp + i) != -1);
Modified: trunk/launchd/src/liblaunch_private.h
===================================================================
--- trunk/launchd/src/liblaunch_private.h 2007-02-19 18:04:45 UTC (rev 23086)
+++ trunk/launchd/src/liblaunch_private.h 2007-02-19 23:21:02 UTC (rev 23087)
@@ -49,6 +49,8 @@
#define LAUNCH_KEY_BATCHCONTROL "BatchControl"
#define LAUNCH_KEY_BATCHQUERY "BatchQuery"
+#define LAUNCH_JOBKEY_ENTERKERNELDEBUGGERBEFOREKILL "EnterKernelDebuggerBeforeKill"
+
#define LAUNCH_JOBKEY_MACH_KUNCSERVER "kUNCServer"
#define LAUNCH_JOBKEY_MACH_EXCEPTIONSERVER "ExceptionServer"
#define LAUNCH_JOBKEY_MACH_TASKSPECIALPORT "TaskSpecialPort"
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.macosforge.org/pipermail/launchd-changes/attachments/20070219/8195c155/attachment.html
More information about the launchd-changes
mailing list