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.
This commit is contained in:
Zbigniew Jędrzejewski-Szmek 2021-06-28 20:07:15 +02:00
parent 580e198a50
commit 04d232d807
10 changed files with 274 additions and 328 deletions

View file

@ -259,11 +259,15 @@
<listitem><para>Takes <option>name</option>, <option>description</option> or
<option>combined</option> as the value. If <option>name</option>, the system manager will use unit
names in status messages, instead of the longer and more informative descriptions set with
<varname>Description=</varname>, see
<citerefentry><refentrytitle>systemd.unit</refentrytitle><manvolnum>5</manvolnum></citerefentry>. If
<option>combined</option>, the system manager will use unit names and description in status messages.
</para></listitem>
names in status messages (e.g. <literal>systemd-journald.service</literal>), instead of the longer
and more informative descriptions set with <varname>Description=</varname> (e.g. <literal>Journal
Logging Service</literal>). If <option>combined</option>, the system manager will use both unit names
and descriptions in status messages (e.g. <literal>systemdmd-jouranld.service - Journal Logging
Service</literal>).</para>
<para>See
<citerefentry><refentrytitle>systemd.unit</refentrytitle><manvolnum>5</manvolnum></citerefentry> for
details about unit names and <varname>Description=</varname>.</para></listitem>
</varlistentry>
<varlistentry>

View file

@ -561,20 +561,19 @@
<variablelist class='unit-directives'>
<varlistentry>
<term><varname>Description=</varname></term>
<listitem><para>A human readable name for the unit. This is used by
<command>systemd</command> (and other UIs) as the label for the unit, so this string should
identify the unit rather than describe it, despite the name. <literal>Apache2 Web
Server</literal> is a good example. Bad examples are <literal>high-performance light-weight
HTTP server</literal> (too generic) or <literal>Apache2</literal> (too specific and
meaningless for people who do not know Apache). <command>systemd</command> will use this
string as a noun in status messages (<literal>Starting
<listitem><para>A short human readable title of the unit. This may be used by
<command>systemd</command> (and other UIs) as a user-visible label for the unit, so this string
should identify the unit rather than describe it, despite the name. This string also shouldn't just
repeat the unit name. <literal>Apache2 Web Server</literal> is a good example. Bad examples are
<literal>high-performance light-weight HTTP server</literal> (too generic) or
<literal>Apache2</literal> (meaningless for people who do not know Apache, duplicates the unit
name). <command>systemd</command> may use this string as a noun in status messages (<literal>Starting
<replaceable>description</replaceable>...</literal>, <literal>Started
<replaceable>description</replaceable>.</literal>, <literal>Reached target
<replaceable>description</replaceable>.</literal>, <literal>Failed to start
<replaceable>description</replaceable>.</literal>), so it should be capitalized, and should
not be a full sentence or a phrase with a continuous verb. Bad examples include
<literal>exiting the container</literal> or <literal>updating the database once per
day.</literal>.</para>
<replaceable>description</replaceable>.</literal>), so it should be capitalized, and should not be a
full sentence, or a phrase with a continuous verb. Bad examples include <literal>exiting the
container</literal> or <literal>updating the database once per day.</literal>.</para>
</listitem>
</varlistentry>

View file

@ -506,52 +506,26 @@ 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.";
assert(IN_SET(t, JOB_START, JOB_STOP));
format = UNIT_VTABLE(u)->status_message_formats.starting_stopping[t == JOB_STOP];
if (format)
return format;
/* Return generic strings */
if (t == JOB_START)
return "Starting %s.";
else {
assert(t == JOB_STOP);
return "Stopping %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...";
}
static void job_print_begin_status_message(Unit *u, JobType t) {
const char *format;
assert(u);
/* Reload status messages have traditionally not been printed to console. */
if (!IN_SET(t, JOB_START, JOB_STOP))
return;
format = job_get_begin_status_message_format(u, t);
DISABLE_WARNING_FORMAT_NONLITERAL;
unit_status_printf(u, STATUS_TYPE_NORMAL, "", format);
REENABLE_WARNING;
}
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_start_message(Unit *u, uint32_t job_id, JobType t) {
_cleanup_free_ char *free_ident = NULL;
const char *ident, *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. */
if (!IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD))
return;
@ -559,42 +533,214 @@ static void job_log_begin_status_message(Unit *u, uint32_t job_id, JobType t) {
if (!unit_log_level_test(u, LOG_INFO))
return;
if (log_on_console()) /* Skip this if it would only go on the console anyway */
return;
format = job_start_message_format(u, t);
ident = unit_status_string(u, &free_ident);
/* We log status messages for all units and all operations. */
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. */
format = job_get_begin_status_message_format(u, t);
/* Print to the log first. */
if (!console_only) { /* Skip this if it would only go on the console anyway */
DISABLE_WARNING_FORMAT_NONLITERAL;
(void) snprintf(buf, sizeof buf, format, unit_status_string(u));
REENABLE_WARNING;
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);
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 to be high level friendly output. */
/* 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);
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_emit_begin_status_message(Unit *u, uint32_t job_id, 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);
job_log_begin_status_message(u, job_id, t);
job_print_begin_status_message(u, t);
/* 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 = (t == JOB_START ? formats->finished_start_job : formats->finished_stop_job)[result];
if (format)
return format;
}
/* 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_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 (!unit_log_level_test(u, job_done_messages[result].log_level))
return;
format = job_done_message_format(u, t, result);
if (!format)
return;
ident = unit_status_string(u, &free_ident);
const char *status = job_done_messages[result].word;
bool do_console = t != JOB_RELOAD && status;
bool console_only = do_console && log_on_console();
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. */
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) {

View file

@ -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;

View file

@ -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);
}

View file

@ -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.",
},

View file

@ -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.",

View file

@ -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;
}

View file

@ -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;
}

View file

@ -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);