X-Git-Url: https://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Fcore%2Fmanager.c;h=491809112611af2a495e3a20b4a8e3314321a3db;hp=ed7fdc71d704d55e432e4ee12f04cc12844131a8;hb=4968105790c65af58d4ab42bffa2a4bedc0be8ee;hpb=7358dc029ab8cb8f9d83eb847389d84f822ccfe8 diff --git a/src/core/manager.c b/src/core/manager.c index ed7fdc71d..491809112 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -69,7 +69,7 @@ #include "audit-fd.h" #include "boot-timestamps.h" #include "env-util.h" -#include "bus-errors.h" +#include "bus-common-errors.h" #include "bus-error.h" #include "bus-util.h" #include "dbus.h" @@ -79,14 +79,14 @@ #include "bus-kernel.h" #include "time-util.h" -/* As soon as 5s passed since a unit was added to our GC queue, make sure to run a gc sweep */ -#define GC_QUEUE_USEC_MAX (10*USEC_PER_SEC) - /* Initial delay and the interval for printing status messages about running jobs */ #define JOBS_IN_PROGRESS_WAIT_USEC (5*USEC_PER_SEC) #define JOBS_IN_PROGRESS_PERIOD_USEC (USEC_PER_SEC / 3) #define JOBS_IN_PROGRESS_PERIOD_DIVISOR 3 +#define NOTIFY_FD_MAX 768 +#define NOTIFY_BUFFER_MAX PIPE_BUF + static int manager_dispatch_notify_fd(sd_event_source *source, int fd, uint32_t revents, void *userdata); static int manager_dispatch_signal_fd(sd_event_source *source, int fd, uint32_t revents, void *userdata); static int manager_dispatch_time_change_fd(sd_event_source *source, int fd, uint32_t revents, void *userdata); @@ -165,6 +165,7 @@ static void manager_print_jobs_in_progress(Manager *m) { uint64_t x; assert(m); + assert(m->n_running_jobs > 0); manager_flip_auto_status(m, true); @@ -187,8 +188,7 @@ static void manager_print_jobs_in_progress(Manager *m) { m->jobs_in_progress_iteration++; if (m->n_running_jobs > 1) - if (asprintf(&job_of_n, "(%u of %u) ", counter, m->n_running_jobs) < 0) - job_of_n = NULL; + asprintf(&job_of_n, "(%u of %u) ", counter, m->n_running_jobs); format_timespan(time, sizeof(time), now(CLOCK_MONOTONIC) - j->begin_usec, 1*USEC_PER_SEC); if (job_get_timeout(j, &x) > 0) @@ -200,7 +200,6 @@ static void manager_print_jobs_in_progress(Manager *m) { job_type_to_string(j->type), unit_description(j->unit), time, limit); - } static int have_ask_password(void) { @@ -241,7 +240,7 @@ static int manager_dispatch_ask_password_fd(sd_event_source *source, if (m->have_ask_password < 0) /* Log error but continue. Negative have_ask_password * is treated as unknown status. */ - log_error("Failed to list /run/systemd/ask-password: %s", strerror(m->have_ask_password)); + log_error_errno(m->have_ask_password, "Failed to list /run/systemd/ask-password: %m"); return 0; } @@ -265,13 +264,11 @@ static int manager_check_ask_password(Manager *m) { mkdir_p_label("/run/systemd/ask-password", 0755); m->ask_password_inotify_fd = inotify_init1(IN_NONBLOCK|IN_CLOEXEC); - if (m->ask_password_inotify_fd < 0) { - log_error("inotify_init1() failed: %m"); - return -errno; - } + if (m->ask_password_inotify_fd < 0) + return log_error_errno(errno, "inotify_init1() failed: %m"); if (inotify_add_watch(m->ask_password_inotify_fd, "/run/systemd/ask-password", IN_CREATE|IN_DELETE|IN_MOVE) < 0) { - log_error("Failed to add watch on /run/systemd/ask-password: %m"); + log_error_errno(errno, "Failed to add watch on /run/systemd/ask-password: %m"); manager_close_ask_password(m); return -errno; } @@ -280,7 +277,7 @@ static int manager_check_ask_password(Manager *m) { m->ask_password_inotify_fd, EPOLLIN, manager_dispatch_ask_password_fd, m); if (r < 0) { - log_error("Failed to add event source for /run/systemd/ask-password: %m"); + log_error_errno(errno, "Failed to add event source for /run/systemd/ask-password: %m"); manager_close_ask_password(m); return -errno; } @@ -305,10 +302,8 @@ static int manager_watch_idle_pipe(Manager *m) { return 0; r = sd_event_add_io(m->event, &m->idle_pipe_event_source, m->idle_pipe[2], EPOLLIN, manager_dispatch_idle_pipe_fd, m); - if (r < 0) { - log_error("Failed to watch idle pipe: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to watch idle pipe: %m"); return 0; } @@ -339,22 +334,18 @@ static int manager_setup_time_change(Manager *m) { * CLOCK_REALTIME makes a jump relative to CLOCK_MONOTONIC */ m->time_change_fd = timerfd_create(CLOCK_REALTIME, TFD_NONBLOCK|TFD_CLOEXEC); - if (m->time_change_fd < 0) { - log_error("Failed to create timerfd: %m"); - return -errno; - } + if (m->time_change_fd < 0) + return log_error_errno(errno, "Failed to create timerfd: %m"); if (timerfd_settime(m->time_change_fd, TFD_TIMER_ABSTIME|TFD_TIMER_CANCEL_ON_SET, &its, NULL) < 0) { - log_debug("Failed to set up TFD_TIMER_CANCEL_ON_SET, ignoring: %m"); + log_debug_errno(errno, "Failed to set up TFD_TIMER_CANCEL_ON_SET, ignoring: %m"); m->time_change_fd = safe_close(m->time_change_fd); return 0; } r = sd_event_add_io(m->event, &m->time_change_event_source, m->time_change_fd, EPOLLIN, manager_dispatch_time_change_fd, m); - if (r < 0) { - log_error("Failed to create time change event source: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to create time change event source: %m"); log_debug("Set up TFD_TIMER_CANCEL_ON_SET timerfd."); @@ -370,17 +361,17 @@ static int enable_special_signals(Manager *m) { * this will fail with EPERM (older) or EINVAL (newer), so * ignore that. */ if (reboot(RB_DISABLE_CAD) < 0 && errno != EPERM && errno != EINVAL) - log_warning("Failed to enable ctrl-alt-del handling: %m"); + log_warning_errno(errno, "Failed to enable ctrl-alt-del handling: %m"); fd = open_terminal("/dev/tty0", O_RDWR|O_NOCTTY|O_CLOEXEC); if (fd < 0) { /* Support systems without virtual console */ if (fd != -ENOENT) - log_warning("Failed to open /dev/tty0: %m"); + log_warning_errno(errno, "Failed to open /dev/tty0: %m"); } else { /* Enable that we get SIGWINCH on kbrequest */ if (ioctl(fd, KDSIGACCEPT, SIGWINCH) < 0) - log_warning("Failed to enable kbrequest handling: %m"); + log_warning_errno(errno, "Failed to enable kbrequest handling: %m"); } return 0; @@ -396,9 +387,6 @@ static int manager_setup_signals(Manager *m) { assert(m); - if (m->test_run) - return 0; - assert_se(sigaction(SIGCHLD, &sa, NULL) == 0); /* We make liberal use of realtime signals here. On @@ -454,7 +442,7 @@ static int manager_setup_signals(Manager *m) { SIGRTMIN+26, /* systemd: set log target to journal-or-kmsg */ SIGRTMIN+27, /* systemd: set log target to console */ SIGRTMIN+28, /* systemd: set log target to kmsg */ - SIGRTMIN+29, /* systemd: set log target to syslog-or-kmsg (obsolete)*/ + SIGRTMIN+29, /* systemd: set log target to syslog-or-kmsg (obsolete) */ /* ... one free signal here SIGRTMIN+30 ... */ #endif @@ -554,7 +542,7 @@ int manager_new(SystemdRunningAs running_as, bool test_run, Manager **_m) { m->idle_pipe[0] = m->idle_pipe[1] = m->idle_pipe[2] = m->idle_pipe[3] = -1; - m->pin_cgroupfs_fd = m->notify_fd = m->signal_fd = m->time_change_fd = m->dev_autofs_fd = m->private_listen_fd = m->kdbus_fd = -1; + m->pin_cgroupfs_fd = m->notify_fd = m->signal_fd = m->time_change_fd = m->dev_autofs_fd = m->private_listen_fd = m->kdbus_fd = m->utab_inotify_fd = -1; m->current_job_id = 1; /* start as id #1, so that we can leave #0 around as "null-like" value */ m->ask_password_inotify_fd = -1; @@ -657,10 +645,8 @@ static int manager_setup_notify(Manager *m) { m->notify_event_source = sd_event_source_unref(m->notify_event_source); fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0); - if (fd < 0) { - log_error("Failed to allocate notification socket: %m"); - return -errno; - } + if (fd < 0) + return log_error_errno(errno, "Failed to allocate notification socket: %m"); if (m->running_as == SYSTEMD_SYSTEM) m->notify_socket = strdup("/run/systemd/notify"); @@ -669,7 +655,7 @@ static int manager_setup_notify(Manager *m) { e = getenv("XDG_RUNTIME_DIR"); if (!e) { - log_error("XDG_RUNTIME_DIR is not set: %m"); + log_error_errno(errno, "XDG_RUNTIME_DIR is not set: %m"); return -EINVAL; } @@ -678,32 +664,17 @@ static int manager_setup_notify(Manager *m) { if (!m->notify_socket) return log_oom(); + (void) mkdir_parents_label(m->notify_socket, 0755); + (void) unlink(m->notify_socket); + strncpy(sa.un.sun_path, m->notify_socket, sizeof(sa.un.sun_path)-1); r = bind(fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)); - if (r < 0) { - log_error("bind(%s) failed: %m", sa.un.sun_path); - if (errno == EADDRINUSE) { - log_notice("Removing %s socket and trying again.", m->notify_socket); - r = unlink(m->notify_socket); - if (r < 0) { - log_error("Failed to remove %s: %m", m->notify_socket); - return -EADDRINUSE; - } - - r = bind(fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + strlen(sa.un.sun_path)); - if (r < 0) { - log_error("bind(%s) failed: %m", sa.un.sun_path); - return -errno; - } - } else - return -errno; - } + if (r < 0) + return log_error_errno(errno, "bind(%s) failed: %m", sa.un.sun_path); r = setsockopt(fd, SOL_SOCKET, SO_PASSCRED, &one, sizeof(one)); - if (r < 0) { - log_error("SO_PASSCRED failed: %m"); - return -errno; - } + if (r < 0) + return log_error_errno(errno, "SO_PASSCRED failed: %m"); m->notify_fd = fd; fd = -1; @@ -713,18 +684,14 @@ static int manager_setup_notify(Manager *m) { if (!m->notify_event_source) { r = sd_event_add_io(m->event, &m->notify_event_source, m->notify_fd, EPOLLIN, manager_dispatch_notify_fd, m); - if (r < 0) { - log_error("Failed to allocate notify event source: %s", strerror(-r)); - return -errno; - } + if (r < 0) + return log_error_errno(r, "Failed to allocate notify event source: %m"); /* Process signals a bit earlier than SIGCHLD, so that we can * still identify to which service an exit message belongs */ r = sd_event_source_set_priority(m->notify_event_source, -7); - if (r < 0) { - log_error("Failed to set priority of notify event source: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to set priority of notify event source: %m"); } return 0; @@ -739,20 +706,17 @@ static int manager_setup_kdbus(Manager *m) { if (m->test_run || m->kdbus_fd >= 0) return 0; - m->kdbus_fd = bus_kernel_create_bus(m->running_as == SYSTEMD_SYSTEM ? "system" : "user", m->running_as == SYSTEMD_SYSTEM, &p); - if (m->kdbus_fd < 0) { - log_debug("Failed to set up kdbus: %s", strerror(-m->kdbus_fd)); - return m->kdbus_fd; - } + if (getpid() == 1) + bus_kernel_fix_attach_mask(); - log_debug("Successfully set up kdbus on %s", p); + m->kdbus_fd = bus_kernel_create_bus( + m->running_as == SYSTEMD_SYSTEM ? "system" : "user", + m->running_as == SYSTEMD_SYSTEM, &p); - /* Create the namespace directory here, so that the contents - * of that directory is not visible to non-root users. This is - * necessary to ensure that users cannot get access to busses - * of virtualized users when no UID namespacing is used. */ - if (m->running_as == SYSTEMD_SYSTEM) - mkdir_p_label("/dev/kdbus/domain", 0700); + if (m->kdbus_fd < 0) + return log_debug_errno(m->kdbus_fd, "Failed to set up kdbus: %m"); + + log_debug("Successfully set up kdbus on %s", p); #endif return 0; @@ -878,7 +842,7 @@ static unsigned manager_dispatch_gc_queue(Manager *m) { if (u->gc_marker == gc_marker + GC_OFFSET_BAD || u->gc_marker == gc_marker + GC_OFFSET_UNSURE) { - log_debug_unit(u->id, "Collecting %s", u->id); + log_unit_debug(u->id, "Collecting %s", u->id); u->gc_marker = gc_marker + GC_OFFSET_BAD; unit_add_to_cleanup_queue(u); } @@ -913,11 +877,12 @@ static void manager_clear_jobs_and_units(Manager *m) { m->n_running_jobs = 0; } -void manager_free(Manager *m) { +Manager* manager_free(Manager *m) { UnitType c; int i; - assert(m); + if (!m) + return NULL; manager_clear_jobs_and_units(m); @@ -979,23 +944,33 @@ void manager_free(Manager *m) { hashmap_free(m->units_requiring_mounts_for); free(m); + return NULL; } int manager_enumerate(Manager *m) { - int r = 0, q; + int r = 0; UnitType c; assert(m); /* Let's ask every type to load all units from disk/kernel * that it might know */ - for (c = 0; c < _UNIT_TYPE_MAX; c++) - if (unit_vtable[c]->enumerate) { - q = unit_vtable[c]->enumerate(m); - if (q < 0) - r = q; + for (c = 0; c < _UNIT_TYPE_MAX; c++) { + int q; + + if (unit_vtable[c]->supported && !unit_vtable[c]->supported(m)) { + log_info("Unit type .%s is not supported on this system.", unit_type_to_string(c)); + continue; } + if (!unit_vtable[c]->enumerate) + continue; + + q = unit_vtable[c]->enumerate(m); + if (q < 0) + r = q; + } + manager_dispatch_load_queue(m); return r; } @@ -1048,14 +1023,14 @@ static void manager_build_unit_path_cache(Manager *m) { d = opendir(*i); if (!d) { if (errno != ENOENT) - log_error("Failed to open directory %s: %m", *i); + log_error_errno(errno, "Failed to open directory %s: %m", *i); continue; } while ((de = readdir(d))) { char *p; - if (ignore_file(de->d_name)) + if (hidden_file(de->d_name)) continue; p = strjoin(streq(*i, "/") ? "" : *i, "/", de->d_name, NULL); @@ -1076,7 +1051,7 @@ static void manager_build_unit_path_cache(Manager *m) { return; fail: - log_error("Failed to build unit path cache: %s", strerror(-r)); + log_error_errno(r, "Failed to build unit path cache: %m"); set_free_free(m->unit_path_cache); m->unit_path_cache = NULL; @@ -1195,7 +1170,7 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove if (mode == JOB_ISOLATE && !unit->allow_isolate) return sd_bus_error_setf(e, BUS_ERROR_NO_ISOLATION, "Operation refused, unit may not be isolated."); - log_debug_unit(unit->id, + log_unit_debug(unit->id, "Trying to enqueue job %s/%s/%s", unit->id, job_type_to_string(type), job_mode_to_string(mode)); @@ -1221,7 +1196,7 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove if (r < 0) goto tr_abort; - log_debug_unit(unit->id, + log_unit_debug(unit->id, "Enqueued job %s/%s as %u", unit->id, job_type_to_string(type), (unsigned) tr->anchor_job->id); @@ -1477,7 +1452,7 @@ static unsigned manager_dispatch_dbus_queue(Manager *m) { return n; } -static void manager_invoke_notify_message(Manager *m, Unit *u, pid_t pid, char *buf, size_t n) { +static void manager_invoke_notify_message(Manager *m, Unit *u, pid_t pid, char *buf, size_t n, FDSet *fds) { _cleanup_strv_free_ char **tags = NULL; assert(m); @@ -1491,15 +1466,16 @@ static void manager_invoke_notify_message(Manager *m, Unit *u, pid_t pid, char * return; } - log_debug_unit(u->id, "Got notification message for unit %s", u->id); + log_unit_debug(u->id, "Got notification message for unit %s", u->id); if (UNIT_VTABLE(u)->notify_message) - UNIT_VTABLE(u)->notify_message(u, pid, tags); + UNIT_VTABLE(u)->notify_message(u, pid, tags, fds); } static int manager_dispatch_notify_fd(sd_event_source *source, int fd, uint32_t revents, void *userdata) { Manager *m = userdata; ssize_t n; + int r; assert(m); assert(m->notify_fd == fd); @@ -1510,73 +1486,101 @@ static int manager_dispatch_notify_fd(sd_event_source *source, int fd, uint32_t } for (;;) { - char buf[4096]; + _cleanup_fdset_free_ FDSet *fds = NULL; + char buf[NOTIFY_BUFFER_MAX+1]; struct iovec iovec = { .iov_base = buf, .iov_len = sizeof(buf)-1, }; - bool found = false; - union { struct cmsghdr cmsghdr; - uint8_t buf[CMSG_SPACE(sizeof(struct ucred))]; + uint8_t buf[CMSG_SPACE(sizeof(struct ucred)) + + CMSG_SPACE(sizeof(int) * NOTIFY_FD_MAX)]; } control = {}; - struct msghdr msghdr = { .msg_iov = &iovec, .msg_iovlen = 1, .msg_control = &control, .msg_controllen = sizeof(control), }; - struct ucred *ucred; + struct cmsghdr *cmsg; + struct ucred *ucred = NULL; + bool found = false; Unit *u1, *u2, *u3; + int *fd_array = NULL; + unsigned n_fds = 0; - n = recvmsg(m->notify_fd, &msghdr, MSG_DONTWAIT); - if (n <= 0) { - if (n == 0) - return -EIO; - + n = recvmsg(m->notify_fd, &msghdr, MSG_DONTWAIT|MSG_CMSG_CLOEXEC); + if (n < 0) { if (errno == EAGAIN || errno == EINTR) break; return -errno; } + if (n == 0) + return -ECONNRESET; + + for (cmsg = CMSG_FIRSTHDR(&msghdr); cmsg; cmsg = CMSG_NXTHDR(&msghdr, cmsg)) { + if (cmsg->cmsg_level == SOL_SOCKET && cmsg->cmsg_type == SCM_RIGHTS) { + + fd_array = (int*) CMSG_DATA(cmsg); + n_fds = (cmsg->cmsg_len - CMSG_LEN(0)) / sizeof(int); + + } else if (cmsg->cmsg_level == SOL_SOCKET && + cmsg->cmsg_type == SCM_CREDENTIALS && + cmsg->cmsg_len == CMSG_LEN(sizeof(struct ucred))) { + + ucred = (struct ucred*) CMSG_DATA(cmsg); + } + } + + if (n_fds > 0) { + assert(fd_array); + + r = fdset_new_array(&fds, fd_array, n_fds); + if (r < 0) { + close_many(fd_array, n_fds); + return log_oom(); + } + } - if (msghdr.msg_controllen < CMSG_LEN(sizeof(struct ucred)) || - control.cmsghdr.cmsg_level != SOL_SOCKET || - control.cmsghdr.cmsg_type != SCM_CREDENTIALS || - control.cmsghdr.cmsg_len != CMSG_LEN(sizeof(struct ucred))) { - log_warning("Received notify message without credentials. Ignoring."); + if (!ucred || ucred->pid <= 0) { + log_warning("Received notify message without valid credentials. Ignoring."); continue; } - ucred = (struct ucred*) CMSG_DATA(&control.cmsghdr); + if ((size_t) n >= sizeof(buf)) { + log_warning("Received notify message exceeded maximum size. Ignoring."); + continue; + } - assert((size_t) n < sizeof(buf)); buf[n] = 0; /* Notify every unit that might be interested, but try * to avoid notifying the same one multiple times. */ u1 = manager_get_unit_by_pid(m, ucred->pid); if (u1) { - manager_invoke_notify_message(m, u1, ucred->pid, buf, n); + manager_invoke_notify_message(m, u1, ucred->pid, buf, n, fds); found = true; } u2 = hashmap_get(m->watch_pids1, LONG_TO_PTR(ucred->pid)); if (u2 && u2 != u1) { - manager_invoke_notify_message(m, u2, ucred->pid, buf, n); + manager_invoke_notify_message(m, u2, ucred->pid, buf, n, fds); found = true; } u3 = hashmap_get(m->watch_pids2, LONG_TO_PTR(ucred->pid)); if (u3 && u3 != u2 && u3 != u1) { - manager_invoke_notify_message(m, u3, ucred->pid, buf, n); + manager_invoke_notify_message(m, u3, ucred->pid, buf, n, fds); found = true; } if (!found) log_warning("Cannot find unit for notify message of PID "PID_FMT".", ucred->pid); + + if (fdset_size(fds) > 0) + log_warning("Got auxiliary fds with notification message, closing all."); } return 0; @@ -1587,7 +1591,7 @@ static void invoke_sigchld_event(Manager *m, Unit *u, siginfo_t *si) { assert(u); assert(si); - log_debug_unit(u->id, "Child "PID_FMT" belongs to %s", si->si_pid, u->id); + log_unit_debug(u->id, "Child "PID_FMT" belongs to %s", si->si_pid, u->id); unit_unwatch_pid(u, si->si_pid); UNIT_VTABLE(u)->sigchld_event(u, si->si_pid, si->si_code, si->si_status); @@ -1659,11 +1663,11 @@ static int manager_start_target(Manager *m, const char *name, JobMode mode) { _cleanup_bus_error_free_ sd_bus_error error = SD_BUS_ERROR_NULL; int r; - log_debug_unit(name, "Activating special unit %s", name); + log_unit_debug(name, "Activating special unit %s", name); r = manager_add_job_by_name(m, JOB_START, name, mode, true, &error, NULL); if (r < 0) - log_error_unit(name, "Failed to enqueue %s job: %s", name, bus_error_message(&error, r)); + log_unit_error(name, "Failed to enqueue %s job: %s", name, bus_error_message(&error, r)); return r; } @@ -1898,8 +1902,8 @@ static int manager_dispatch_time_change_fd(sd_event_source *source, int fd, uint assert(m->time_change_fd == fd); log_struct(LOG_INFO, - MESSAGE_ID(SD_MESSAGE_TIME_CHANGE), - "MESSAGE=Time has been changed", + LOG_MESSAGE_ID(SD_MESSAGE_TIME_CHANGE), + LOG_MESSAGE("Time has been changed"), NULL); /* Restart the watch */ @@ -2004,10 +2008,8 @@ int manager_loop(Manager *m) { wait_usec = USEC_INFINITY; r = sd_event_run(m->event, wait_usec); - if (r < 0) { - log_error("Failed to run event loop: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to run event loop: %m"); } return m->exit_code; @@ -2066,6 +2068,7 @@ void manager_send_unit_audit(Manager *m, Unit *u, int type, bool success) { #ifdef HAVE_AUDIT _cleanup_free_ char *p = NULL; + const char *msg; int audit_fd; audit_fd = get_audit_fd(); @@ -2085,18 +2088,19 @@ void manager_send_unit_audit(Manager *m, Unit *u, int type, bool success) { p = unit_name_to_prefix_and_instance(u->id); if (!p) { - log_error_unit(u->id, - "Failed to allocate unit name for audit message: %s", strerror(ENOMEM)); + log_oom(); return; } - if (audit_log_user_comm_message(audit_fd, type, "", p, NULL, NULL, NULL, success) < 0) { - if (errno == EPERM) { + msg = strappenda("unit=", p); + + if (audit_log_user_comm_message(audit_fd, type, msg, "systemd", NULL, NULL, NULL, success) < 0) { + if (errno == EPERM) /* We aren't allowed to send audit messages? * Then let's not retry again. */ close_audit_fd(); - } else - log_warning("Failed to send audit message: %m"); + else + log_warning_errno(errno, "Failed to send audit message: %m"); } #endif @@ -2129,14 +2133,14 @@ void manager_send_unit_plymouth(Manager *m, Unit *u) { * message then wait for plymouth */ fd = socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0); if (fd < 0) { - log_error("socket() failed: %m"); + log_error_errno(errno, "socket() failed: %m"); return; } if (connect(fd, &sa.sa, offsetof(struct sockaddr_un, sun_path) + 1 + strlen(sa.un.sun_path+1)) < 0) { if (!IN_SET(errno, EPIPE, EAGAIN, ENOENT, ECONNREFUSED, ECONNRESET, ECONNABORTED)) - log_error("connect() failed: %m"); + log_error_errno(errno, "connect() failed: %m"); return; } @@ -2148,7 +2152,7 @@ void manager_send_unit_plymouth(Manager *m, Unit *u) { errno = 0; if (write(fd, message, n + 1) != n + 1) if (!IN_SET(errno, EPIPE, EAGAIN, ENOENT, ECONNREFUSED, ECONNRESET, ECONNABORTED)) - log_error("Failed to write Plymouth message: %m"); + log_error_errno(errno, "Failed to write Plymouth message: %m"); } void manager_dispatch_bus_name_owner_changed( @@ -2325,7 +2329,7 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { uint32_t id; if (safe_atou32(l+15, &id) < 0) - log_warning("Failed to parse current job id value %s", l+15); + log_debug("Failed to parse current job id value %s", l+15); else m->current_job_id = MAX(m->current_job_id, id); @@ -2333,7 +2337,7 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { uint32_t n; if (safe_atou32(l+17, &n) < 0) - log_warning("Failed to parse installed jobs counter %s", l+17); + log_debug("Failed to parse installed jobs counter %s", l+17); else m->n_installed_jobs += n; @@ -2341,7 +2345,7 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { uint32_t n; if (safe_atou32(l+14, &n) < 0) - log_warning("Failed to parse failed jobs counter %s", l+14); + log_debug("Failed to parse failed jobs counter %s", l+14); else m->n_failed_jobs += n; @@ -2350,7 +2354,7 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { b = parse_boolean(l+10); if (b < 0) - log_warning("Failed to parse taint /usr flag %s", l+10); + log_debug("Failed to parse taint /usr flag %s", l+10); else m->taint_usr = m->taint_usr || b; @@ -2401,7 +2405,7 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { int fd; if (safe_atoi(l + 10, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_warning("Failed to parse notify fd: %s", l + 10); + log_debug("Failed to parse notify fd: %s", l + 10); else { m->notify_event_source = sd_event_source_unref(m->notify_event_source); safe_close(m->notify_fd); @@ -2424,14 +2428,21 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { int fd; if (safe_atoi(l + 9, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_warning("Failed to parse kdbus fd: %s", l + 9); + log_debug("Failed to parse kdbus fd: %s", l + 9); else { safe_close(m->kdbus_fd); m->kdbus_fd = fdset_remove(fds, fd); } - } else if (bus_track_deserialize_item(&m->deserialized_subscribed, l) == 0) - log_warning("Unknown serialization item '%s'", l); + } else { + int k; + + k = bus_track_deserialize_item(&m->deserialized_subscribed, l); + if (k < 0) + log_debug_errno(k, "Failed to deserialize bus tracker object: %m"); + else if (k == 0) + log_debug("Unknown serialization item '%s'", l); + } } for (;;) { @@ -2580,45 +2591,13 @@ bool manager_unit_inactive_or_pending(Manager *m, const char *name) { return unit_inactive_or_pending(u); } -void manager_check_finished(Manager *m) { +static void manager_notify_finished(Manager *m) { char userspace[FORMAT_TIMESPAN_MAX], initrd[FORMAT_TIMESPAN_MAX], kernel[FORMAT_TIMESPAN_MAX], sum[FORMAT_TIMESPAN_MAX]; usec_t firmware_usec, loader_usec, kernel_usec, initrd_usec, userspace_usec, total_usec; - Unit *u = NULL; - Iterator i; - - assert(m); - - if (m->n_running_jobs == 0) - m->jobs_in_progress_event_source = sd_event_source_unref(m->jobs_in_progress_event_source); - - if (hashmap_size(m->jobs) > 0) { - - if (m->jobs_in_progress_event_source) - sd_event_source_set_time(m->jobs_in_progress_event_source, now(CLOCK_MONOTONIC) + JOBS_IN_PROGRESS_WAIT_USEC); - - return; - } - - manager_flip_auto_status(m, false); - - /* Notify Type=idle units that we are done now */ - m->idle_pipe_event_source = sd_event_source_unref(m->idle_pipe_event_source); - manager_close_idle_pipe(m); - - /* Turn off confirm spawn now */ - m->confirm_spawn = false; - /* No need to update ask password status when we're going non-interactive */ - manager_close_ask_password(m); - - /* This is no longer the first boot */ - manager_set_first_boot(m, false); - - if (dual_timestamp_is_set(&m->finish_timestamp)) + if (m->test_run) return; - dual_timestamp_get(&m->finish_timestamp); - if (m->running_as == SYSTEMD_SYSTEM && detect_container(NULL) <= 0) { /* Note that m->kernel_usec.monotonic is always at 0, @@ -2637,28 +2616,28 @@ void manager_check_finished(Manager *m) { initrd_usec = m->userspace_timestamp.monotonic - m->initrd_timestamp.monotonic; log_struct(LOG_INFO, - MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), + LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), "KERNEL_USEC="USEC_FMT, kernel_usec, "INITRD_USEC="USEC_FMT, initrd_usec, "USERSPACE_USEC="USEC_FMT, userspace_usec, - "MESSAGE=Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.", - format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC), - format_timespan(initrd, sizeof(initrd), initrd_usec, USEC_PER_MSEC), - format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC), - format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC), + LOG_MESSAGE("Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.", + format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC), + format_timespan(initrd, sizeof(initrd), initrd_usec, USEC_PER_MSEC), + format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC), + format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)), NULL); } else { kernel_usec = m->userspace_timestamp.monotonic - m->kernel_timestamp.monotonic; initrd_usec = 0; log_struct(LOG_INFO, - MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), + LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), "KERNEL_USEC="USEC_FMT, kernel_usec, "USERSPACE_USEC="USEC_FMT, userspace_usec, - "MESSAGE=Startup finished in %s (kernel) + %s (userspace) = %s.", - format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC), - format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC), - format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC), + LOG_MESSAGE("Startup finished in %s (kernel) + %s (userspace) = %s.", + format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC), + format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC), + format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)), NULL); } } else { @@ -2666,17 +2645,13 @@ void manager_check_finished(Manager *m) { total_usec = userspace_usec = m->finish_timestamp.monotonic - m->userspace_timestamp.monotonic; log_struct(LOG_INFO, - MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), + LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED), "USERSPACE_USEC="USEC_FMT, userspace_usec, - "MESSAGE=Startup finished in %s.", - format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC), + LOG_MESSAGE("Startup finished in %s.", + format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)), NULL); } - SET_FOREACH(u, m->startup_units, i) - if (u->cgroup_path) - cgroup_context_apply(unit_get_cgroup_context(u), unit_get_cgroup_mask(u), u->cgroup_path, manager_state(m)); - bus_manager_send_finished(m, firmware_usec, loader_usec, kernel_usec, initrd_usec, userspace_usec, total_usec); sd_notifyf(false, @@ -2685,6 +2660,47 @@ void manager_check_finished(Manager *m) { format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)); } +void manager_check_finished(Manager *m) { + Unit *u = NULL; + Iterator i; + + assert(m); + + if (hashmap_size(m->jobs) > 0) { + + if (m->jobs_in_progress_event_source) + sd_event_source_set_time(m->jobs_in_progress_event_source, now(CLOCK_MONOTONIC) + JOBS_IN_PROGRESS_WAIT_USEC); + + return; + } + + manager_flip_auto_status(m, false); + + /* Notify Type=idle units that we are done now */ + m->idle_pipe_event_source = sd_event_source_unref(m->idle_pipe_event_source); + manager_close_idle_pipe(m); + + /* Turn off confirm spawn now */ + m->confirm_spawn = false; + + /* No need to update ask password status when we're going non-interactive */ + manager_close_ask_password(m); + + /* This is no longer the first boot */ + manager_set_first_boot(m, false); + + if (dual_timestamp_is_set(&m->finish_timestamp)) + return; + + dual_timestamp_get(&m->finish_timestamp); + + manager_notify_finished(m); + + SET_FOREACH(u, m->startup_units, i) + if (u->cgroup_path) + cgroup_context_apply(unit_get_cgroup_context(u), unit_get_cgroup_mask(u), u->cgroup_path, manager_state(m)); +} + static int create_generator_dir(Manager *m, char **generator, const char *name) { char *p; int r; @@ -2705,8 +2721,7 @@ static int create_generator_dir(Manager *m, char **generator, const char *name) r = mkdir_p_label(p, 0755); if (r < 0) { - log_error("Failed to create generator directory %s: %s", - p, strerror(-r)); + log_error_errno(r, "Failed to create generator directory %s: %m", p); free(p); return r; } @@ -2722,8 +2737,7 @@ static int create_generator_dir(Manager *m, char **generator, const char *name) r = mkdir_p_label(p, 0755); if (r < 0) { - log_error("Failed to create generator directory %s: %s", - p, strerror(-r)); + log_error_errno(r, "Failed to create generator directory %s: %m", p); free(p); return r; } @@ -2735,7 +2749,7 @@ static int create_generator_dir(Manager *m, char **generator, const char *name) return log_oom(); if (!mkdtemp(p)) { - log_error("Failed to create generator directory %s: %m", + log_error_errno(errno, "Failed to create generator directory %s: %m", p); free(p); return -errno; @@ -2762,7 +2776,6 @@ static void trim_generator_dir(Manager *m, char **generator) { } void manager_run_generators(Manager *m) { - _cleanup_closedir_ DIR *d = NULL; const char *generator_path; const char *argv[5]; int r; @@ -2773,13 +2786,13 @@ void manager_run_generators(Manager *m) { return; generator_path = m->running_as == SYSTEMD_SYSTEM ? SYSTEM_GENERATOR_PATH : USER_GENERATOR_PATH; - d = opendir(generator_path); - if (!d) { - if (errno == ENOENT) - return; - log_error("Failed to enumerate generator directory %s: %m", - generator_path); + /* Optimize by skipping the whole process by not creating output directories + * if no generators are found. */ + if (access(generator_path, F_OK) != 0) { + if (errno != ENOENT) + log_error_errno(errno, "Failed to open generator directory %s: %m", + generator_path); return; } @@ -2802,7 +2815,7 @@ void manager_run_generators(Manager *m) { argv[4] = NULL; RUN_WITH_UMASK(0022) - execute_directory(generator_path, d, DEFAULT_TIMEOUT_USEC, (char**) argv); + execute_directory(generator_path, DEFAULT_TIMEOUT_USEC, (char**) argv); finish: trim_generator_dir(m, &m->generator_unit_path); @@ -2968,12 +2981,14 @@ void manager_set_first_boot(Manager *m, bool b) { void manager_status_printf(Manager *m, StatusType type, const char *status, const char *format, ...) { va_list ap; - if (!manager_get_show_status(m, type)) + /* If m is NULL, assume we're after shutdown and let the messages through. */ + + if (m && !manager_get_show_status(m, type)) return; /* XXX We should totally drop the check for ephemeral here * and thus effectively make 'Type=idle' pointless. */ - if (type == STATUS_TYPE_EPHEMERAL && m->n_on_console > 0) + if (type == STATUS_TYPE_EPHEMERAL && m && m->n_on_console > 0) return; va_start(ap, format);