chiark / gitweb /
Simplify execute_directory()
[elogind.git] / src / core / manager.c
index ed7fdc71d704d55e432e4ee12f04cc12844131a8..491809112611af2a495e3a20b4a8e3314321a3db 100644 (file)
@@ -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"
 #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);