Merge pull request #10770 from poettering/unit-done-log

improvements to structure log events from PID1
This commit is contained in:
Lennart Poettering 2018-11-16 17:54:19 +01:00 committed by GitHub
commit ae3cc6ec0d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
14 changed files with 338 additions and 198 deletions

View File

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

View File

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

View File

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

View File

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

View File

@ -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. */

View File

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

View File

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

View File

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

View File

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

View File

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

View File

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

View File

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

View File

@ -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, ...) \

View File

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