diff --git a/catalog/systemd.catalog.in b/catalog/systemd.catalog.in index 49a45890f6..5c6799ee5d 100644 --- a/catalog/systemd.catalog.in +++ b/catalog/systemd.catalog.in @@ -189,59 +189,67 @@ System shutdown has been initiated. The shutdown has now begun and all system services are terminated and all file systems unmounted. -- 7d4958e842da4a758f6c1cdc7b36dcc5 -Subject: Unit @UNIT@ has begun start-up +Subject: A start job for unit @UNIT@ has begun execution Defined-By: systemd Support: %SUPPORT_URL% -Unit @UNIT@ has begun starting up. +A start job for unit @UNIT@ has begun execution. + +The job identifier is @JOB_ID@. -- 39f53479d3a045ac8e11786248231fbf -Subject: Unit @UNIT@ has finished start-up +Subject: A start job for unit @UNIT@ has finished successfully Defined-By: systemd Support: %SUPPORT_URL% -Unit @UNIT@ has finished starting up. +A start job for unit @UNIT@ has finished successfully. -The start-up result is @JOB_RESULT@. - --- de5b426a63be47a7b6ac3eaac82e2f6f -Subject: Unit @UNIT@ has begun shutting down -Defined-By: systemd -Support: %SUPPORT_URL% - -Unit @UNIT@ has begun shutting down. - --- 9d1aaa27d60140bd96365438aad20286 -Subject: Unit @UNIT@ has finished shutting down -Defined-By: systemd -Support: %SUPPORT_URL% - -Unit @UNIT@ has finished shutting down. +The job identifier is @JOB_ID@. -- be02cf6855d2428ba40df7e9d022f03d -Subject: Unit @UNIT@ has failed +Subject: A start job for unit @UNIT@ has failed Defined-By: systemd Support: %SUPPORT_URL% -Unit @UNIT@ has failed. +A start job for unit @UNIT@ has finished with a failure. -The result is @JOB_RESULT@. +The job identifier is @JOB_ID@ and the job result is @JOB_RESULT@. + +-- de5b426a63be47a7b6ac3eaac82e2f6f +Subject: A stop job for unit @UNIT@ has begun execution +Defined-By: systemd +Support: %SUPPORT_URL% + +A stop job for unit @UNIT@ has begun execution. + +The job identifier is @JOB_ID@. + +-- 9d1aaa27d60140bd96365438aad20286 +Subject: A stop job for unit @UNIT@ has finished +Defined-By: systemd +Support: %SUPPORT_URL% + +A stop job for unit @UNIT@ has finished. + +The job identifier is @JOB_ID@ and the job result is @JOB_RESULT@. -- d34d037fff1847e6ae669a370e694725 -Subject: Unit @UNIT@ has begun reloading its configuration +Subject: A reload job for unit @UNIT@ has begun execution Defined-By: systemd Support: %SUPPORT_URL% -Unit @UNIT@ has begun reloading its configuration +A reload job for unit @UNIT@ has begun execution. + +The job identifier is @JOB_ID@. -- 7b05ebc668384222baa8881179cfda54 -Subject: Unit @UNIT@ has finished reloading its configuration +Subject: A reload job for unit @UNIT@ has finished Defined-By: systemd Support: %SUPPORT_URL% -Unit @UNIT@ has finished reloading its configuration +A reload job for unit @UNIT@ has finished. -The result is @JOB_RESULT@. +The job identifier is @JOB_ID@ and the job result is @JOB_RESULT@. -- 641257651c1b4ec9a8624d7a40a9e1e7 Subject: Process @EXECUTABLE@ could not be executed @@ -344,6 +352,29 @@ Support: %SUPPORT_URL% The unit @UNIT@ completed and consumed the indicated resources. +-- 7ad2d189f7e94e70a38c781354912448 +Subject: Unit succeeded +Defined-By: systemd +Support: %SUPPORT_URL% + +The unit @UNIT@ has successfully entered the 'dead' state. + +-- d9b373ed55a64feb8242e02dbe79a49c +Subject: Unit failed +Defined-By: systemd +Support: %SUPPORT_URL% + +The unit @UNIT@ has entered the 'failed' state with result '@UNIT_RESULT@'. + +-- 98e322203f7a4ed290d09fe03c09fe15 +Subject: Unit process exited +Defined-By: systemd +Support: %SUPPORT_URL% + +An @COMMAND@= process belonging to unit @UNIT@ has exited. + +The process' exit code is '@EXIT_CODE@' and its exit status is @EXIT_STATUS@. + -- 50876a9db00f4c40bde1a2ad381c3a1b Subject: The system is configured in a way that might cause problems Defined-By: systemd diff --git a/src/core/automount.c b/src/core/automount.c index eaacf5e8b9..9da3f87fca 100644 --- a/src/core/automount.c +++ b/src/core/automount.c @@ -315,8 +315,10 @@ static void automount_enter_dead(Automount *a, AutomountResult f) { if (a->result == AUTOMOUNT_SUCCESS) a->result = f; - if (a->result != AUTOMOUNT_SUCCESS) - log_unit_warning(UNIT(a), "Failed with result '%s'.", automount_result_to_string(a->result)); + if (a->result == AUTOMOUNT_SUCCESS) + unit_log_success(UNIT(a)); + else + unit_log_failure(UNIT(a), automount_result_to_string(a->result)); automount_set_state(a, a->result != AUTOMOUNT_SUCCESS ? AUTOMOUNT_FAILED : AUTOMOUNT_DEAD); } diff --git a/src/core/job.c b/src/core/job.c index 2dc520389b..8f36e02eb9 100644 --- a/src/core/job.c +++ b/src/core/job.c @@ -509,6 +509,95 @@ 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; + + assert(u); + + 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."; + } +} + +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, "", 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]; + + assert(u); + assert(t >= 0); + assert(t < _JOB_TYPE_MAX); + + if (!IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD)) + return; + + if (log_on_console()) /* Skip this if it would only go on the console anyway */ + return; + + /* 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_description(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_struct(LOG_INFO, + LOG_MESSAGE("%s", buf), + "JOB_ID=%" PRIu32, job_id, + "JOB_TYPE=%s", job_type_to_string(t), + LOG_UNIT_ID(u), + LOG_UNIT_INVOCATION_ID(u), + mid); +} + +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); + + job_log_begin_status_message(u, job_id, t); + job_print_begin_status_message(u, t); +} + static int job_perform_on_unit(Job **j) { uint32_t id; Manager *m; @@ -550,11 +639,12 @@ static int job_perform_on_unit(Job **j) { assert_not_reached("Invalid job type"); } - /* Log if the job still exists and the start/stop/reload function - * actually did something. */ + /* Log if the job still exists and the start/stop/reload function actually did something. Note that this means + * for units for which there's no 'activating' phase (i.e. because we transition directly from 'inactive' to + * 'active') we'll possibly skip the "Starting..." message. */ *j = manager_get_job(m, id); if (*j && r > 0) - unit_status_emit_starting_stopping_reloading(u, t); + job_emit_begin_status_message(u, id, t); return r; } @@ -583,7 +673,9 @@ int job_run_and_invalidate(Job *j) { switch (j->type) { case JOB_VERIFY_ACTIVE: { - UnitActiveState t = unit_active_state(j->unit); + UnitActiveState t; + + t = unit_active_state(j->unit); if (UNIT_IS_ACTIVE_OR_RELOADING(t)) r = -EALREADY; else if (t == UNIT_ACTIVATING) @@ -598,8 +690,7 @@ int job_run_and_invalidate(Job *j) { case JOB_RESTART: r = job_perform_on_unit(&j); - /* If the unit type does not support starting/stopping, - * then simply wait. */ + /* If the unit type does not support starting/stopping, then simply wait. */ if (r == -EBADR) r = 0; break; @@ -617,8 +708,12 @@ int job_run_and_invalidate(Job *j) { } if (j) { - if (r == -EALREADY) + if (r == -EAGAIN) + job_set_state(j, JOB_WAITING); /* Hmm, not ready after all, let's return to JOB_WAITING state */ + else if (r == -EALREADY) /* already being executed */ r = job_finish_and_invalidate(j, JOB_DONE, true, true); + else if (r == -ECOMM) /* condition failed, but all is good */ + r = job_finish_and_invalidate(j, JOB_DONE, true, false); else if (r == -EBADR) r = job_finish_and_invalidate(j, JOB_SKIPPED, true, false); else if (r == -ENOEXEC) @@ -631,8 +726,6 @@ int job_run_and_invalidate(Job *j) { r = job_finish_and_invalidate(j, JOB_DEPENDENCY, true, false); else if (r == -ESTALE) r = job_finish_and_invalidate(j, JOB_ONCE, true, false); - else if (r == -EAGAIN) - job_set_state(j, JOB_WAITING); else if (r < 0) r = job_finish_and_invalidate(j, JOB_FAILED, true, false); } @@ -640,7 +733,7 @@ int job_run_and_invalidate(Job *j) { return r; } -_pure_ static const char *job_get_status_message_format(Unit *u, JobType t, JobResult result) { +_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.", @@ -669,7 +762,6 @@ _pure_ static const char *job_get_status_message_format(Unit *u, JobType t, JobR [JOB_SKIPPED] = "%s is not active.", }; - const UnitStatusMessageFormats *format_table; const char *format; assert(u); @@ -677,13 +769,11 @@ _pure_ static const char *job_get_status_message_format(Unit *u, JobType t, JobR assert(t < _JOB_TYPE_MAX); if (IN_SET(t, JOB_START, JOB_STOP, JOB_RESTART)) { - format_table = &UNIT_VTABLE(u)->status_message_formats; - if (format_table) { - format = t == JOB_START ? format_table->finished_start_job[result] : - format_table->finished_stop_job[result]; - if (format) - return format; - } + format = t == JOB_START ? + UNIT_VTABLE(u)->status_message_formats.finished_start_job[result] : + UNIT_VTABLE(u)->status_message_formats.finished_stop_job[result]; + if (format) + return format; } /* Return generic strings */ @@ -701,7 +791,7 @@ _pure_ static const char *job_get_status_message_format(Unit *u, JobType t, JobR static const struct { const char *color, *word; -} job_print_status_messages [_JOB_RESULT_MAX] = { +} 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" }, @@ -713,7 +803,7 @@ static const struct { [JOB_ONCE] = { ANSI_HIGHLIGHT_RED, " ONCE " }, }; -static void job_print_status_message(Unit *u, JobType t, JobResult result) { +static void job_print_done_status_message(Unit *u, JobType t, JobResult result) { const char *format; const char *status; @@ -725,19 +815,23 @@ static void job_print_status_message(Unit *u, JobType t, JobResult result) { if (t == JOB_RELOAD) return; - if (!job_print_status_messages[result].word) + /* 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; - format = job_get_status_message_format(u, t, result); + 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_status_messages[result].color, - job_print_status_messages[result].word, + status = strjoina(job_print_done_status_messages[result].color, + job_print_done_status_messages[result].word, ANSI_NORMAL); else - status = job_print_status_messages[result].word; + status = job_print_done_status_messages[result].word; if (result != JOB_DONE) manager_flip_auto_status(u->manager, true); @@ -754,7 +848,7 @@ static void job_print_status_message(Unit *u, JobType t, JobResult result) { } } -static void job_log_status_message(Unit *u, JobType t, JobResult result) { +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] = { @@ -777,10 +871,24 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) { /* 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_status_messages[result].word) + if (log_on_console() && job_print_done_status_messages[result].word) return; - format = job_get_status_message_format(u, t, result); + /* 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_struct(LOG_INFO, + "MESSAGE=Condition check resulted in %s being skipped.", unit_description(u), + "JOB_ID=%" PRIu32, job_id, + "JOB_TYPE=%s", job_type_to_string(t), + "JOB_RESULT=%s", job_result_to_string(result), + LOG_UNIT_ID(u), + LOG_UNIT_INVOCATION_ID(u), + "MESSAGE_ID=" SD_MESSAGE_UNIT_STARTED_STR); + + return; + } + + format = job_get_done_status_message_format(u, t, result); if (!format) return; @@ -813,6 +921,7 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) { default: log_struct(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_ID(u), @@ -822,6 +931,7 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) { log_struct(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_ID(u), @@ -829,15 +939,11 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) { mid); } -static void job_emit_status_message(Unit *u, JobType t, JobResult result) { +static void job_emit_done_status_message(Unit *u, uint32_t job_id, JobType t, JobResult result) { assert(u); - /* 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; - - job_log_status_message(u, t, result); - job_print_status_message(u, t, result); + 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, UnitDependency d) { @@ -888,11 +994,11 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive, bool alr j->result = result; - log_unit_debug(u, "Job %s/%s finished, result=%s", u->id, job_type_to_string(t), job_result_to_string(result)); + log_unit_debug(u, "Job %" PRIu32 " %s/%s finished, result=%s", j->id, u->id, job_type_to_string(t), job_result_to_string(result)); /* If this job did nothing to respective unit we don't log the status message */ if (!already) - job_emit_status_message(u, t, result); + job_emit_done_status_message(u, j->id, t, result); /* Patch restart jobs so that they become normal start jobs */ if (result == JOB_DONE && t == JOB_RESTART) { @@ -1033,14 +1139,19 @@ int job_start_timer(Job *j, bool job_running) { } void job_add_to_run_queue(Job *j) { + int r; + assert(j); assert(j->installed); if (j->in_run_queue) return; - if (!j->manager->run_queue) - sd_event_source_set_enabled(j->manager->run_queue_event_source, SD_EVENT_ONESHOT); + if (!j->manager->run_queue) { + r = sd_event_source_set_enabled(j->manager->run_queue_event_source, SD_EVENT_ONESHOT); + if (r < 0) + log_warning_errno(r, "Failed to enable job run queue event source, ignoring: %m"); + } LIST_PREPEND(run_queue, j->manager->run_queue, j); j->in_run_queue = true; diff --git a/src/core/manager.c b/src/core/manager.c index 1f739bf22b..14be38600d 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -2138,7 +2138,7 @@ static int manager_dispatch_run_queue(sd_event_source *source, void *userdata) { assert(j->installed); assert(j->in_run_queue); - job_run_and_invalidate(j); + (void) job_run_and_invalidate(j); } if (m->n_running_jobs > 0) diff --git a/src/core/mount.c b/src/core/mount.c index 5e1ef1e6ac..8035a73184 100644 --- a/src/core/mount.c +++ b/src/core/mount.c @@ -799,8 +799,10 @@ static void mount_enter_dead(Mount *m, MountResult f) { if (m->result == MOUNT_SUCCESS) m->result = f; - if (m->result != MOUNT_SUCCESS) - log_unit_warning(UNIT(m), "Failed with result '%s'.", mount_result_to_string(m->result)); + if (m->result == MOUNT_SUCCESS) + unit_log_success(UNIT(m)); + else + unit_log_failure(UNIT(m), mount_result_to_string(m->result)); mount_set_state(m, m->result != MOUNT_SUCCESS ? MOUNT_FAILED : MOUNT_DEAD); @@ -1270,8 +1272,11 @@ static void mount_sigchld_event(Unit *u, pid_t pid, int code, int status) { m->control_command_id = _MOUNT_EXEC_COMMAND_INVALID; } - log_unit_full(u, f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, - "Mount process exited, code=%s status=%i", sigchld_code_to_string(code), status); + unit_log_process_exit( + u, f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "Mount process", + mount_exec_command_to_string(m->control_command_id), + code, status); /* Note that due to the io event priority logic, we can be sure the new mountinfo is loaded * before we process the SIGCHLD for the mount command. */ diff --git a/src/core/path.c b/src/core/path.c index 258e3a00cb..7523bf54f7 100644 --- a/src/core/path.c +++ b/src/core/path.c @@ -449,8 +449,10 @@ static void path_enter_dead(Path *p, PathResult f) { if (p->result == PATH_SUCCESS) p->result = f; - if (p->result != PATH_SUCCESS) - log_unit_warning(UNIT(p), "Failed with result '%s'.", path_result_to_string(p->result)); + if (p->result == PATH_SUCCESS) + unit_log_success(UNIT(p)); + else + unit_log_failure(UNIT(p), path_result_to_string(p->result)); path_set_state(p, p->result != PATH_SUCCESS ? PATH_FAILED : PATH_DEAD); } diff --git a/src/core/scope.c b/src/core/scope.c index 7883d19325..6d8d4af56d 100644 --- a/src/core/scope.c +++ b/src/core/scope.c @@ -240,8 +240,10 @@ static void scope_enter_dead(Scope *s, ScopeResult f) { if (s->result == SCOPE_SUCCESS) s->result = f; - if (s->result != SCOPE_SUCCESS) - log_unit_warning(UNIT(s), "Failed with result '%s'.", scope_result_to_string(s->result)); + if (s->result == SCOPE_SUCCESS) + unit_log_success(UNIT(s)); + else + unit_log_failure(UNIT(s), scope_result_to_string(s->result)); scope_set_state(s, s->result != SCOPE_SUCCESS ? SCOPE_FAILED : SCOPE_DEAD); } diff --git a/src/core/service.c b/src/core/service.c index 50ceda7ac6..a90711213c 100644 --- a/src/core/service.c +++ b/src/core/service.c @@ -1699,8 +1699,10 @@ static void service_enter_dead(Service *s, ServiceResult f, bool allow_restart) if (s->result == SERVICE_SUCCESS) s->result = f; - if (s->result != SERVICE_SUCCESS) - log_unit_warning(UNIT(s), "Failed with result '%s'.", service_result_to_string(s->result)); + if (s->result == SERVICE_SUCCESS) + unit_log_success(UNIT(s)); + else + unit_log_failure(UNIT(s), service_result_to_string(s->result)); if (allow_restart && service_shall_restart(s)) s->will_auto_restart = true; @@ -3233,21 +3235,13 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { /* When this is a successful exit, let's log about the exit code on DEBUG level. If this is a failure * and the process exited on its own via exit(), then let's make this a NOTICE, under the assumption - * that the service already logged the reason at a higher log level on its own. However, if the service - * died due to a signal, then it most likely didn't say anything about any reason, hence let's raise - * our log level to WARNING then. */ - - log_struct(f == SERVICE_SUCCESS ? LOG_DEBUG : - (code == CLD_EXITED ? LOG_NOTICE : LOG_WARNING), - LOG_UNIT_MESSAGE(u, "Main process exited, code=%s, status=%i/%s", - sigchld_code_to_string(code), status, - strna(code == CLD_EXITED - ? exit_status_to_string(status, EXIT_STATUS_FULL) - : signal_to_string(status))), - "EXIT_CODE=%s", sigchld_code_to_string(code), - "EXIT_STATUS=%i", status, - LOG_UNIT_ID(u), - LOG_UNIT_INVOCATION_ID(u)); + * that the service already logged the reason at a higher log level on its own. (Internally, + * unit_log_process_exit() will possibly bump this to WARNING if the service died due to a signal.) */ + unit_log_process_exit( + u, f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "Main process", + service_exec_command_to_string(SERVICE_EXEC_START), + code, status); if (s->result == SERVICE_SUCCESS) s->result = f; @@ -3336,9 +3330,11 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SERVICE_SUCCESS; } - log_unit_full(u, f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, - "Control process exited, code=%s status=%i", - sigchld_code_to_string(code), status); + unit_log_process_exit( + u, f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "Control process", + service_exec_command_to_string(s->control_command_id), + code, status); if (s->result == SERVICE_SUCCESS) s->result = f; diff --git a/src/core/socket.c b/src/core/socket.c index 407ad1352c..f725c9eb00 100644 --- a/src/core/socket.c +++ b/src/core/socket.c @@ -1985,8 +1985,10 @@ static void socket_enter_dead(Socket *s, SocketResult f) { if (s->result == SOCKET_SUCCESS) s->result = f; - if (s->result != SOCKET_SUCCESS) - log_unit_warning(UNIT(s), "Failed with result '%s'.", socket_result_to_string(s->result)); + if (s->result == SOCKET_SUCCESS) + unit_log_success(UNIT(s)); + else + unit_log_failure(UNIT(s), socket_result_to_string(s->result)); socket_set_state(s, s->result != SOCKET_SUCCESS ? SOCKET_FAILED : SOCKET_DEAD); @@ -2968,9 +2970,11 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SOCKET_SUCCESS; } - log_unit_full(u, f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, - "Control process exited, code=%s status=%i", - sigchld_code_to_string(code), status); + unit_log_process_exit( + u, f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "Control process", + socket_exec_command_to_string(s->control_command_id), + code, status); if (s->result == SOCKET_SUCCESS) s->result = f; diff --git a/src/core/swap.c b/src/core/swap.c index ff1412879f..e2b888ec9e 100644 --- a/src/core/swap.c +++ b/src/core/swap.c @@ -653,8 +653,10 @@ static void swap_enter_dead(Swap *s, SwapResult f) { if (s->result == SWAP_SUCCESS) s->result = f; - if (s->result != SWAP_SUCCESS) - log_unit_warning(UNIT(s), "Failed with result '%s'.", swap_result_to_string(s->result)); + if (s->result == SWAP_SUCCESS) + unit_log_success(UNIT(s)); + else + unit_log_failure(UNIT(s), swap_result_to_string(s->result)); swap_set_state(s, s->result != SWAP_SUCCESS ? SWAP_FAILED : SWAP_DEAD); @@ -1011,8 +1013,11 @@ static void swap_sigchld_event(Unit *u, pid_t pid, int code, int status) { s->control_command_id = _SWAP_EXEC_COMMAND_INVALID; } - log_unit_full(u, f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, - "Swap process exited, code=%s status=%i", sigchld_code_to_string(code), status); + unit_log_process_exit( + u, f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "Swap process", + swap_exec_command_to_string(s->control_command_id), + code, status); switch (s->state) { diff --git a/src/core/timer.c b/src/core/timer.c index bd119cabd3..c7f769dbe1 100644 --- a/src/core/timer.c +++ b/src/core/timer.c @@ -288,8 +288,10 @@ static void timer_enter_dead(Timer *t, TimerResult f) { if (t->result == TIMER_SUCCESS) t->result = f; - if (t->result != TIMER_SUCCESS) - log_unit_warning(UNIT(t), "Failed with result '%s'.", timer_result_to_string(t->result)); + if (t->result == TIMER_SUCCESS) + unit_log_success(UNIT(t)); + else + unit_log_failure(UNIT(t), timer_result_to_string(t->result)); timer_set_state(t, t->result != TIMER_SUCCESS ? TIMER_FAILED : TIMER_DEAD); } diff --git a/src/core/unit.c b/src/core/unit.c index c4a0b49edb..ab057ada87 100644 --- a/src/core/unit.c +++ b/src/core/unit.c @@ -1627,92 +1627,6 @@ void unit_status_printf(Unit *u, const char *status, const char *unit_status_msg REENABLE_WARNING; } -_pure_ static const char* unit_get_status_message_format(Unit *u, JobType t) { - const char *format; - const UnitStatusMessageFormats *format_table; - - assert(u); - assert(IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD)); - - if (t != JOB_RELOAD) { - format_table = &UNIT_VTABLE(u)->status_message_formats; - if (format_table) { - format = format_table->starting_stopping[t == JOB_STOP]; - if (format) - return format; - } - } - - /* Return generic strings */ - if (t == JOB_START) - return "Starting %s."; - else if (t == JOB_STOP) - return "Stopping %s."; - else - return "Reloading %s."; -} - -static void unit_status_print_starting_stopping(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 = unit_get_status_message_format(u, t); - - DISABLE_WARNING_FORMAT_NONLITERAL; - unit_status_printf(u, "", format); - REENABLE_WARNING; -} - -static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) { - const char *format, *mid; - char buf[LINE_MAX]; - - assert(u); - - if (!IN_SET(t, JOB_START, JOB_STOP, JOB_RELOAD)) - return; - - if (log_on_console()) - return; - - /* We log status messages for all units and all operations. */ - - format = unit_get_status_message_format(u, t); - - DISABLE_WARNING_FORMAT_NONLITERAL; - (void) snprintf(buf, sizeof buf, format, unit_description(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_struct(LOG_INFO, - LOG_MESSAGE("%s", buf), - LOG_UNIT_ID(u), - LOG_UNIT_INVOCATION_ID(u), - mid); -} - -void unit_status_emit_starting_stopping_reloading(Unit *u, JobType t) { - assert(u); - assert(t >= 0); - assert(t < _JOB_TYPE_MAX); - - unit_status_log_starting_stopping_reloading(u, t); - unit_status_print_starting_stopping(u, t); -} int unit_start_limit_test(Unit *u) { const char *reason; @@ -1812,7 +1726,7 @@ int unit_start(Unit *u) { if (state != UNIT_ACTIVATING && !unit_condition_test(u)) { log_unit_debug(u, "Starting requested but condition failed. Not starting unit."); - return -EALREADY; + return -ECOMM; } /* If the asserts failed, fail the entire job */ @@ -5530,6 +5444,57 @@ int unit_pid_attachable(Unit *u, pid_t pid, sd_bus_error *error) { return 0; } +void unit_log_success(Unit *u) { + assert(u); + + log_struct(LOG_INFO, + "MESSAGE_ID=" SD_MESSAGE_UNIT_SUCCESS_STR, + LOG_UNIT_ID(u), + LOG_UNIT_INVOCATION_ID(u), + LOG_UNIT_MESSAGE(u, "Succeeded.")); +} + +void unit_log_failure(Unit *u, const char *result) { + assert(u); + assert(result); + + log_struct(LOG_WARNING, + "MESSAGE_ID=" SD_MESSAGE_UNIT_FAILURE_RESULT_STR, + LOG_UNIT_ID(u), + LOG_UNIT_INVOCATION_ID(u), + LOG_UNIT_MESSAGE(u, "Failed with result '%s'.", result), + "UNIT_RESULT=%s", result); +} + +void unit_log_process_exit( + Unit *u, + int level, + const char *kind, + const char *command, + int code, + int status) { + + assert(u); + assert(kind); + + if (code != CLD_EXITED) + level = LOG_WARNING; + + log_struct(level, + "MESSAGE_ID=" SD_MESSAGE_UNIT_PROCESS_EXIT_STR, + LOG_UNIT_MESSAGE(u, "%s exited, code=%s, status=%i/%s", + kind, + sigchld_code_to_string(code), status, + strna(code == CLD_EXITED + ? exit_status_to_string(status, EXIT_STATUS_FULL) + : signal_to_string(status))), + "EXIT_CODE=%s", sigchld_code_to_string(code), + "EXIT_STATUS=%i", status, + "COMMAND=%s", strna(command), + LOG_UNIT_ID(u), + LOG_UNIT_INVOCATION_ID(u)); +} + static const char* const collect_mode_table[_COLLECT_MODE_MAX] = { [COLLECT_INACTIVE] = "inactive", [COLLECT_INACTIVE_OR_FAILED] = "inactive-or-failed", diff --git a/src/core/unit.h b/src/core/unit.h index c6ee1dfc3b..3931684a56 100644 --- a/src/core/unit.h +++ b/src/core/unit.h @@ -701,7 +701,6 @@ int unit_coldplug(Unit *u); void unit_catchup(Unit *u); void unit_status_printf(Unit *u, const char *status, const char *unit_status_msg_format) _printf_(3, 0); -void unit_status_emit_starting_stopping_reloading(Unit *u, JobType t); bool unit_need_daemon_reload(Unit *u); @@ -807,6 +806,10 @@ const char *unit_label_path(Unit *u); int unit_pid_attachable(Unit *unit, pid_t pid, sd_bus_error *error); +void unit_log_success(Unit *u); +void unit_log_failure(Unit *u, const char *result); +void unit_log_process_exit(Unit *u, int level, const char *kind, const char *command, int code, int status); + /* Macros which append UNIT= or USER_UNIT= to the message */ #define log_unit_full(unit, level, error, ...) \ diff --git a/src/systemd/sd-messages.h b/src/systemd/sd-messages.h index ba6c6b1cf8..293db8e8e1 100644 --- a/src/systemd/sd-messages.h +++ b/src/systemd/sd-messages.h @@ -81,16 +81,19 @@ _SD_BEGIN_DECLARATIONS; #define SD_MESSAGE_SHUTDOWN SD_ID128_MAKE(98,26,88,66,d1,d5,4a,49,9c,4e,98,92,1d,93,bc,40) #define SD_MESSAGE_SHUTDOWN_STR SD_ID128_MAKE_STR(98,26,88,66,d1,d5,4a,49,9c,4e,98,92,1d,93,bc,40) +/* The messages below are actually about jobs, not really about units, the macros are misleadingly named. Moreover + * SD_MESSAGE_UNIT_FAILED is not actually about a failing unit but about a failed start job. A job either finishes with + * SD_MESSAGE_UNIT_STARTED or with SD_MESSAGE_UNIT_FAILED hence. */ #define SD_MESSAGE_UNIT_STARTING SD_ID128_MAKE(7d,49,58,e8,42,da,4a,75,8f,6c,1c,dc,7b,36,dc,c5) #define SD_MESSAGE_UNIT_STARTING_STR SD_ID128_MAKE_STR(7d,49,58,e8,42,da,4a,75,8f,6c,1c,dc,7b,36,dc,c5) #define SD_MESSAGE_UNIT_STARTED SD_ID128_MAKE(39,f5,34,79,d3,a0,45,ac,8e,11,78,62,48,23,1f,bf) #define SD_MESSAGE_UNIT_STARTED_STR SD_ID128_MAKE_STR(39,f5,34,79,d3,a0,45,ac,8e,11,78,62,48,23,1f,bf) +#define SD_MESSAGE_UNIT_FAILED SD_ID128_MAKE(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d) +#define SD_MESSAGE_UNIT_FAILED_STR SD_ID128_MAKE_STR(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d) #define SD_MESSAGE_UNIT_STOPPING SD_ID128_MAKE(de,5b,42,6a,63,be,47,a7,b6,ac,3e,aa,c8,2e,2f,6f) #define SD_MESSAGE_UNIT_STOPPING_STR SD_ID128_MAKE_STR(de,5b,42,6a,63,be,47,a7,b6,ac,3e,aa,c8,2e,2f,6f) #define SD_MESSAGE_UNIT_STOPPED SD_ID128_MAKE(9d,1a,aa,27,d6,01,40,bd,96,36,54,38,aa,d2,02,86) #define SD_MESSAGE_UNIT_STOPPED_STR SD_ID128_MAKE_STR(9d,1a,aa,27,d6,01,40,bd,96,36,54,38,aa,d2,02,86) -#define SD_MESSAGE_UNIT_FAILED SD_ID128_MAKE(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d) -#define SD_MESSAGE_UNIT_FAILED_STR SD_ID128_MAKE_STR(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d) #define SD_MESSAGE_UNIT_RELOADING SD_ID128_MAKE(d3,4d,03,7f,ff,18,47,e6,ae,66,9a,37,0e,69,47,25) #define SD_MESSAGE_UNIT_RELOADING_STR SD_ID128_MAKE_STR(d3,4d,03,7f,ff,18,47,e6,ae,66,9a,37,0e,69,47,25) #define SD_MESSAGE_UNIT_RELOADED SD_ID128_MAKE(7b,05,eb,c6,68,38,42,22,ba,a8,88,11,79,cf,da,54) @@ -103,9 +106,18 @@ _SD_BEGIN_DECLARATIONS; #define SD_MESSAGE_UNIT_RESOURCES SD_ID128_MAKE(ae,8f,7b,86,6b,03,47,b9,af,31,fe,1c,80,b1,27,c0) #define SD_MESSAGE_UNIT_RESOURCES_STR SD_ID128_MAKE_STR(ae,8f,7b,86,6b,03,47,b9,af,31,fe,1c,80,b1,27,c0) +#define SD_MESSAGE_UNIT_SUCCESS SD_ID128_MAKE(7a,d2,d1,89,f7,e9,4e,70,a3,8c,78,13,54,91,24,48) +#define SD_MESSAGE_UNIT_SUCCESS_STR SD_ID128_MAKE_STR(7a,d2,d1,89,f7,e9,4e,70,a3,8c,78,13,54,91,24,48) +#define SD_MESSAGE_UNIT_FAILURE_RESULT SD_ID128_MAKE(d9,b3,73,ed,55,a6,4f,eb,82,42,e0,2d,be,79,a4,9c) +#define SD_MESSAGE_UNIT_FAILURE_RESULT_STR \ + SD_ID128_MAKE_STR(d9,b3,73,ed,55,a6,4f,eb,82,42,e0,2d,be,79,a4,9c) + #define SD_MESSAGE_SPAWN_FAILED SD_ID128_MAKE(64,12,57,65,1c,1b,4e,c9,a8,62,4d,7a,40,a9,e1,e7) #define SD_MESSAGE_SPAWN_FAILED_STR SD_ID128_MAKE_STR(64,12,57,65,1c,1b,4e,c9,a8,62,4d,7a,40,a9,e1,e7) +#define SD_MESSAGE_UNIT_PROCESS_EXIT SD_ID128_MAKE(98,e3,22,20,3f,7a,4e,d2,90,d0,9f,e0,3c,09,fe,15) +#define SD_MESSAGE_UNIT_PROCESS_EXIT_STR SD_ID128_MAKE_STR(98,e3,22,20,3f,7a,4e,d2,90,d0,9f,e0,3c,09,fe,15) + #define SD_MESSAGE_FORWARD_SYSLOG_MISSED SD_ID128_MAKE(00,27,22,9c,a0,64,41,81,a7,6c,4e,92,45,8a,fa,2e) #define SD_MESSAGE_FORWARD_SYSLOG_MISSED_STR \ SD_ID128_MAKE_STR(00,27,22,9c,a0,64,41,81,a7,6c,4e,92,45,8a,fa,2e)