core: rework unit printing and implement 'combined' format

The code to print unit status formats had a long history, and became a
hard-to-manage mess of duplicate code parts. We would use sprintf() to
format a string, and then call sprintf() again… The code is reworked
to avoid repeated formattings and to streamline printing to the log
and the console.

The approach used in this patch is a bit more complex then in patches by Colin
Walter and Paweł Marciniak, because an allocation is only done if "combined"
format is used. In other cases we return the existing ->id or ->description
strings. The caller can also control whether a shorter or longer status string
should be used. This way the caller can use a shorter format where it makes
sense, for example in the cylon eye output, where we don't have enough
horizontal space.

Patch is based on Colin Walters' https://github.com/systemd/systemd/pull/15957,
and Paweł Marciniak's patch posted on fedora-devel.

Note: for some reason, the functions for printing of start and stop messages
were sepearated by some unrelated functions. They are moved to be consecutive,
but this makes the much more verbose than it would be otherwise. I found it
useful to view in gitk's "new" mode.

Co-authored-by: Colin Walters <walters@verbum.org>
Co-authored-by: Paweł Marciniak <sunwire+git@gmail.com>

Output from a Fedora Rawhide container boot (w/ some follow-up patches to
tweak Descriptions):

Welcome to Fedora 35 (Rawhide Prerelease)!

Queued start job for default target graphical.target.
[  OK  ] Created slice system-getty.slice - Slice /system/getty.
[  OK  ] Created slice system-modprobe.slice - Slice /system/modprobe.
[  OK  ] Created slice system-sshd\x2dkeygen.slice - Slice /system/sshd-keygen.
[  OK  ] Created slice user.slice - User and Session Slice.
[  OK  ] Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[  OK  ] Reached target cryptsetup.target - Local Encrypted Volumes.
[  OK  ] Reached target paths.target - Path Units.
[  OK  ] Reached target remote-cryptsetup.target - Remote Encrypted Volumes.
[  OK  ] Reached target remote-fs.target - Remote File Systems.
[  OK  ] Reached target slices.target - Slice Units.
[  OK  ] Reached target swap.target - Swaps.
[  OK  ] Reached target veritysetup.target - Local Verity Integrity Protected Volumes.
[  OK  ] Listening on systemd-coredump.socket - Process Core Dump Socket.
[  OK  ] Listening on systemd-initctl.socket - initctl Compatibility Named Pipe.
[  OK  ] Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log).
[  OK  ] Listening on systemd-journald.socket - Journal Socket.
[  OK  ] Listening on systemd-networkd.socket - Network Service Netlink Socket.
[  OK  ] Listening on systemd-userdbd.socket - User Database Manager Socket.
         Mounting dev-hugepages.mount - Huge Pages File System...
         Starting systemd-journald.service - Journal Service...
         Starting systemd-remount-fs.service - Remount Root and Kernel File Systems...
         Starting systemd-sysctl.service - Apply Kernel Variables...
[  OK  ] Mounted dev-hugepages.mount - Huge Pages File System.
[  OK  ] Finished systemd-remount-fs.service - Remount Root and Kernel File Systems.
         Starting systemd-hwdb-update.service - Rebuild Hardware Database...
         Starting systemd-sysusers.service - Create System Users...
[  OK  ] Finished systemd-sysctl.service - Apply Kernel Variables.
[  OK  ] Started systemd-journald.service - Journal Service.
         Starting systemd-journal-flush.service - Flush Journal to Persistent Storage...
[  OK  ] Finished systemd-sysusers.service - Create System Users.
         Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev...
[  OK  ] Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev.
[  OK  ] Reached target local-fs-pre.target - Preparation for Local File Systems.
[  OK  ] Reached target local-fs.target - Local File Systems.
[  OK  ] Reached target machines.target - Containers.
         Starting dracut-shutdown.service - Restore /run/initramfs on shutdown...
         Starting ldconfig.service - Rebuild Dynamic Linker Cache...
[  OK  ] Finished dracut-shutdown.service - Restore /run/initramfs on shutdown.
[  OK  ] Finished ldconfig.service - Rebuild Dynamic Linker Cache.
[  OK  ] Finished systemd-journal-flush.service - Flush Journal to Persistent Storage.
         Starting systemd-tmpfiles-setup.service - Create Volatile Files and Directories...
[  OK  ] Finished systemd-tmpfiles-setup.service - Create Volatile Files and Directories.
         Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog...
         Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
         Starting systemd-update-utmp.service - Update UTMP about System Boot/Shutdown...
         Starting systemd-userdbd.service - User Database Manager...
[  OK  ] Finished systemd-update-utmp.service - Update UTMP about System Boot/Shutdown.
[  OK  ] Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog.
[  OK  ] Started systemd-userdbd.service - User Database Manager.
[  OK  ] Started systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
[  OK  ] Finished systemd-hwdb-update.service - Rebuild Hardware Database.
         Starting systemd-networkd.service - Network Configuration...
         Starting systemd-update-done.service - Update is Completed...
[  OK  ] Finished systemd-update-done.service - Update is Completed.
[  OK  ] Reached target sysinit.target - System Initialization.
[  OK  ] Started dnf-makecache.timer - dnf makecache --timer.
[  OK  ] Started logrotate.timer - Daily rotation of log files.
[  OK  ] Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories.
[  OK  ] Reached target timers.target - Timer Units.
[  OK  ] Listening on dbus.socket - D-Bus System Message Bus Socket.
[  OK  ] Reached target sockets.target - Socket Units.
[  OK  ] Reached target basic.target - Basic System.
[  OK  ] Reached target sshd-keygen.target.
         Starting sysstat.service - Resets System Activity Logs...
         Starting systemd-homed.service - Home Area Manager...
         Starting systemd-logind.service - User Login Management...
         Starting dbus-broker.service - D-Bus System Message Bus...
[FAILED] Failed to start sysstat.service - Resets System Activity Logs.
See 'systemctl status sysstat.service' for details.
[  OK  ] Started dbus-broker.service - D-Bus System Message Bus.
[  OK  ] Started systemd-homed.service - Home Area Manager.
[  OK  ] Finished systemd-homed-activate.service - Home Area Activation.
[  OK  ] Started systemd-logind.service - User Login Management.
[  OK  ] Started systemd-networkd.service - Network Configuration.
         Starting systemd-networkd-wait-online.service - Wait for Network to be Configured...
         Starting systemd-resolved.service - Network Name Resolution...
[  OK  ] Started systemd-resolved.service - Network Name Resolution.
[  OK  ] Reached target network.target - Network.
[  OK  ] Reached target nss-lookup.target - Host and Network Name Lookups.
         Starting sshd.service - OpenSSH server daemon...
         Starting systemd-user-sessions.service - Permit User Sessions...
[  OK  ] Finished systemd-user-sessions.service - Permit User Sessions.
[  OK  ] Started console-getty.service - Console Getty.
[  OK  ] Reached target getty.target - Login Prompts.
[  OK  ] Started sshd.service - OpenSSH server daemon.
[  OK  ] Reached target multi-user.target - Multi-User System.
[  OK  ] Reached target graphical.target - Graphical Interface.
         Starting systemd-update-utmp-runlevel.service - Update UTMP about System Runlevel Changes...
[  OK  ] Finished systemd-update-utmp-runlevel.service - Update UTMP about System Runlevel Changes.

Fedora 35 (Rawhide Prerelease)
Kernel 5.12.12-300.fc34.x86_64 on an x86_64 (console)

rawhide login: [  OK  ] Stopped session-24.scope - Session 24 of User zbyszek.
[  OK  ] Removed slice system-getty.slice - Slice /system/getty.
[  OK  ] Removed slice system-modprobe.slice - Slice /system/modprobe.
[  OK  ] Removed slice system-sshd\x2dkeygen.slice - Slice /system/sshd-keygen.
[  OK  ] Stopped target graphical.target - Graphical Interface.
[  OK  ] Stopped target multi-user.target - Multi-User System.
[  OK  ] Stopped target getty.target - Login Prompts.
[  OK  ] Stopped target machines.target - Containers.
[  OK  ] Stopped target nss-lookup.target - Host and Network Name Lookups.
[  OK  ] Stopped target remote-cryptsetup.target - Remote Encrypted Volumes.
[  OK  ] Stopped target timers.target - Timer Units.
[  OK  ] Stopped dnf-makecache.timer - dnf makecache --timer.
[  OK  ] Stopped logrotate.timer - Daily rotation of log files.
[  OK  ] Stopped systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories.
[  OK  ] Closed systemd-coredump.socket - Process Core Dump Socket.
         Stopping console-getty.service - Console Getty...
         Stopping dracut-shutdown.service - Restore /run/initramfs on shutdown...
         Stopping sshd.service - OpenSSH server daemon...
         Stopping systemd-logind.service - User Login Management...
         Stopping systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
         Stopping user@1000.service - User Manager for UID 1000...
[  OK  ] Stopped systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
[  OK  ] Stopped systemd-networkd-wait-online.service - Wait for Network to be Configured.
[  OK  ] Stopped sshd.service - OpenSSH server daemon.
[  OK  ] Stopped console-getty.service - Console Getty.
[  OK  ] Stopped dracut-shutdown.service - Restore /run/initramfs on shutdown.
[  OK  ] Stopped target sshd-keygen.target.
[  OK  ] Stopped systemd-logind.service - User Login Management.
[  OK  ] Stopped user@1000.service - User Manager for UID 1000.
         Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000...
[  OK  ] Unmounted run-user-1000.mount - /run/user/1000.
[  OK  ] Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000.
[  OK  ] Removed slice user-1000.slice - User Slice of UID 1000.
         Stopping systemd-user-sessions.service - Permit User Sessions...
[  OK  ] Stopped systemd-user-sessions.service - Permit User Sessions.
[  OK  ] Stopped target network.target - Network.
[  OK  ] Stopped target remote-fs.target - Remote File Systems.
         Stopping systemd-homed-activate.service - Home Area Activation...
         Stopping systemd-resolved.service - Network Name Resolution...
[  OK  ] Stopped systemd-resolved.service - Network Name Resolution.
         Stopping systemd-networkd.service - Network Configuration...
[  OK  ] Stopped systemd-homed-activate.service - Home Area Activation.
         Stopping systemd-homed.service - Home Area Manager...
[  OK  ] Stopped systemd-homed.service - Home Area Manager.
[  OK  ] Stopped target basic.target - Basic System.
[  OK  ] Stopped target paths.target - Path Units.
[  OK  ] Stopped target slices.target - Slice Units.
[  OK  ] Removed slice user.slice - User and Session Slice.
[  OK  ] Stopped target sockets.target - Socket Units.
         Stopping dbus-broker.service - D-Bus System Message Bus...
[  OK  ] Stopped dbus-broker.service - D-Bus System Message Bus.
[  OK  ] Closed dbus.socket - D-Bus System Message Bus Socket.
[  OK  ] Stopped target sysinit.target - System Initialization.
[  OK  ] Stopped target cryptsetup.target - Local Encrypted Volumes.
[  OK  ] Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch.
[  OK  ] Stopped systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[  OK  ] Stopped target veritysetup.target - Local Verity Integrity Protected Volumes.
[  OK  ] Stopped systemd-update-done.service - Update is Completed.
[  OK  ] Stopped ldconfig.service - Rebuild Dynamic Linker Cache.
[  OK  ] Stopped systemd-hwdb-update.service - Rebuild Hardware Database.
[  OK  ] Stopped systemd-journal-catalog-update.service - Rebuild Journal Catalog.
         Stopping systemd-update-utmp.service - Update UTMP about System Boot/Shutdown...
[  OK  ] Stopped systemd-networkd.service - Network Configuration.
[  OK  ] Closed systemd-networkd.socket - Network Service Netlink Socket.
[  OK  ] Stopped systemd-sysctl.service - Apply Kernel Variables.
[  OK  ] Stopped systemd-update-utmp.service - Update UTMP about System Boot/Shutdown.
[  OK  ] Stopped systemd-tmpfiles-setup.service - Create Volatile Files and Directories.
[  OK  ] Stopped target local-fs.target - Local File Systems.
         Unmounting home.mount - /home...
         Unmounting run-credentials-systemd\x2dsysusers.se…e.mount - /run/credentials/systemd-sysusers.service...
         Unmounting tmp.mount - Temporary Directory /tmp...
[  OK  ] Unmounted home.mount - /home.
[  OK  ] Unmounted tmp.mount - Temporary Directory /tmp.
[  OK  ] Unmounted run-credentials-systemd\x2dsysusers.service.mount - /run/credentials/systemd-sysusers.service.
[  OK  ] Stopped target local-fs-pre.target - Preparation for Local File Systems.
[  OK  ] Stopped target swap.target - Swaps.
[  OK  ] Reached target umount.target - Unmount All Filesystems.
[  OK  ] Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev.
[  OK  ] Stopped systemd-sysusers.service - Create System Users.
[  OK  ] Stopped systemd-remount-fs.service - Remount Root and Kernel File Systems.
[  OK  ] Reached target shutdown.target - System Shutdown.
[  OK  ] Reached target final.target - Late Boot Services.
[  OK  ] Finished systemd-poweroff.service - System Power Off.
[  OK  ] Reached target poweroff.target - System Power Off.
Sending SIGTERM to remaining processes...
Sending SIGKILL to remaining processes...
All filesystems, swaps, loop devices, MD devices and DM devices detached.
Powering off.

8 files changed, 253 insertions, 310 deletions

diff --git a/src/core/job.c b/src/core/job.c
index a273e4220e..e09bd64a87 100644
--- a/src/core/job.c
+++ b/src/core/job.c
@@ -506,95 +506,241 @@ static void job_change_type(Job *j, JobType newtype) {
         j->type = newtype;
 }
 
-_pure_ static const char* job_get_begin_status_message_format(Unit *u, JobType t) {
-        const char *format;
-
+static const char* job_start_message_format(Unit *u, JobType t) {
         assert(u);
+        assert(IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD));
 
         if (t == JOB_RELOAD)
-                return "Reloading %s.";
+                return "Reloading %s...";
+        else if (t == JOB_START)
+                return UNIT_VTABLE(u)->status_message_formats.starting_stopping[0] ?: "Starting %s...";
+        else
+                return UNIT_VTABLE(u)->status_message_formats.starting_stopping[1] ?: "Stopping %s...";
+}
 
-        assert(IN_SET(t, JOB_START, JOB_STOP));
+static void job_emit_start_message(Unit *u, uint32_t job_id, JobType t) {
+        _cleanup_free_ char *free_ident = NULL;
+        const char *ident, *format;
 
-        format = UNIT_VTABLE(u)->status_message_formats.starting_stopping[t == JOB_STOP];
-        if (format)
-                return format;
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+        assert(u->id); /* We better don't try to run a unit that doesn't even have an id. */
 
-        /* Return generic strings */
-        if (t == JOB_START)
-                return "Starting %s.";
-        else {
-                assert(t == JOB_STOP);
-                return "Stopping %s.";
+        if (!IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD))
+                return;
+
+        if (!unit_log_level_test(u, LOG_INFO))
+                return;
+
+        format = job_start_message_format(u, t);
+        ident = unit_status_string(u, &free_ident);
+
+        bool do_console = t != JOB_RELOAD;
+        bool console_only = do_console && log_on_console(); /* Reload status messages have traditionally
+                                                             * not been printed to the console. */
+
+        /* Print to the log first. */
+        if (!console_only) {  /* Skip this if it would only go on the console anyway */
+
+                const char *mid =
+                        t == JOB_START ? "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTING_STR :
+                        t == JOB_STOP  ? "MESSAGE_ID=" SD_MESSAGE_UNIT_STOPPING_STR :
+                                         "MESSAGE_ID=" SD_MESSAGE_UNIT_RELOADING_STR;
+                const char *msg_fmt = strjoina("MESSAGE=", format);
+
+                /* Note that we deliberately use LOG_MESSAGE() instead of LOG_UNIT_MESSAGE() here, since this
+                 * is supposed to mimic closely what is written to screen using the status output, which is
+                 * supposed to be high level friendly output. */
+
+                DISABLE_WARNING_FORMAT_NONLITERAL;
+                log_unit_struct(u, LOG_INFO,
+                                msg_fmt, ident,
+                                "JOB_ID=%" PRIu32, job_id,
+                                "JOB_TYPE=%s", job_type_to_string(t),
+                                LOG_UNIT_INVOCATION_ID(u),
+                                mid);
+                REENABLE_WARNING;
+        }
+
+        /* Log to the console second. */
+        if (do_console) {
+                DISABLE_WARNING_FORMAT_NONLITERAL;
+                unit_status_printf(u, STATUS_TYPE_NORMAL, "", format, ident);
+                REENABLE_WARNING;
         }
 }
 
-static void job_print_begin_status_message(Unit *u, JobType t) {
+static const char* job_done_message_format(Unit *u, JobType t, JobResult result) {
+        static const char* const generic_finished_start_job[_JOB_RESULT_MAX] = {
+                [JOB_DONE]        = "Started %s.",
+                [JOB_TIMEOUT]     = "Timed out starting %s.",
+                [JOB_FAILED]      = "Failed to start %s.",
+                [JOB_DEPENDENCY]  = "Dependency failed for %s.",
+                [JOB_ASSERT]      = "Assertion failed for %s.",
+                [JOB_UNSUPPORTED] = "Starting of %s unsupported.",
+                [JOB_COLLECTED]   = "Unnecessary job was removed for %s.",
+                [JOB_ONCE]        = "Unit %s has been started before and cannot be started again.",
+        };
+        static const char* const generic_finished_stop_job[_JOB_RESULT_MAX] = {
+                [JOB_DONE]        = "Stopped %s.",
+                [JOB_FAILED]      = "Stopped %s with error.",
+                [JOB_TIMEOUT]     = "Timed out stopping %s.",
+        };
+        static const char* const generic_finished_reload_job[_JOB_RESULT_MAX] = {
+                [JOB_DONE]        = "Reloaded %s.",
+                [JOB_FAILED]      = "Reload failed for %s.",
+                [JOB_TIMEOUT]     = "Timed out reloading %s.",
+        };
+        /* When verify-active detects the unit is inactive, report it.
+         * Most likely a DEPEND warning from a requisiting unit will
+         * occur next and it's nice to see what was requisited. */
+        static const char* const generic_finished_verify_active_job[_JOB_RESULT_MAX] = {
+                [JOB_SKIPPED]     = "%s is inactive.",
+        };
         const char *format;
 
         assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
 
-        /* Reload status messages have traditionally not been printed to console. */
-        if (!IN_SET(t, JOB_START, JOB_STOP))
-                return;
+        /* Show condition check message if the job did not actually do anything due to failed condition. */
+        if (t == JOB_START && result == JOB_DONE && !u->condition_result)
+                return "Condition check resulted in %s being skipped.";
+
+        if (IN_SET(t, JOB_START, JOB_STOP, JOB_RESTART)) {
+                const UnitStatusMessageFormats *formats = &UNIT_VTABLE(u)->status_message_formats;
+                if (formats->finished_job) {
+                        format = formats->finished_job(u, t, result);
+                        if (format)
+                                return format;
+                }
 
-        format = job_get_begin_status_message_format(u, t);
+                format = (t == JOB_START ? formats->finished_start_job : formats->finished_stop_job)[result];
+                if (format)
+                        return format;
+        }
 
-        DISABLE_WARNING_FORMAT_NONLITERAL;
-        unit_status_printf(u, STATUS_TYPE_NORMAL, "", format);
-        REENABLE_WARNING;
+        /* Return generic strings */
+        switch (t) {
+        case JOB_START:
+                return generic_finished_start_job[result];
+        case JOB_STOP:
+        case JOB_RESTART:
+                return generic_finished_stop_job[result];
+        case JOB_RELOAD:
+                return generic_finished_reload_job[result];
+        case JOB_VERIFY_ACTIVE:
+                return generic_finished_verify_active_job[result];
+        default:
+                return NULL;
+        }
+}
+
+static const struct {
+        int log_level;
+        const char *color, *word;
+} job_done_messages[_JOB_RESULT_MAX] = {
+        [JOB_DONE]        = { LOG_INFO,    ANSI_OK_COLOR,         "  OK  " },
+        [JOB_CANCELED]    = { LOG_INFO,                                    },
+        [JOB_TIMEOUT]     = { LOG_ERR,     ANSI_HIGHLIGHT_RED,    " TIME " },
+        [JOB_FAILED]      = { LOG_ERR,     ANSI_HIGHLIGHT_RED,    "FAILED" },
+        [JOB_DEPENDENCY]  = { LOG_WARNING, ANSI_HIGHLIGHT_YELLOW, "DEPEND" },
+        [JOB_SKIPPED]     = { LOG_NOTICE,  ANSI_HIGHLIGHT,        " INFO " },
+        [JOB_INVALID]     = { LOG_INFO,                                    },
+        [JOB_ASSERT]      = { LOG_WARNING, ANSI_HIGHLIGHT_YELLOW, "ASSERT" },
+        [JOB_UNSUPPORTED] = { LOG_WARNING, ANSI_HIGHLIGHT_YELLOW, "UNSUPP" },
+        [JOB_COLLECTED]   = { LOG_INFO,                                    },
+        [JOB_ONCE]        = { LOG_ERR,     ANSI_HIGHLIGHT_RED,    " ONCE " },
+};
+
+static const char* job_done_mid(JobType type, JobResult result) {
+        switch (type) {
+        case JOB_START:
+                if (result == JOB_DONE)
+                        return "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTED_STR;
+                else
+                        return "MESSAGE_ID=" SD_MESSAGE_UNIT_FAILED_STR;
+
+        case JOB_RELOAD:
+                return "MESSAGE_ID=" SD_MESSAGE_UNIT_RELOADED_STR;
+
+        case JOB_STOP:
+        case JOB_RESTART:
+                return "MESSAGE_ID=" SD_MESSAGE_UNIT_STOPPED_STR;
+
+        default:
+                return NULL;
+        }
 }
 
-static void job_log_begin_status_message(Unit *u, uint32_t job_id, JobType t) {
-        const char *format, *mid;
-        char buf[LINE_MAX];
+static void job_emit_done_message(Unit *u, uint32_t job_id, JobType t, JobResult result) {
+        _cleanup_free_ char *free_ident = NULL;
+        const char *ident, *format;
 
         assert(u);
         assert(t >= 0);
         assert(t < _JOB_TYPE_MAX);
 
-        if (!IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD))
+        if (!unit_log_level_test(u, job_done_messages[result].log_level))
                 return;
 
-        if (!unit_log_level_test(u, LOG_INFO))
+        format = job_done_message_format(u, t, result);
+        if (!format)
                 return;
 
-        if (log_on_console()) /* Skip this if it would only go on the console anyway */
-                return;
+        ident = unit_status_string(u, &free_ident);
 
-        /* We log status messages for all units and all operations. */
-
-        format = job_get_begin_status_message_format(u, t);
-
-        DISABLE_WARNING_FORMAT_NONLITERAL;
-        (void) snprintf(buf, sizeof buf, format, unit_status_string(u));
-        REENABLE_WARNING;
-
-        mid = t == JOB_START ? "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTING_STR :
-              t == JOB_STOP  ? "MESSAGE_ID=" SD_MESSAGE_UNIT_STOPPING_STR :
-                               "MESSAGE_ID=" SD_MESSAGE_UNIT_RELOADING_STR;
-
-        /* Note that we deliberately use LOG_MESSAGE() instead of
-         * LOG_UNIT_MESSAGE() here, since this is supposed to mimic
-         * closely what is written to screen using the status output,
-         * which is supposed the highest level, friendliest output
-         * possible, which means we should avoid the low-level unit
-         * name. */
-        log_unit_struct(u, LOG_INFO,
-                        LOG_MESSAGE("%s", buf),
-                        "JOB_ID=%" PRIu32, job_id,
-                        "JOB_TYPE=%s", job_type_to_string(t),
-                        LOG_UNIT_INVOCATION_ID(u),
-                        mid);
-}
+        const char *status = job_done_messages[result].word;
+        bool do_console = t != JOB_RELOAD && status;
+        bool console_only = do_console && log_on_console();
 
-static void job_emit_begin_status_message(Unit *u, uint32_t job_id, JobType t) {
-        assert(u);
-        assert(t >= 0);
-        assert(t < _JOB_TYPE_MAX);
+        if (t == JOB_START && result == JOB_DONE && !u->condition_result) {
+                /* No message on the console if the job did not actually do anything due to failed condition. */
+                if (console_only)
+                        return;
+                else
+                        do_console = false;
+        }
+
+        if (!console_only) {  /* Skip printing if output goes to the console, and job_print_status_message()
+                               * will actually print something to the console. */
 
-        job_log_begin_status_message(u, job_id, t);
-        job_print_begin_status_message(u, t);
+                const char *mid = job_done_mid(t, result);  /* mid may be NULL. log_unit_struct() will ignore it. */
+                const char *msg_fmt = strjoina("MESSAGE=", format);
+
+                DISABLE_WARNING_FORMAT_NONLITERAL;
+                log_unit_struct(u, job_done_messages[result].log_level,
+                                msg_fmt, ident,
+                                "JOB_ID=%" PRIu32, job_id,
+                                "JOB_TYPE=%s", job_type_to_string(t),
+                                "JOB_RESULT=%s", job_result_to_string(result),
+                                LOG_UNIT_INVOCATION_ID(u),
+                                mid);
+                REENABLE_WARNING;
+        }
+
+        if (do_console) {
+                if (log_get_show_color())
+                        status = strjoina(job_done_messages[result].color,
+                                          status,
+                                          ANSI_NORMAL);
+
+                DISABLE_WARNING_FORMAT_NONLITERAL;
+                unit_status_printf(u,
+                                   result == JOB_DONE ? STATUS_TYPE_NORMAL : STATUS_TYPE_NOTICE,
+                                   status, format, ident);
+                REENABLE_WARNING;
+
+                if (t == JOB_START && result == JOB_FAILED) {
+                        _cleanup_free_ char *quoted = NULL;
+
+                        quoted = shell_maybe_quote(u->id, 0);
+                        if (quoted)
+                                manager_status_printf(u->manager, STATUS_TYPE_NORMAL, NULL,
+                                                      "See 'systemctl status %s' for details.", quoted);
+                }
+        }
 }
 
 static int job_perform_on_unit(Job **j) {
@@ -643,7 +789,7 @@ static int job_perform_on_unit(Job **j) {
          * 'active') we'll possibly skip the "Starting..." message. */
         *j = manager_get_job(m, id);
         if (*j && r > 0)
-                job_emit_begin_status_message(u, id, t);
+                job_emit_start_message(u, id, t);
 
         return r;
 }
@@ -732,224 +878,6 @@ int job_run_and_invalidate(Job *j) {
         return r;
 }
 
-_pure_ static const char *job_get_done_status_message_format(Unit *u, JobType t, JobResult result) {
-
-        static const char *const generic_finished_start_job[_JOB_RESULT_MAX] = {
-                [JOB_DONE]        = "Started %s.",
-                [JOB_TIMEOUT]     = "Timed out starting %s.",
-                [JOB_FAILED]      = "Failed to start %s.",
-                [JOB_DEPENDENCY]  = "Dependency failed for %s.",
-                [JOB_ASSERT]      = "Assertion failed for %s.",
-                [JOB_UNSUPPORTED] = "Starting of %s not supported.",
-                [JOB_COLLECTED]   = "Unnecessary job for %s was removed.",
-                [JOB_ONCE]        = "Unit %s has been started before and cannot be started again."
-        };
-        static const char *const generic_finished_stop_job[_JOB_RESULT_MAX] = {
-                [JOB_DONE]        = "Stopped %s.",
-                [JOB_FAILED]      = "Stopped (with error) %s.",
-                [JOB_TIMEOUT]     = "Timed out stopping %s.",
-        };
-        static const char *const generic_finished_reload_job[_JOB_RESULT_MAX] = {
-                [JOB_DONE]        = "Reloaded %s.",
-                [JOB_FAILED]      = "Reload failed for %s.",
-                [JOB_TIMEOUT]     = "Timed out reloading %s.",
-        };
-        /* When verify-active detects the unit is inactive, report it.
-         * Most likely a DEPEND warning from a requisiting unit will
-         * occur next and it's nice to see what was requisited. */
-        static const char *const generic_finished_verify_active_job[_JOB_RESULT_MAX] = {
-                [JOB_SKIPPED]     = "%s is not active.",
-        };
-
-        const char *format;
-
-        assert(u);
-        assert(t >= 0);
-        assert(t < _JOB_TYPE_MAX);
-
-        if (IN_SET(t, JOB_START, JOB_STOP, JOB_RESTART)) {
-                const UnitStatusMessageFormats *formats = &UNIT_VTABLE(u)->status_message_formats;
-                if (formats->finished_job) {
-                        format = formats->finished_job(u, t, result);
-                        if (format)
-                                return format;
-                }
-                format = t == JOB_START ?
-                        formats->finished_start_job[result] :
-                        formats->finished_stop_job[result];
-                if (format)
-                        return format;
-        }
-
-        /* Return generic strings */
-        if (t == JOB_START)
-                return generic_finished_start_job[result];
-        else if (IN_SET(t, JOB_STOP, JOB_RESTART))
-                return generic_finished_stop_job[result];
-        else if (t == JOB_RELOAD)
-                return generic_finished_reload_job[result];
-        else if (t == JOB_VERIFY_ACTIVE)
-                return generic_finished_verify_active_job[result];
-
-        return NULL;
-}
-
-static const struct {
-        const char *color, *word;
-} job_print_done_status_messages[_JOB_RESULT_MAX] = {
-        [JOB_DONE]        = { ANSI_OK_COLOR,         "  OK  " },
-        [JOB_TIMEOUT]     = { ANSI_HIGHLIGHT_RED,    " TIME " },
-        [JOB_FAILED]      = { ANSI_HIGHLIGHT_RED,    "FAILED" },
-        [JOB_DEPENDENCY]  = { ANSI_HIGHLIGHT_YELLOW, "DEPEND" },
-        [JOB_SKIPPED]     = { ANSI_HIGHLIGHT,        " INFO " },
-        [JOB_ASSERT]      = { ANSI_HIGHLIGHT_YELLOW, "ASSERT" },
-        [JOB_UNSUPPORTED] = { ANSI_HIGHLIGHT_YELLOW, "UNSUPP" },
-        /* JOB_COLLECTED */
-        [JOB_ONCE]        = { ANSI_HIGHLIGHT_RED,    " ONCE " },
-};
-
-static void job_print_done_status_message(Unit *u, JobType t, JobResult result) {
-        const char *format;
-        const char *status;
-
-        assert(u);
-        assert(t >= 0);
-        assert(t < _JOB_TYPE_MAX);
-
-        /* Reload status messages have traditionally not been printed to console. */
-        if (t == JOB_RELOAD)
-                return;
-
-        /* No message if the job did not actually do anything due to failed condition. */
-        if (t == JOB_START && result == JOB_DONE && !u->condition_result)
-                return;
-
-        if (!job_print_done_status_messages[result].word)
-                return;
-
-        format = job_get_done_status_message_format(u, t, result);
-        if (!format)
-                return;
-
-        if (log_get_show_color())
-                status = strjoina(job_print_done_status_messages[result].color,
-                                  job_print_done_status_messages[result].word,
-                                  ANSI_NORMAL);
-        else
-                status = job_print_done_status_messages[result].word;
-
-        DISABLE_WARNING_FORMAT_NONLITERAL;
-        unit_status_printf(u,
-                           result == JOB_DONE ? STATUS_TYPE_NORMAL : STATUS_TYPE_NOTICE,
-                           status, format);
-        REENABLE_WARNING;
-
-        if (t == JOB_START && result == JOB_FAILED) {
-                _cleanup_free_ char *quoted = NULL;
-
-                quoted = shell_maybe_quote(u->id, 0);
-                manager_status_printf(u->manager, STATUS_TYPE_NORMAL, NULL, "See 'systemctl status %s' for details.", strna(quoted));
-        }
-}
-
-static void job_log_done_status_message(Unit *u, uint32_t job_id, JobType t, JobResult result) {
-        const char *format, *mid;
-        char buf[LINE_MAX];
-        static const int job_result_log_level[_JOB_RESULT_MAX] = {
-                [JOB_DONE]        = LOG_INFO,
-                [JOB_CANCELED]    = LOG_INFO,
-                [JOB_TIMEOUT]     = LOG_ERR,
-                [JOB_FAILED]      = LOG_ERR,
-                [JOB_DEPENDENCY]  = LOG_WARNING,
-                [JOB_SKIPPED]     = LOG_NOTICE,
-                [JOB_INVALID]     = LOG_INFO,
-                [JOB_ASSERT]      = LOG_WARNING,
-                [JOB_UNSUPPORTED] = LOG_WARNING,
-                [JOB_COLLECTED]   = LOG_INFO,
-                [JOB_ONCE]        = LOG_ERR,
-        };
-
-        assert(u);
-        assert(t >= 0);
-        assert(t < _JOB_TYPE_MAX);
-
-        /* Skip printing if output goes to the console, and job_print_status_message()
-           will actually print something to the console. */
-        if (log_on_console() && job_print_done_status_messages[result].word)
-                return;
-
-        /* Show condition check message if the job did not actually do anything due to failed condition. */
-        if (t == JOB_START && result == JOB_DONE && !u->condition_result) {
-                log_unit_struct(u, LOG_INFO,
-                                "MESSAGE=Condition check resulted in %s being skipped.", unit_status_string(u),
-                                "JOB_ID=%" PRIu32, job_id,
-                                "JOB_TYPE=%s", job_type_to_string(t),
-                                "JOB_RESULT=%s", job_result_to_string(result),
-                                LOG_UNIT_INVOCATION_ID(u),
-                                "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTED_STR);
-
-                return;
-        }
-
-        if (!unit_log_level_test(u, job_result_log_level[result]))
-                return;
-
-        format = job_get_done_status_message_format(u, t, result);
-        if (!format)
-                return;
-
-        /* The description might be longer than the buffer, but that's OK,
-         * we'll just truncate it here. Note that we use snprintf() rather than
-         * xsprintf() on purpose here: we are fine with truncation and don't
-         * consider that an error. */
-        DISABLE_WARNING_FORMAT_NONLITERAL;
-        (void) snprintf(buf, sizeof(buf), format, unit_status_string(u));
-        REENABLE_WARNING;
-
-        switch (t) {
-
-        case JOB_START:
-                if (result == JOB_DONE)
-                        mid = "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTED_STR;
-                else
-                        mid = "MESSAGE_ID=" SD_MESSAGE_UNIT_FAILED_STR;
-                break;
-
-        case JOB_RELOAD:
-                mid = "MESSAGE_ID=" SD_MESSAGE_UNIT_RELOADED_STR;
-                break;
-
-        case JOB_STOP:
-        case JOB_RESTART:
-                mid = "MESSAGE_ID=" SD_MESSAGE_UNIT_STOPPED_STR;
-                break;
-
-        default:
-                log_unit_struct(u, job_result_log_level[result],
-                                LOG_MESSAGE("%s", buf),
-                                "JOB_ID=%" PRIu32, job_id,
-                                "JOB_TYPE=%s", job_type_to_string(t),
-                                "JOB_RESULT=%s", job_result_to_string(result),
-                                LOG_UNIT_INVOCATION_ID(u));
-                return;
-        }
-
-        log_unit_struct(u, job_result_log_level[result],
-                        LOG_MESSAGE("%s", buf),
-                        "JOB_ID=%" PRIu32, job_id,
-                        "JOB_TYPE=%s", job_type_to_string(t),
-                        "JOB_RESULT=%s", job_result_to_string(result),
-                        LOG_UNIT_INVOCATION_ID(u),
-                        mid);
-}
-
-static void job_emit_done_status_message(Unit *u, uint32_t job_id, JobType t, JobResult result) {
-        assert(u);
-
-        job_log_done_status_message(u, job_id, t, result);
-        job_print_done_status_message(u, t, result);
-}
-
 static void job_fail_dependencies(Unit *u, UnitDependencyAtom match_atom) {
         Unit *other;
 
@@ -985,7 +913,7 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive, bool alr
 
         /* If this job did nothing to the respective unit we don't log the status message */
         if (!already)
-                job_emit_done_status_message(u, j->id, t, result);
+                job_emit_done_message(u, j->id, t, result);
 
         /* Patch restart jobs so that they become normal start jobs */
         if (result == JOB_DONE && t == JOB_RESTART) {
diff --git a/src/core/main.c b/src/core/main.c
index 906c1482d7..da6c50a1c4 100644
--- a/src/core/main.c
+++ b/src/core/main.c
@@ -2219,7 +2219,7 @@ static int do_queue_default_job(
         } else
                 log_info("Queued %s job for default target %s.",
                          job_type_to_string(job->type),
-                         unit_status_string(job->unit));
+                         unit_status_string(job->unit, NULL));
 
         m->default_unit_job_id = job->id;
 
diff --git a/src/core/manager.c b/src/core/manager.c
index f3275a4070..3a4cae2d56 100644
--- a/src/core/manager.c
+++ b/src/core/manager.c
@@ -240,11 +240,18 @@ static void manager_print_jobs_in_progress(Manager *m) {
         if (job_get_timeout(j, &x) > 0)
                 format_timespan(limit, sizeof(limit), x - j->begin_usec, 1*USEC_PER_SEC);
 
+        /* We want to use enough information for the user to identify previous lines talking about the same
+         * unit, but keep the message as short as possible. So if 'Starting foo.service' or 'Starting
+         * foo.service (Description)' were used, 'foo.service' is enough here. On the other hand, if we used
+         * 'Starting Description' before, then we shall also use 'Description' here. So we pass NULL as the
+         * second argument to unit_status_string(). */
+        const char *ident = unit_status_string(j->unit, NULL);
+
         manager_status_printf(m, STATUS_TYPE_EPHEMERAL, cylon,
                               "%sA %s job is running for %s (%s / %s)",
                               strempty(job_of_n),
                               job_type_to_string(j->type),
-                              unit_status_string(j->unit),
+                              ident,
                               time, limit);
 }
 
diff --git a/src/core/service.c b/src/core/service.c
index af5a2decf1..cf530c2c33 100644
--- a/src/core/service.c
+++ b/src/core/service.c
@@ -4430,12 +4430,10 @@ static int service_can_clean(Unit *u, ExecCleanMask *ret) {
 }
 
 static const char *service_finished_job(Unit *u, JobType t, JobResult result) {
-        if (t == JOB_START && result == JOB_DONE) {
-                Service *s = SERVICE(u);
-
-                if (s->type == SERVICE_ONESHOT)
-                        return "Finished %s.";
-        }
+        if (t == JOB_START &&
+            result == JOB_DONE &&
+            SERVICE(u)->type == SERVICE_ONESHOT)
+                return "Finished %s.";
 
         /* Fall back to generic */
         return NULL;
@@ -4601,10 +4599,6 @@ const UnitVTable service_vtable = {
         .exit_status = service_exit_status,
 
         .status_message_formats = {
-                .starting_stopping = {
-                        [0] = "Starting %s...",
-                        [1] = "Stopping %s...",
-                },
                 .finished_start_job = {
                         [JOB_FAILED]     = "Failed to start %s.",
                 },
diff --git a/src/core/socket.c b/src/core/socket.c
index a64bf7360c..239fbc5c2c 100644
--- a/src/core/socket.c
+++ b/src/core/socket.c
@@ -3543,10 +3543,6 @@ const UnitVTable socket_vtable = {
         .bus_commit_properties = bus_socket_commit_properties,
 
         .status_message_formats = {
-                /*.starting_stopping = {
-                        [0] = "Starting socket %s...",
-                        [1] = "Stopping socket %s...",
-                },*/
                 .finished_start_job = {
                         [JOB_DONE]       = "Listening on %s.",
                         [JOB_FAILED]     = "Failed to listen on %s.",
diff --git a/src/core/transaction.c b/src/core/transaction.c
index 51232e4ab1..ebe5f1910d 100644
--- a/src/core/transaction.c
+++ b/src/core/transaction.c
@@ -419,7 +419,8 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi
                         unit_status_printf(delete->unit,
                                            STATUS_TYPE_NOTICE,
                                            status,
-                                           "Ordering cycle found, skipping %s");
+                                           "Ordering cycle found, skipping %s",
+                                           unit_status_string(delete->unit, NULL));
                         transaction_delete_unit(tr, delete->unit);
                         return -EAGAIN;
                 }
diff --git a/src/core/unit.c b/src/core/unit.c
index 3792cee711..ff9019a449 100644
--- a/src/core/unit.c
+++ b/src/core/unit.c
@@ -1331,7 +1331,7 @@ int unit_add_exec_dependencies(Unit *u, ExecContext *c) {
         return 0;
 }
 
-const char *unit_description(Unit *u) {
+const char* unit_description(Unit *u) {
         assert(u);
 
         if (u->description)
@@ -1340,13 +1340,29 @@ const char *unit_description(Unit *u) {
         return strna(u->id);
 }
 
-const char *unit_status_string(Unit *u) {
+const char* unit_status_string(Unit *u, char **combined) {
         assert(u);
+        assert(u->id);
 
-        if (u->manager->status_unit_format == STATUS_UNIT_FORMAT_NAME && u->id)
+        /* Return u->id, u->description, or "{u->id} - {u->description}".
+         * Versions with u->description are only used if it is set.
+         * The last option is used if configured and the caller provided 'combined' pointer. */
+
+        if (!u->description ||
+            u->manager->status_unit_format == STATUS_UNIT_FORMAT_NAME ||
+            (u->manager->status_unit_format == STATUS_UNIT_FORMAT_COMBINED && !combined))
                 return u->id;
 
-        return unit_description(u);
+        if (u->description && u->manager->status_unit_format == STATUS_UNIT_FORMAT_COMBINED && combined) {
+                char *t = strjoin(u->id, " - ", u->description);
+                if (t) {
+                        *combined = t;
+                        return t;
+                } else
+                        log_oom();
+        }
+
+        return u->description;
 }
 
 /* Common implementation for multiple backends */
@@ -1730,15 +1746,16 @@ static bool unit_test_assert(Unit *u) {
         return u->assert_result;
 }
 
-void unit_status_printf(Unit *u, StatusType status_type, const char *status, const char *unit_status_msg_format) {
-        const char *d;
-
-        d = unit_status_string(u);
-        if (log_get_show_color())
-                d = strjoina(ANSI_HIGHLIGHT, d, ANSI_NORMAL);
+void unit_status_printf(Unit *u, StatusType status_type, const char *status, const char *format, const char *ident) {
+        if (log_get_show_color()) {
+                if (u->manager->status_unit_format == STATUS_UNIT_FORMAT_COMBINED && strchr(ident, ' '))
+                        ident = strjoina(ANSI_HIGHLIGHT, u->id, ANSI_NORMAL, " - ", u->description);
+                else
+                        ident = strjoina(ANSI_HIGHLIGHT, ident, ANSI_NORMAL);
+        }
 
         DISABLE_WARNING_FORMAT_NONLITERAL;
-        manager_status_printf(u->manager, status_type, status, unit_status_msg_format, d);
+        manager_status_printf(u->manager, status_type, status, format, ident);
         REENABLE_WARNING;
 }
 
diff --git a/src/core/unit.h b/src/core/unit.h
index 3b302e7e20..759104ffa7 100644
--- a/src/core/unit.h
+++ b/src/core/unit.h
@@ -765,7 +765,7 @@ int unit_set_slice(Unit *u, Unit *slice, UnitDependencyMask mask);
 int unit_set_default_slice(Unit *u);
 
 const char *unit_description(Unit *u) _pure_;
-const char *unit_status_string(Unit *u) _pure_;
+const char *unit_status_string(Unit *u, char **combined);
 
 bool unit_has_name(const Unit *u, const char *name);
 
@@ -820,7 +820,7 @@ int unit_add_blockdev_dependency(Unit *u, const char *what, UnitDependencyMask m
 int unit_coldplug(Unit *u);
 void unit_catchup(Unit *u);
 
-void unit_status_printf(Unit *u, StatusType status_type, const char *status, const char *unit_status_msg_format) _printf_(4, 0);
+void unit_status_printf(Unit *u, StatusType status_type, const char *status, const char *format, const char *ident) _printf_(4, 0);
 
 bool unit_need_daemon_reload(Unit *u);