Merge pull request #6915 from poettering/log-execute

make execute.c logging a bit less special

3 files changed, 182 insertions, 232 deletions

diff --git a/src/basic/log.c b/src/basic/log.c
index 168c6c37ce..4f0fe54579 100644
--- a/src/basic/log.c
+++ b/src/basic/log.c
@@ -74,6 +74,7 @@ static bool show_location = false;
 
 static bool upgrade_syslog_to_journal = false;
 static bool always_reopen_console = false;
+static bool open_when_needed = false;
 
 /* Akin to glibc's __abort_msg; which is private and we hence cannot
  * use here. */
@@ -585,6 +586,9 @@ int log_dispatch_internal(
         if ((level & LOG_FACMASK) == 0)
                 level = log_facility | LOG_PRI(level);
 
+        if (open_when_needed)
+                log_open();
+
         do {
                 char *e;
                 int k = 0;
@@ -640,6 +644,9 @@ int log_dispatch_internal(
                 buffer = e;
         } while (buffer);
 
+        if (open_when_needed)
+                log_close();
+
         return -error;
 }
 
@@ -834,9 +841,8 @@ void log_assert_failed_return_realm(
 }
 
 int log_oom_internal(LogRealm realm, const char *file, int line, const char *func) {
-        log_internal_realm(LOG_REALM_PLUS_LEVEL(realm, LOG_ERR),
-                           ENOMEM, file, line, func, "Out of memory.");
-        return -ENOMEM;
+        return log_internal_realm(LOG_REALM_PLUS_LEVEL(realm, LOG_ERR),
+                                  ENOMEM, file, line, func, "Out of memory.");
 }
 
 int log_format_iovec(
@@ -911,38 +917,48 @@ int log_struct_internal(
         if ((level & LOG_FACMASK) == 0)
                 level = log_facility | LOG_PRI(level);
 
-        if (IN_SET(log_target, LOG_TARGET_AUTO,
-                               LOG_TARGET_JOURNAL_OR_KMSG,
-                               LOG_TARGET_JOURNAL) &&
-            journal_fd >= 0) {
-                char header[LINE_MAX];
-                struct iovec iovec[17] = {};
-                unsigned n = 0, i;
-                int r;
-                struct msghdr mh = {
-                        .msg_iov = iovec,
-                };
-                bool fallback = false;
-
-                /* If the journal is available do structured logging */
-                log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL);
-                iovec[n++] = IOVEC_MAKE_STRING(header);
+        if (IN_SET(log_target,
+                   LOG_TARGET_AUTO,
+                   LOG_TARGET_JOURNAL_OR_KMSG,
+                   LOG_TARGET_JOURNAL)) {
+
+                if (open_when_needed)
+                        log_open_journal();
+
+                if (journal_fd >= 0) {
+                        char header[LINE_MAX];
+                        struct iovec iovec[17] = {};
+                        unsigned n = 0, i;
+                        int r;
+                        struct msghdr mh = {
+                                .msg_iov = iovec,
+                        };
+                        bool fallback = false;
+
+                        /* If the journal is available do structured logging */
+                        log_do_header(header, sizeof(header), level, error, file, line, func, NULL, NULL, NULL, NULL);
+                        iovec[n++] = IOVEC_MAKE_STRING(header);
+
+                        va_start(ap, format);
+                        r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, true, error, format, ap);
+                        if (r < 0)
+                                fallback = true;
+                        else {
+                                mh.msg_iovlen = n;
+                                (void) sendmsg(journal_fd, &mh, MSG_NOSIGNAL);
+                        }
 
-                va_start(ap, format);
-                r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, true, error, format, ap);
-                if (r < 0)
-                        fallback = true;
-                else {
-                        mh.msg_iovlen = n;
-                        (void) sendmsg(journal_fd, &mh, MSG_NOSIGNAL);
-                }
+                        va_end(ap);
+                        for (i = 1; i < n; i += 2)
+                                free(iovec[i].iov_base);
 
-                va_end(ap);
-                for (i = 1; i < n; i += 2)
-                        free(iovec[i].iov_base);
+                        if (!fallback) {
+                                if (open_when_needed)
+                                        log_close();
 
-                if (!fallback)
-                        return -error;
+                                return -error;
+                        }
+                }
         }
 
         /* Fallback if journal logging is not available or didn't work. */
@@ -969,8 +985,12 @@ int log_struct_internal(
         }
         va_end(ap);
 
-        if (!found)
+        if (!found) {
+                if (open_when_needed)
+                        log_close();
+
                 return -error;
+        }
 
         return log_dispatch_internal(level, error, file, line, func, NULL, NULL, NULL, NULL, buf + 8);
 }
@@ -1221,10 +1241,6 @@ void log_received_signal(int level, const struct signalfd_siginfo *si) {
 
 }
 
-void log_set_upgrade_syslog_to_journal(bool b) {
-        upgrade_syslog_to_journal = b;
-}
-
 int log_syntax_internal(
                 const char *unit,
                 int level,
@@ -1272,6 +1288,14 @@ int log_syntax_internal(
                         NULL);
 }
 
+void log_set_upgrade_syslog_to_journal(bool b) {
+        upgrade_syslog_to_journal = b;
+}
+
 void log_set_always_reopen_console(bool b) {
         always_reopen_console = b;
 }
+
+void log_set_open_when_needed(bool b) {
+        open_when_needed = b;
+}
diff --git a/src/basic/log.h b/src/basic/log.h
index e3fd3203d0..10a6032788 100644
--- a/src/basic/log.h
+++ b/src/basic/log.h
@@ -303,6 +303,7 @@ void log_received_signal(int level, const struct signalfd_siginfo *si);
 
 void log_set_upgrade_syslog_to_journal(bool b);
 void log_set_always_reopen_console(bool b);
+void log_set_open_when_needed(bool b);
 
 int log_syntax_internal(
                 const char *unit,
diff --git a/src/core/execute.c b/src/core/execute.c
index 0b49be2000..cd4b9f8eb2 100644
--- a/src/core/execute.c
+++ b/src/core/execute.c
@@ -588,7 +588,7 @@ static int setup_output(
         case EXEC_OUTPUT_JOURNAL_AND_CONSOLE:
                 r = connect_logger_as(unit, context, params, o, ident, fileno, uid, gid);
                 if (r < 0) {
-                        log_unit_error_errno(unit, r, "Failed to connect %s to the journal socket, ignoring: %m", fileno == STDOUT_FILENO ? "stdout" : "stderr");
+                        log_unit_warning_errno(unit, r, "Failed to connect %s to the journal socket, ignoring: %m", fileno == STDOUT_FILENO ? "stdout" : "stderr");
                         r = open_null_as(O_WRONLY, fileno);
                 } else {
                         struct stat st;
@@ -1323,9 +1323,7 @@ static bool skip_seccomp_unavailable(const Unit* u, const char* msg) {
         if (is_seccomp_available())
                 return false;
 
-        log_open();
         log_unit_debug(u, "SECCOMP features not detected in the kernel, skipping %s", msg);
-        log_close();
         return true;
 }
 
@@ -2109,10 +2107,8 @@ static int apply_mount_namespace(
         /* If we couldn't set up the namespace this is probably due to a
          * missing capability. In this case, silently proceeed. */
         if (IN_SET(r, -EPERM, -EACCES)) {
-                log_open();
                 log_unit_debug_errno(u, r, "Failed to set up namespace, assuming containerized execution, ignoring: %m");
-                log_close();
-                r = 0;
+                return 0;
         }
 
         return r;
@@ -2192,13 +2188,13 @@ static int setup_keyring(
         keyring = keyctl(KEYCTL_JOIN_SESSION_KEYRING, 0, 0, 0, 0);
         if (keyring == -1) {
                 if (errno == ENOSYS)
-                        log_debug_errno(errno, "Kernel keyring not supported, ignoring.");
+                        log_unit_debug_errno(u, errno, "Kernel keyring not supported, ignoring.");
                 else if (IN_SET(errno, EACCES, EPERM))
-                        log_debug_errno(errno, "Kernel keyring access prohibited, ignoring.");
+                        log_unit_debug_errno(u, errno, "Kernel keyring access prohibited, ignoring.");
                 else if (errno == EDQUOT)
-                        log_debug_errno(errno, "Out of kernel keyrings to allocate, ignoring.");
+                        log_unit_debug_errno(u, errno, "Out of kernel keyrings to allocate, ignoring.");
                 else
-                        return log_error_errno(errno, "Setting up kernel keyring failed: %m");
+                        return log_unit_error_errno(u, errno, "Setting up kernel keyring failed: %m");
 
                 return 0;
         }
@@ -2209,19 +2205,19 @@ static int setup_keyring(
 
                 key = add_key("user", "invocation_id", &u->invocation_id, sizeof(u->invocation_id), KEY_SPEC_SESSION_KEYRING);
                 if (key == -1)
-                        log_debug_errno(errno, "Failed to add invocation ID to keyring, ignoring: %m");
+                        log_unit_debug_errno(u, errno, "Failed to add invocation ID to keyring, ignoring: %m");
                 else {
                         if (keyctl(KEYCTL_SETPERM, key,
                                    KEY_POS_VIEW|KEY_POS_READ|KEY_POS_SEARCH|
                                    KEY_USR_VIEW|KEY_USR_READ|KEY_USR_SEARCH, 0, 0) < 0)
-                                return log_error_errno(errno, "Failed to restrict invocation ID permission: %m");
+                                return log_unit_error_errno(u, errno, "Failed to restrict invocation ID permission: %m");
                 }
         }
 
         /* And now, make the keyring owned by the service's user */
         if (uid_is_valid(uid) || gid_is_valid(gid))
                 if (keyctl(KEYCTL_CHOWN, keyring, uid, gid, 0) < 0)
-                        return log_error_errno(errno, "Failed to change ownership of session keyring: %m");
+                        return log_unit_error_errno(u, errno, "Failed to change ownership of session keyring: %m");
 
         /* When requested link the user keyring into the session keyring. */
         if (context->keyring_mode == EXEC_KEYRING_SHARED) {
@@ -2237,13 +2233,13 @@ static int setup_keyring(
 
                 if (gid_is_valid(gid) && gid != saved_gid) {
                         if (setregid(gid, -1) < 0)
-                                return log_error_errno(errno, "Failed to change GID for user keyring: %m");
+                                return log_unit_error_errno(u, errno, "Failed to change GID for user keyring: %m");
                 }
 
                 if (uid_is_valid(uid) && uid != saved_uid) {
                         if (setreuid(uid, -1) < 0) {
                                 (void) setregid(saved_gid, -1);
-                                return log_error_errno(errno, "Failed to change UID for user keyring: %m");
+                                return log_unit_error_errno(u, errno, "Failed to change UID for user keyring: %m");
                         }
                 }
 
@@ -2256,19 +2252,19 @@ static int setup_keyring(
                         (void) setreuid(saved_uid, -1);
                         (void) setregid(saved_gid, -1);
 
-                        return log_error_errno(r, "Failed to link user keyring into session keyring: %m");
+                        return log_unit_error_errno(u, r, "Failed to link user keyring into session keyring: %m");
                 }
 
                 if (uid_is_valid(uid) && uid != saved_uid) {
                         if (setreuid(saved_uid, -1) < 0) {
                                 (void) setregid(saved_gid, -1);
-                                return log_error_errno(errno, "Failed to change UID back for user keyring: %m");
+                                return log_unit_error_errno(u, errno, "Failed to change UID back for user keyring: %m");
                         }
                 }
 
                 if (gid_is_valid(gid) && gid != saved_gid) {
                         if (setregid(saved_gid, -1) < 0)
-                                return log_error_errno(errno, "Failed to change GID back for user keyring: %m");
+                                return log_unit_error_errno(u, errno, "Failed to change GID back for user keyring: %m");
                 }
         }
 
@@ -2403,8 +2399,7 @@ static int exec_child(
                 unsigned n_socket_fds,
                 char **files_env,
                 int user_lookup_fd,
-                int *exit_status,
-                char **error_message) {
+                int *exit_status) {
 
         _cleanup_strv_free_ char **our_env = NULL, **pass_env = NULL, **accum_env = NULL, **final_argv = NULL;
         _cleanup_free_ char *mac_selinux_context_net = NULL, *home_buffer = NULL;
@@ -2438,9 +2433,6 @@ static int exec_child(
         assert(context);
         assert(params);
         assert(exit_status);
-        assert(error_message);
-        /* We don't always set error_message, hence it must be initialized */
-        assert(*error_message == NULL);
 
         rename_process_from_path(command->path);
 
@@ -2458,33 +2450,34 @@ static int exec_child(
         r = reset_signal_mask();
         if (r < 0) {
                 *exit_status = EXIT_SIGNAL_MASK;
-                *error_message = strdup("Failed to set process signal mask");
-                /* If strdup fails, here and below, we will just print the generic error message. */
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to set process signal mask: %m");
         }
 
         if (params->idle_pipe)
                 do_idle_pipe_dance(params->idle_pipe);
 
-        /* Close sockets very early to make sure we don't
-         * block init reexecution because it cannot bind its
-         * sockets */
+        /* Close fds we don't need very early to make sure we don't block init reexecution because it cannot bind its
+         * sockets. Among the fds we close are the logging fds, and we want to keep them closed, so that we don't have
+         * any fds open we don't really want open during the transition. In order to make logging work, we switch the
+         * log subsystem into open_when_needed mode, so that it reopens the logs on every single log call. */
 
         log_forget_fds();
+        log_set_open_when_needed(true);
+
+        /* In case anything used libc syslog(), close this here, too */
+        closelog();
 
         n_fds = n_storage_fds + n_socket_fds;
         r = close_remaining_fds(params, runtime, dcreds, user_lookup_fd, socket_fd, fds, n_fds);
         if (r < 0) {
                 *exit_status = EXIT_FDS;
-                *error_message = strdup("Failed to close unwanted file descriptors");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to close unwanted file descriptors: %m");
         }
 
         if (!context->same_pgrp)
                 if (setsid() < 0) {
                         *exit_status = EXIT_SETSID;
-                        *error_message = strdup("Failed to create new process session");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to create new process session: %m");
                 }
 
         exec_context_tty_reset(context, params);
@@ -2496,7 +2489,7 @@ static int exec_child(
                 cmdline = exec_command_line(argv);
                 if (!cmdline) {
                         *exit_status = EXIT_MEMORY;
-                        return -ENOMEM;
+                        return log_oom();
                 }
 
                 r = ask_for_confirmation(vc, unit, cmdline);
@@ -2506,7 +2499,7 @@ static int exec_child(
                                 return 0;
                         }
                         *exit_status = EXIT_CONFIRM;
-                        *error_message = strdup("Execution cancelled by the user");
+                        log_unit_error(unit, "Execution cancelled by the user");
                         return -ECANCELED;
                 }
         }
@@ -2516,27 +2509,24 @@ static int exec_child(
                 /* Make sure we bypass our own NSS module for any NSS checks */
                 if (putenv((char*) "SYSTEMD_NSS_DYNAMIC_BYPASS=1") != 0) {
                         *exit_status = EXIT_USER;
-                        *error_message = strdup("Failed to update environment");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to update environment: %m");
                 }
 
                 r = dynamic_creds_realize(dcreds, &uid, &gid);
                 if (r < 0) {
                         *exit_status = EXIT_USER;
-                        *error_message = strdup("Failed to update dynamic user credentials");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to update dynamic user credentials: %m");
                 }
 
                 if (!uid_is_valid(uid)) {
                         *exit_status = EXIT_USER;
-                        (void) asprintf(error_message, "UID validation failed for \""UID_FMT"\"", uid);
-                        /* If asprintf fails, here and below, we will just print the generic error message. */
+                        log_unit_error(unit, "UID validation failed for \""UID_FMT"\"", uid);
                         return -ESRCH;
                 }
 
                 if (!gid_is_valid(gid)) {
                         *exit_status = EXIT_USER;
-                        (void) asprintf(error_message, "GID validation failed for \""GID_FMT"\"", gid);
+                        log_unit_error(unit, "GID validation failed for \""GID_FMT"\"", gid);
                         return -ESRCH;
                 }
 
@@ -2547,15 +2537,13 @@ static int exec_child(
                 r = get_fixed_user(context, &username, &uid, &gid, &home, &shell);
                 if (r < 0) {
                         *exit_status = EXIT_USER;
-                        *error_message = strdup("Failed to determine user credentials");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to determine user credentials: %m");
                 }
 
                 r = get_fixed_group(context, &groupname, &gid);
                 if (r < 0) {
                         *exit_status = EXIT_GROUP;
-                        *error_message = strdup("Failed to determine group credentials");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to determine group credentials: %m");
                 }
         }
 
@@ -2564,15 +2552,13 @@ static int exec_child(
                                      &supplementary_gids, &ngids);
         if (r < 0) {
                 *exit_status = EXIT_GROUP;
-                *error_message = strdup("Failed to determine supplementary groups");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to determine supplementary groups: %m");
         }
 
         r = send_user_lookup(unit, user_lookup_fd, uid, gid);
         if (r < 0) {
                 *exit_status = EXIT_USER;
-                *error_message = strdup("Failed to send user credentials to PID1");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to send user credentials to PID1: %m");
         }
 
         user_lookup_fd = safe_close(user_lookup_fd);
@@ -2580,8 +2566,7 @@ static int exec_child(
         r = acquire_home(context, uid, &home, &home_buffer);
         if (r < 0) {
                 *exit_status = EXIT_CHDIR;
-                *error_message = strdup("Failed to determine $HOME for user");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to determine $HOME for user: %m");
         }
 
         /* If a socket is connected to STDIN/STDOUT/STDERR, we
@@ -2592,30 +2577,26 @@ static int exec_child(
         r = setup_input(context, params, socket_fd, named_iofds);
         if (r < 0) {
                 *exit_status = EXIT_STDIN;
-                *error_message = strdup("Failed to set up standard input");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to set up standard input: %m");
         }
 
         r = setup_output(unit, context, params, STDOUT_FILENO, socket_fd, named_iofds, basename(command->path), uid, gid, &journal_stream_dev, &journal_stream_ino);
         if (r < 0) {
                 *exit_status = EXIT_STDOUT;
-                *error_message = strdup("Failed to set up standard output");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to set up standard output: %m");
         }
 
         r = setup_output(unit, context, params, STDERR_FILENO, socket_fd, named_iofds, basename(command->path), uid, gid, &journal_stream_dev, &journal_stream_ino);
         if (r < 0) {
                 *exit_status = EXIT_STDERR;
-                *error_message = strdup("Failed to set up standard error output");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to set up standard error output: %m");
         }
 
         if (params->cgroup_path) {
                 r = cg_attach_everywhere(params->cgroup_supported, params->cgroup_path, 0, NULL, NULL);
                 if (r < 0) {
                         *exit_status = EXIT_CGROUP;
-                        (void) asprintf(error_message, "Failed to attach to cgroup %s", params->cgroup_path);
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to attach to cgroup %s: %m", params->cgroup_path);
                 }
         }
 
@@ -2629,22 +2610,18 @@ static int exec_child(
 
                 sprintf(t, "%i", context->oom_score_adjust);
                 r = write_string_file("/proc/self/oom_score_adj", t, 0);
-                if (r == -EPERM || r == -EACCES) {
-                        log_open();
+                if (IN_SET(r, -EPERM, -EACCES))
                         log_unit_debug_errno(unit, r, "Failed to adjust OOM setting, assuming containerized execution, ignoring: %m");
-                        log_close();
-                } else if (r < 0) {
+                else if (r < 0) {
                         *exit_status = EXIT_OOM_ADJUST;
-                        *error_message = strdup("Failed to adjust OOM setting");
-                        return -errno;
+                        return log_unit_error_errno(unit, r, "Failed to adjust OOM setting: %m");
                 }
         }
 
         if (context->nice_set)
                 if (setpriority(PRIO_PROCESS, 0, context->nice) < 0) {
                         *exit_status = EXIT_NICE;
-                        *error_message = strdup("Failed to set up process scheduling priority (nice level)");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to set up process scheduling priority (nice level): %m");
                 }
 
         if (context->cpu_sched_set) {
@@ -2659,38 +2636,33 @@ static int exec_child(
                                        &param);
                 if (r < 0) {
                         *exit_status = EXIT_SETSCHEDULER;
-                        *error_message = strdup("Failed to set up CPU scheduling");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to set up CPU scheduling: %m");
                 }
         }
 
         if (context->cpuset)
                 if (sched_setaffinity(0, CPU_ALLOC_SIZE(context->cpuset_ncpus), context->cpuset) < 0) {
                         *exit_status = EXIT_CPUAFFINITY;
-                        *error_message = strdup("Failed to set up CPU affinity");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to set up CPU affinity: %m");
                 }
 
         if (context->ioprio_set)
                 if (ioprio_set(IOPRIO_WHO_PROCESS, 0, context->ioprio) < 0) {
                         *exit_status = EXIT_IOPRIO;
-                        *error_message = strdup("Failed to set up IO scheduling priority");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to set up IO scheduling priority: %m");
                 }
 
         if (context->timer_slack_nsec != NSEC_INFINITY)
                 if (prctl(PR_SET_TIMERSLACK, context->timer_slack_nsec) < 0) {
                         *exit_status = EXIT_TIMERSLACK;
-                        *error_message = strdup("Failed to set up timer slack");
-                        return -errno;
+                        return log_unit_error_errno(unit, errno, "Failed to set up timer slack: %m");
                 }
 
         if (context->personality != PERSONALITY_INVALID) {
                 r = safe_personality(context->personality);
                 if (r < 0) {
                         *exit_status = EXIT_PERSONALITY;
-                        *error_message = strdup("Failed to set up execution domain (personality)");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to set up execution domain (personality): %m");
                 }
         }
 
@@ -2706,8 +2678,7 @@ static int exec_child(
                 r = chown_terminal(STDIN_FILENO, uid);
                 if (r < 0) {
                         *exit_status = EXIT_STDIN;
-                        *error_message = strdup("Failed to change ownership of terminal");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to change ownership of terminal: %m");
                 }
         }
 
@@ -2718,25 +2689,20 @@ static int exec_child(
                 r = cg_set_task_access(SYSTEMD_CGROUP_CONTROLLER, params->cgroup_path, 0644, uid, gid);
                 if (r < 0) {
                         *exit_status = EXIT_CGROUP;
-                        *error_message = strdup("Failed to adjust control group access");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to adjust control group access: %m");
                 }
 
-
                 r = cg_set_group_access(SYSTEMD_CGROUP_CONTROLLER, params->cgroup_path, 0755, uid, gid);
                 if (r < 0) {
                         *exit_status = EXIT_CGROUP;
-                        *error_message = strdup("Failed to adjust control group access");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to adjust control group access: %m");
                 }
         }
 
         for (dt = 0; dt < _EXEC_DIRECTORY_MAX; dt++) {
                 r = setup_exec_directory(context, params, uid, gid, dt, exit_status);
-                if (r < 0) {
-                        *error_message = strdup("Failed to set up special execution directory");
-                        return r;
-                }
+                if (r < 0)
+                        return log_unit_error_errno(unit, r, "Failed to set up special execution directory in %s: %m", params->prefix[dt]);
         }
 
         r = build_environment(
@@ -2752,13 +2718,13 @@ static int exec_child(
                         &our_env);
         if (r < 0) {
                 *exit_status = EXIT_MEMORY;
-                return r;
+                return log_oom();
         }
 
         r = build_pass_environment(context, &pass_env);
         if (r < 0) {
                 *exit_status = EXIT_MEMORY;
-                return r;
+                return log_oom();
         }
 
         accum_env = strv_env_merge(5,
@@ -2770,7 +2736,7 @@ static int exec_child(
                                    NULL);
         if (!accum_env) {
                 *exit_status = EXIT_MEMORY;
-                return -ENOMEM;
+                return log_oom();
         }
         accum_env = strv_env_clean(accum_env);
 
@@ -2779,8 +2745,7 @@ static int exec_child(
         r = setup_keyring(unit, context, params, uid, gid);
         if (r < 0) {
                 *exit_status = EXIT_KEYRING;
-                *error_message = strdup("Failed to set up kernel keyring");
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to set up kernel keyring: %m");
         }
 
         /* We need sandboxing if the caller asked us to apply it and the command isn't explicitly excepted from it */
@@ -2816,8 +2781,7 @@ static int exec_child(
                         r = setup_pam(context->pam_name, username, uid, gid, context->tty_path, &accum_env, fds, n_fds);
                         if (r < 0) {
                                 *exit_status = EXIT_PAM;
-                                *error_message = strdup("Failed to set up PAM session");
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to set up PAM session: %m");
                         }
                 }
         }
@@ -2826,8 +2790,7 @@ static int exec_child(
                 r = setup_netns(runtime->netns_storage_socket);
                 if (r < 0) {
                         *exit_status = EXIT_NETWORK;
-                        *error_message = strdup("Failed to set up network namespacing");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to set up network namespacing: %m");
                 }
         }
 
@@ -2836,25 +2799,21 @@ static int exec_child(
                 r = apply_mount_namespace(unit, command, context, params, runtime);
                 if (r < 0) {
                         *exit_status = EXIT_NAMESPACE;
-                        *error_message = strdup("Failed to set up mount namespacing");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to set up mount namespacing: %m");
                 }
         }
 
         /* Apply just after mount namespace setup */
         r = apply_working_directory(context, params, home, needs_mount_namespace, exit_status);
-        if (r < 0) {
-                *error_message = strdup("Changing to the requested working directory failed");
-                return r;
-        }
+        if (r < 0)
+                return log_unit_error_errno(unit, r, "Changing to the requested working directory failed: %m");
 
         /* Drop groups as early as possbile */
         if (needs_setuid) {
                 r = enforce_groups(context, gid, supplementary_gids, ngids);
                 if (r < 0) {
-                        *error_message = strdup("Changing group credentials failed");
                         *exit_status = EXIT_GROUP;
-                        return r;
+                        return log_unit_error_errno(unit, r, "Changing group credentials failed: %m");
                 }
         }
 
@@ -2863,9 +2822,8 @@ static int exec_child(
                 if (use_selinux && params->selinux_context_net && socket_fd >= 0) {
                         r = mac_selinux_get_child_mls_label(socket_fd, command->path, context->selinux_context, &mac_selinux_context_net);
                         if (r < 0) {
-                                *error_message = strdup("Failed to determine SELinux context");
                                 *exit_status = EXIT_SELINUX_CONTEXT;
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to determine SELinux context: %m");
                         }
                 }
 #endif
@@ -2873,9 +2831,8 @@ static int exec_child(
                 if (context->private_users) {
                         r = setup_private_users(uid, gid);
                         if (r < 0) {
-                                *error_message = strdup("Failed to set up user namespacing");
                                 *exit_status = EXIT_USER;
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to set up user namespacing: %m");
                         }
                 }
         }
@@ -2889,9 +2846,8 @@ static int exec_child(
         if (r >= 0)
                 r = flags_fds(fds, n_storage_fds, n_socket_fds, context->non_blocking);
         if (r < 0) {
-                *error_message = strdup("Failed to adjust passed file descriptors");
                 *exit_status = EXIT_FDS;
-                return r;
+                return log_unit_error_errno(unit, r, "Failed to adjust passed file descriptors: %m");
         }
 
         secure_bits = context->secure_bits;
@@ -2906,18 +2862,16 @@ static int exec_child(
 
                         r = setrlimit_closest(i, context->rlimit[i]);
                         if (r < 0) {
-                                *error_message = strdup("Failed to adjust resource limits");
                                 *exit_status = EXIT_LIMITS;
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to adjust resource limit %s: %m", rlimit_to_string(i));
                         }
                 }
 
                 /* Set the RTPRIO resource limit to 0, but only if nothing else was explicitly requested. */
                 if (context->restrict_realtime && !context->rlimit[RLIMIT_RTPRIO]) {
                         if (setrlimit(RLIMIT_RTPRIO, &RLIMIT_MAKE_CONST(0)) < 0) {
-                                *error_message = strdup("Failed to adjust RLIMIT_RTPRIO resource limit");
                                 *exit_status = EXIT_LIMITS;
-                                return -errno;
+                                return log_unit_error_errno(unit, errno, "Failed to adjust RLIMIT_RTPRIO resource limit: %m");
                         }
                 }
 
@@ -2934,8 +2888,7 @@ static int exec_child(
                         r = capability_bounding_set_drop(bset, false);
                         if (r < 0) {
                                 *exit_status = EXIT_CAPABILITIES;
-                                *error_message = strdup("Failed to drop capabilities");
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to drop capabilities: %m");
                         }
                 }
 
@@ -2946,8 +2899,7 @@ static int exec_child(
                         r = capability_ambient_set_apply(context->capability_ambient_set, true);
                         if (r < 0) {
                                 *exit_status = EXIT_CAPABILITIES;
-                                *error_message = strdup("Failed to apply ambient capabilities (before UID change)");
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to apply ambient capabilities (before UID change): %m");
                         }
                 }
         }
@@ -2957,8 +2909,7 @@ static int exec_child(
                         r = enforce_user(context, uid);
                         if (r < 0) {
                                 *exit_status = EXIT_USER;
-                                (void) asprintf(error_message, "Failed to change UID to "UID_FMT, uid);
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to change UID to " UID_FMT ": %m", uid);
                         }
 
                         if (!needs_ambient_hack &&
@@ -2968,8 +2919,7 @@ static int exec_child(
                                 r = capability_ambient_set_apply(context->capability_ambient_set, false);
                                 if (r < 0) {
                                         *exit_status = EXIT_CAPABILITIES;
-                                        *error_message = strdup("Failed to apply ambient capabilities (after UID change)");
-                                        return r;
+                                        return log_unit_error_errno(unit, r, "Failed to apply ambient capabilities (after UID change): %m");
                                 }
 
                                 /* If we were asked to change user and ambient capabilities
@@ -2998,8 +2948,7 @@ static int exec_child(
                                 r = setexeccon(exec_context);
                                 if (r < 0) {
                                         *exit_status = EXIT_SELINUX_CONTEXT;
-                                        (void) asprintf(error_message, "Failed to change SELinux context to %s", exec_context);
-                                        return r;
+                                        return log_unit_error_errno(unit, r, "Failed to change SELinux context to %s: %m", exec_context);
                                 }
                         }
                 }
@@ -3010,8 +2959,7 @@ static int exec_child(
                         r = setup_smack(context, command);
                         if (r < 0) {
                                 *exit_status = EXIT_SMACK_PROCESS_LABEL;
-                                *error_message = strdup("Failed to set SMACK process label");
-                                return r;
+                                return log_unit_error_errno(unit, r, "Failed to set SMACK process label: %m");
                         }
                 }
 #endif
@@ -3021,10 +2969,7 @@ static int exec_child(
                         r = aa_change_onexec(context->apparmor_profile);
                         if (r < 0 && !context->apparmor_profile_ignore) {
                                 *exit_status = EXIT_APPARMOR_PROFILE;
-                                (void) asprintf(error_message,
-                                                "Failed to prepare AppArmor profile change to %s",
-                                                context->apparmor_profile);
-                                return -errno;
+                                return log_unit_error_errno(unit, errno, "Failed to prepare AppArmor profile change to %s: %m", context->apparmor_profile);
                         }
                 }
 #endif
@@ -3034,79 +2979,68 @@ static int exec_child(
                 if (prctl(PR_GET_SECUREBITS) != secure_bits)
                         if (prctl(PR_SET_SECUREBITS, secure_bits) < 0) {
                                 *exit_status = EXIT_SECUREBITS;
-                                *error_message = strdup("Failed to set process secure bits");
-                                return -errno;
+                                return log_unit_error_errno(unit, errno, "Failed to set process secure bits: %m");
                         }
 
                 if (context_has_no_new_privileges(context))
                         if (prctl(PR_SET_NO_NEW_PRIVS, 1, 0, 0, 0) < 0) {
                                 *exit_status = EXIT_NO_NEW_PRIVILEGES;
-                                *error_message = strdup("Failed to disable new privileges");
-                                return -errno;
+                                return log_unit_error_errno(unit, errno, "Failed to disable new privileges: %m");
                         }
 
 #ifdef HAVE_SECCOMP
                 r = apply_address_families(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_ADDRESS_FAMILIES;
-                        *error_message = strdup("Failed to restrict address families");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to restrict address families: %m");
                 }
 
                 r = apply_memory_deny_write_execute(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to disable writing to executable memory");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to disable writing to executable memory: %m");
                 }
 
                 r = apply_restrict_realtime(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply realtime restrictions");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply realtime restrictions: %m");
                 }
 
                 r = apply_restrict_namespaces(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply namespace restrictions");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply namespace restrictions: %m");
                 }
 
                 r = apply_protect_sysctl(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply sysctl restrictions");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply sysctl restrictions: %m");
                 }
 
                 r = apply_protect_kernel_modules(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply module loading restrictions");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply module loading restrictions: %m");
                 }
 
                 r = apply_private_devices(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to set up private devices");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to set up private devices: %m");
                 }
 
                 r = apply_syscall_archs(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply syscall architecture restrictions");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply syscall architecture restrictions: %m");
                 }
 
                 r = apply_lock_personality(unit, context);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to lock personalities");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to lock personalities: %m");
                 }
 
                 /* This really should remain the last step before the execve(), to make sure our own code is unaffected
@@ -3114,8 +3048,7 @@ static int exec_child(
                 r = apply_syscall_filter(unit, context, needs_ambient_hack);
                 if (r < 0) {
                         *exit_status = EXIT_SECCOMP;
-                        *error_message = strdup("Failed to apply system call filters");
-                        return r;
+                        return log_unit_error_errno(unit, r, "Failed to apply system call filters: %m");
                 }
 #endif
         }
@@ -3126,7 +3059,7 @@ static int exec_child(
                 ee = strv_env_delete(accum_env, 1, context->unset_environment);
                 if (!ee) {
                         *exit_status = EXIT_MEMORY;
-                        return -ENOMEM;
+                        return log_oom();
                 }
 
                 strv_free(accum_env);
@@ -3136,8 +3069,7 @@ static int exec_child(
         final_argv = replace_env_argv(argv, accum_env);
         if (!final_argv) {
                 *exit_status = EXIT_MEMORY;
-                *error_message = strdup("Failed to prepare process arguments");
-                return -ENOMEM;
+                return log_oom();
         }
 
         if (_unlikely_(log_get_max_level() >= LOG_DEBUG)) {
@@ -3145,20 +3077,33 @@ static int exec_child(
 
                 line = exec_command_line(final_argv);
                 if (line) {
-                        log_open();
                         log_struct(LOG_DEBUG,
                                    "EXECUTABLE=%s", command->path,
                                    LOG_UNIT_MESSAGE(unit, "Executing: %s", line),
                                    LOG_UNIT_ID(unit),
                                    LOG_UNIT_INVOCATION_ID(unit),
                                    NULL);
-                        log_close();
                 }
         }
 
         execve(command->path, final_argv, accum_env);
+
+        if (errno == ENOENT && (command->flags & EXEC_COMMAND_IGNORE_FAILURE)) {
+
+                log_struct_errno(LOG_INFO, errno,
+                                 "MESSAGE_ID=" SD_MESSAGE_SPAWN_FAILED_STR,
+                                 LOG_UNIT_ID(unit),
+                                 LOG_UNIT_INVOCATION_ID(unit),
+                                 LOG_UNIT_MESSAGE(unit, "Executable %s missing, skipping: %m",
+                                                  command->path),
+                                 "EXECUTABLE=%s", command->path,
+                                 NULL);
+
+                return 0;
+        }
+
         *exit_status = EXIT_EXEC;
-        return -errno;
+        return log_unit_error_errno(unit, errno, "Failed to execute command: %m");
 }
 
 int exec_spawn(Unit *unit,
@@ -3226,13 +3171,13 @@ int exec_spawn(Unit *unit,
                    LOG_UNIT_ID(unit),
                    LOG_UNIT_INVOCATION_ID(unit),
                    NULL);
+
         pid = fork();
         if (pid < 0)
                 return log_unit_error_errno(unit, errno, "Failed to fork: %m");
 
         if (pid == 0) {
-                int exit_status;
-                _cleanup_free_ char *error_message = NULL;
+                int exit_status = EXIT_SUCCESS;
 
                 r = exec_child(unit,
                                command,
@@ -3248,38 +3193,18 @@ int exec_spawn(Unit *unit,
                                n_socket_fds,
                                files_env,
                                unit->manager->user_lookup_fds[1],
-                               &exit_status,
-                               &error_message);
+                               &exit_status);
+
                 if (r < 0) {
-                        log_open();
-                        if (error_message)
-                                log_struct_errno(LOG_ERR, r,
-                                                 "MESSAGE_ID=" SD_MESSAGE_SPAWN_FAILED_STR,
-                                                 LOG_UNIT_ID(unit),
-                                                 LOG_UNIT_INVOCATION_ID(unit),
-                                                 LOG_UNIT_MESSAGE(unit, "%s: %m",
-                                                                  error_message),
-                                                 "EXECUTABLE=%s", command->path,
-                                                 NULL);
-                        else if (r == -ENOENT && (command->flags & EXEC_COMMAND_IGNORE_FAILURE))
-                                log_struct_errno(LOG_INFO, r,
-                                                 "MESSAGE_ID=" SD_MESSAGE_SPAWN_FAILED_STR,
-                                                 LOG_UNIT_ID(unit),
-                                                 LOG_UNIT_INVOCATION_ID(unit),
-                                                 LOG_UNIT_MESSAGE(unit, "Skipped spawning %s: %m",
-                                                                  command->path),
-                                                 "EXECUTABLE=%s", command->path,
-                                                 NULL);
-                        else
-                                log_struct_errno(LOG_ERR, r,
-                                                 "MESSAGE_ID=" SD_MESSAGE_SPAWN_FAILED_STR,
-                                                 LOG_UNIT_ID(unit),
-                                                 LOG_UNIT_INVOCATION_ID(unit),
-                                                 LOG_UNIT_MESSAGE(unit, "Failed at step %s spawning %s: %m",
-                                                                  exit_status_to_string(exit_status, EXIT_STATUS_SYSTEMD),
-                                                                  command->path),
-                                                 "EXECUTABLE=%s", command->path,
-                                                 NULL);
+                        log_struct_errno(LOG_ERR, r,
+                                         "MESSAGE_ID=" SD_MESSAGE_SPAWN_FAILED_STR,
+                                         LOG_UNIT_ID(unit),
+                                         LOG_UNIT_INVOCATION_ID(unit),
+                                         LOG_UNIT_MESSAGE(unit, "Failed at step %s spawning %s: %m",
+                                                          exit_status_to_string(exit_status, EXIT_STATUS_SYSTEMD),
+                                                          command->path),
+                                         "EXECUTABLE=%s", command->path,
+                                         NULL);
                 }
 
                 _exit(exit_status);