]> git.saurik.com Git - apple/launchd.git/blobdiff - src/log.c
launchd-442.21.tar.gz
[apple/launchd.git] / src / log.c
diff --git a/src/log.c b/src/log.c
new file mode 100644 (file)
index 0000000..d74e418
--- /dev/null
+++ b/src/log.c
@@ -0,0 +1,398 @@
+#include <dispatch/dispatch.h>
+#include <assumes.h>
+#include "job_reply.h"
+
+#include "launchd.h"
+#include "launch_internal.h"
+#include "vproc_internal.h"
+#include "log.h"
+
+#define ROUND_TO_64BIT_WORD_SIZE(x)    ((x + 7) & ~7)
+#define LAUNCHD_DEBUG_LOG "launchd-debug.%s.log"
+#define LAUNCHD_PERF_LOG "launchd-perf.%s.log"
+#define LAUNCHD_SHUTDOWN_LOG "launchd-shutdown.%s.log"
+#define LAUNCHD_LOWLEVEL_LOG "launchd-lowlevel.%s.log"
+
+char *launchd_username = "unknown";
+char *launchd_label = "com.apple.launchd.unknown";
+mach_port_t launchd_drain_reply_port;
+bool launchd_var_available = false;
+int64_t launchd_system_start;
+
+static FILE *_launchd_shutdown_log;
+static FILE *_launchd_debug_log;
+static FILE *_launchd_perf_log;
+static STAILQ_HEAD(, logmsg_s) _launchd_logq = STAILQ_HEAD_INITIALIZER(_launchd_logq);
+static size_t _launchd_logq_sz;
+static size_t _launchd_logq_cnt;
+static int _launchd_log_up2 = LOG_UPTO(LOG_NOTICE);
+
+static int64_t _launchd_shutdown_start;
+
+struct _launchd_open_log_ctx_s {
+       const char *path;
+       FILE **filep;
+};
+
+static void
+_launchd_open_log_once(void *ctx)
+{
+       struct _launchd_open_log_ctx_s *ctx2 = ctx;
+       const char *path = ctx2->path;
+       FILE **filep = ctx2->filep;
+
+       char saved[PATH_MAX];
+       snprintf(saved, sizeof(saved), "%s.1", path);
+       (void)rename(path, saved);
+
+       FILE *file = fopen(path, "w");
+       if (file) {
+               (void)_fd(fileno(file));
+               *filep = file;
+       } else if (launchd_console) {
+               fprintf(launchd_console, "Could not open %s: %d: %s\n", path, errno, strerror(errno));
+       }
+}
+
+static void
+_launchd_shutdown_start_once(void *ctx __attribute__((unused)))
+{
+       _launchd_shutdown_start = runtime_get_wall_time();
+}
+
+int
+runtime_setlogmask(int maskpri)
+{
+       _launchd_log_up2 = maskpri;
+       return _launchd_log_up2;
+}
+
+static bool
+_logmsg_add(struct launchd_syslog_attr *attr, int err_num, const char *msg)
+{
+       size_t lm_sz = sizeof(struct logmsg_s) + strlen(msg) + strlen(attr->from_name) + strlen(attr->about_name) + strlen(attr->session_name) + 4;
+       char *data_off;
+       struct logmsg_s *lm;
+
+       /* Force the unpacking for the log_drain cause unalignment faults. */
+       lm_sz = ROUND_TO_64BIT_WORD_SIZE(lm_sz);
+
+       if (unlikely((lm = calloc(1, lm_sz)) == NULL)) {
+               return false;
+       }
+
+       data_off = lm->data;
+
+       lm->when = runtime_get_wall_time();
+       lm->from_pid = attr->from_pid;
+       lm->about_pid = attr->about_pid;
+       lm->err_num = err_num;
+       lm->pri = attr->priority;
+       lm->obj_sz = lm_sz;
+       lm->msg = data_off;
+       data_off += sprintf(data_off, "%s", msg) + 1;
+       lm->from_name = data_off;
+       data_off += sprintf(data_off, "%s", attr->from_name) + 1;
+       lm->about_name = data_off;
+       data_off += sprintf(data_off, "%s", attr->about_name) + 1;
+       lm->session_name = data_off;
+       data_off += sprintf(data_off, "%s", attr->session_name) + 1;
+
+       STAILQ_INSERT_TAIL(&_launchd_logq, lm, sqe);
+       _launchd_logq_sz += lm_sz;
+       _launchd_logq_cnt++;
+
+       return true;
+}
+
+static void
+_logmsg_remove(struct logmsg_s *lm)
+{
+       STAILQ_REMOVE(&_launchd_logq, lm, logmsg_s, sqe);
+       _launchd_logq_sz -= lm->obj_sz;
+       _launchd_logq_cnt--;
+
+       free(lm);
+}
+
+bool
+_launchd_osx_redirect(const char *message)
+{
+       launchd_syslog(LOG_ERR, "%s", message);
+       return true;
+}
+
+void
+launchd_syslog(int pri, const char *message, ...)
+{
+       struct launchd_syslog_attr attr = {
+               .from_name = launchd_label,
+               .about_name = launchd_label,
+               .session_name = pid1_magic ? "System" : "Background",
+               .priority = pri,
+               .from_uid = launchd_uid,
+               .from_pid = getpid(),
+               .about_pid = getpid(),
+       };
+
+       va_list ap;
+
+       va_start(ap, message);
+       launchd_vsyslog(&attr, message, ap);
+       va_end(ap);
+}
+
+void
+launchd_vsyslog(struct launchd_syslog_attr *attr, const char *fmt, va_list args)
+{
+       int saved_errno = errno;
+       char message[2048];
+
+       static dispatch_once_t perf_once = 0;
+       static dispatch_once_t shutdown_once = 0;
+       static dispatch_once_t shutdown_start_once = 0;
+       static dispatch_once_t debug_once = 0;
+
+       bool echo2console = (attr->priority & LOG_CONSOLE);
+       attr->priority &= ~LOG_CONSOLE;
+       if (attr->priority == LOG_APPLEONLY && launchd_apple_internal) {
+               attr->priority = LOG_NOTICE;
+       }
+
+       FILE *log2here = NULL;
+
+       /* launchctl is responsible for mounting /var as read-write. So we need to
+        * wait until /var/log is available before trying to log anything to our log
+        * anything to our auxilliary log files. This is kind of a hack because
+        * we'll lose the first few relevant messages at boot for debug and
+        * performance logging, but the loss isn't too bad. 
+        */
+       if (launchd_var_available) {
+               /* This file is for logging low-level errors where we can't necessarily be
+                * assured that we can write to the console or use syslog.
+                */
+               char *store = launchd_copy_persistent_store(LAUNCHD_PERSISTENT_STORE_LOGS, NULL);
+               char path[PATH_MAX];
+
+               if (attr->priority == LOG_PERF) {
+                       if (launchd_log_perf) {
+                               (void)snprintf(path, sizeof(path), "%s" LAUNCHD_PERF_LOG, store, launchd_username);
+
+                               struct _launchd_open_log_ctx_s ctx2 = {
+                                       .path = path,
+                                       .filep = &_launchd_perf_log,
+                               };
+                               dispatch_once_f(&perf_once, &ctx2, _launchd_open_log_once);
+                               log2here = _launchd_perf_log;
+                       }
+
+                       // Don't log performance messages to the normal syslog store.
+                       attr->priority = LOG_DEBUG + 1;
+               } else {
+                       if (launchd_shutting_down && launchd_log_shutdown) {
+                               dispatch_once_f(&shutdown_start_once, NULL, _launchd_shutdown_start_once);
+
+                               (void)snprintf(path, sizeof(path), "%s" LAUNCHD_SHUTDOWN_LOG, store, launchd_username);
+
+                               struct _launchd_open_log_ctx_s ctx2 = {
+                                       .path = path,
+                                       .filep = &_launchd_shutdown_log,
+                               };
+                               dispatch_once_f(&shutdown_once, &ctx2, _launchd_open_log_once);
+                               log2here = _launchd_shutdown_log;
+                       } else if (launchd_log_debug) {
+                               (void)snprintf(path, sizeof(path), "%s" LAUNCHD_DEBUG_LOG, store, launchd_username);
+
+                               struct _launchd_open_log_ctx_s ctx2 = {
+                                       .path = path,
+                                       .filep = &_launchd_debug_log,
+                               };
+                               dispatch_once_f(&debug_once, &ctx2, _launchd_open_log_once);
+                               log2here = _launchd_debug_log;
+                       }
+               }
+
+               free(store);
+
+       }
+
+       vsnprintf(message, sizeof(message), fmt, args);
+       if (echo2console && launchd_console) {
+               fprintf(launchd_console, "%-32s %-8u %-64s %-8u  %s\n", attr->from_name, attr->from_pid, attr->about_name, attr->about_pid, message);
+       }
+
+       if (log2here) {
+               int64_t delta = 0;
+               if (log2here == _launchd_shutdown_log) {
+                       delta = runtime_get_wall_time() - _launchd_shutdown_start;
+               } else {
+                       delta = runtime_get_wall_time() - launchd_system_start;
+               }
+
+               fprintf(log2here, "%-8lld %-32s %-8u %-24s %-8u  %s\n", delta, attr->from_name, attr->from_pid, attr->about_name, attr->about_pid, message);
+       }
+
+       if ((LOG_MASK(attr->priority) & _launchd_log_up2)) {
+               _logmsg_add(attr, saved_errno, message);
+       }
+}
+
+static kern_return_t
+_launchd_log_pack(vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
+{
+       struct logmsg_s *lm;
+       void *offset;
+
+       *outvalCnt = _launchd_logq_sz;
+
+       mig_allocate(outval, *outvalCnt);
+
+       if (unlikely(*outval == 0)) {
+               return 1;
+       }
+
+       offset = (void *)*outval;
+       while ((lm = STAILQ_FIRST(&_launchd_logq))) {
+               lm->from_name_offset = lm->from_name - (char *)lm;
+               lm->about_name_offset = lm->about_name - (char *)lm;
+               lm->msg_offset = lm->msg - (char *)lm;
+               lm->session_name_offset = lm->session_name - (char *)lm;
+
+               memcpy(offset, lm, lm->obj_sz);
+
+               offset += lm->obj_sz;
+
+               _logmsg_remove(lm);
+       }
+
+       return 0;
+}
+
+static void
+_launchd_log_uncork_pending_drain(void)
+{
+       mach_msg_type_number_t outvalCnt;
+       mach_port_t tmp_port;
+       vm_offset_t outval;
+
+       if (!launchd_drain_reply_port) {
+               return;
+       }
+
+       if (_launchd_logq_cnt == 0) {
+               return;
+       }
+
+       if (_launchd_log_pack(&outval, &outvalCnt) != 0) {
+               return;
+       }
+
+       tmp_port = launchd_drain_reply_port;
+       launchd_drain_reply_port = MACH_PORT_NULL;
+
+       if (unlikely(errno = job_mig_log_drain_reply(tmp_port, 0, outval, outvalCnt))) {
+               if (errno != MACH_SEND_INVALID_DEST) {
+                       (void)osx_assumes_zero(errno);
+               }
+               (void)osx_assumes_zero(launchd_mport_deallocate(tmp_port));
+       }
+
+       mig_deallocate(outval, outvalCnt);
+}
+
+void
+launchd_log_push(void)
+{
+       vm_offset_t outval = 0;
+       mach_msg_type_number_t outvalCnt = 0;
+
+       if (!pid1_magic) {
+               if (_launchd_perf_log) {
+                       (void)fflush(_launchd_perf_log);
+               }
+               if (_launchd_shutdown_log) {
+                       (void)fflush(_launchd_shutdown_log);
+               }
+               if (_launchd_debug_log) {
+                       (void)fflush(_launchd_debug_log);
+               }
+
+               if (_launchd_logq_cnt && _launchd_log_pack(&outval, &outvalCnt) == 0) {
+                       (void)_vprocmgr_log_forward(inherited_bootstrap_port, (void *)outval, outvalCnt);
+                       mig_deallocate(outval, outvalCnt);
+               }
+       } else {
+               _launchd_log_uncork_pending_drain();
+       }
+}
+
+kern_return_t
+launchd_log_forward(uid_t forward_uid, gid_t forward_gid, vm_offset_t inval, mach_msg_type_number_t invalCnt)
+{
+       struct logmsg_s *lm, *lm_walk;
+       mach_msg_type_number_t data_left = invalCnt;
+
+       if (inval == 0) {
+               return 0;
+       }
+
+       for (lm_walk = (struct logmsg_s *)inval; (data_left > 0) && (lm_walk->obj_sz <= data_left); lm_walk = ((void *)lm_walk + lm_walk->obj_sz)) {
+               /* malloc(3) returns non-NULL when you ask for zero bytes. If our object
+                * is zero bytes, something is wrong.
+                */
+               if (lm_walk->obj_sz == 0) {
+                       launchd_syslog(LOG_WARNING, "Encountered a log message of size 0 with %u bytes left in forwarded data. Ignoring remaining messages.", data_left);
+                       break;
+               }
+
+               if (!(lm = malloc(lm_walk->obj_sz))) {
+                       launchd_syslog(LOG_WARNING, "Failed to allocate %llu bytes for log message with %u bytes left in forwarded data. Ignoring remaining messages.", lm_walk->obj_sz, data_left);
+                       break;
+               }
+
+               memcpy(lm, lm_walk, lm_walk->obj_sz);
+               lm->sender_uid = forward_uid;
+               lm->sender_gid = forward_gid;
+
+               lm->from_name += (size_t)lm;
+               lm->about_name += (size_t)lm;
+               lm->msg += (size_t)lm;
+               lm->session_name += (size_t)lm;
+
+               STAILQ_INSERT_TAIL(&_launchd_logq, lm, sqe);
+               _launchd_logq_sz += lm->obj_sz;
+               _launchd_logq_cnt++;
+
+               data_left -= lm->obj_sz;
+       }
+
+       mig_deallocate(inval, invalCnt);
+
+       return 0;
+}
+
+kern_return_t
+launchd_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
+{
+       (void)osx_assumes_zero(launchd_drain_reply_port);
+
+       if ((_launchd_logq_cnt == 0) || launchd_shutting_down) {
+               launchd_drain_reply_port = srp;
+               (void)osx_assumes_zero(launchd_mport_notify_req(launchd_drain_reply_port, MACH_NOTIFY_DEAD_NAME));
+
+               return MIG_NO_REPLY;
+       }
+
+       return _launchd_log_pack(outval, outvalCnt);
+}
+
+void
+launchd_closelog(void)
+{
+       launchd_log_push();
+
+       if (_launchd_shutdown_log) {
+               (void)fflush(_launchd_shutdown_log);
+               (void)runtime_fsync(fileno(_launchd_shutdown_log));
+       }
+}