log: fix order of log_unit_struct() to match other logging calls

Also, while we are at it, introduce some syntactic sugar for creating
ERRNO= and MESSAGE= structured logging fields.
This commit is contained in:
Lennart Poettering
2014-11-28 02:18:46 +01:00
parent 6c861f0aef
commit e2cc6eca73
17 changed files with 153 additions and 144 deletions
+28 -26
View File
@@ -426,12 +426,13 @@ static int setup_output(const ExecContext *context, int fileno, int socket_fd, c
case EXEC_OUTPUT_JOURNAL_AND_CONSOLE:
r = connect_logger_as(context, o, ident, unit_id, fileno);
if (r < 0) {
log_unit_struct(LOG_CRIT, unit_id,
"MESSAGE=Failed to connect std%s of %s to the journal socket: %s",
fileno == STDOUT_FILENO ? "out" : "err",
unit_id, strerror(-r),
"ERRNO=%d", -r,
NULL);
log_unit_struct(unit_id,
LOG_CRIT,
LOG_MESSAGE("Failed to connect %s of %s to the journal socket: %s",
fileno == STDOUT_FILENO ? "stdout" : "stderr",
unit_id, strerror(-r)),
LOG_ERRNO(-r),
NULL);
r = open_null_as(O_WRONLY, fileno);
}
return r;
@@ -1751,10 +1752,10 @@ static int exec_child(ExecCommand *command,
line = exec_command_line(final_argv);
if (line) {
log_open();
log_unit_struct(LOG_DEBUG,
params->unit_id,
log_unit_struct(params->unit_id,
LOG_DEBUG,
"EXECUTABLE=%s", command->path,
"MESSAGE=Executing: %s", line,
LOG_MESSAGE("Executing: %s", line),
NULL);
log_close();
}
@@ -1799,11 +1800,11 @@ int exec_spawn(ExecCommand *command,
err = exec_context_load_environment(context, params->unit_id, &files_env);
if (err < 0) {
log_unit_struct(LOG_ERR,
params->unit_id,
"MESSAGE=Failed to load environment files: %s", strerror(-err),
"ERRNO=%d", -err,
NULL);
log_unit_struct(params->unit_id,
LOG_ERR,
LOG_MESSAGE("Failed to load environment files: %s", strerror(-err)),
LOG_ERRNO(-err),
NULL);
return err;
}
@@ -1813,10 +1814,10 @@ int exec_spawn(ExecCommand *command,
if (!line)
return log_oom();
log_unit_struct(LOG_DEBUG,
params->unit_id,
log_unit_struct(params->unit_id,
LOG_DEBUG,
"EXECUTABLE=%s", command->path,
"MESSAGE=About to execute: %s", line,
LOG_MESSAGE("About to execute: %s", line),
NULL);
free(line);
@@ -1838,12 +1839,13 @@ int exec_spawn(ExecCommand *command,
&r);
if (r != 0) {
log_open();
log_struct(LOG_ERR, MESSAGE_ID(SD_MESSAGE_SPAWN_FAILED),
log_struct(LOG_ERR,
LOG_MESSAGE_ID(SD_MESSAGE_SPAWN_FAILED),
"EXECUTABLE=%s", command->path,
"MESSAGE=Failed at step %s spawning %s: %s",
exit_status_to_string(r, EXIT_STATUS_SYSTEMD),
command->path, strerror(-err),
"ERRNO=%d", -err,
LOG_MESSAGE("Failed at step %s spawning %s: %s",
exit_status_to_string(r, EXIT_STATUS_SYSTEMD),
command->path, strerror(-err)),
LOG_ERRNO(-err),
NULL);
log_close();
}
@@ -1851,10 +1853,10 @@ int exec_spawn(ExecCommand *command,
_exit(r);
}
log_unit_struct(LOG_DEBUG,
params->unit_id,
"MESSAGE=Forked %s as "PID_FMT,
command->path, pid,
log_unit_struct(params->unit_id,
LOG_DEBUG,
LOG_MESSAGE("Forked %s as "PID_FMT,
command->path, pid),
NULL);
/* We add the new process to the cgroup both in the child (so
+27 -27
View File
@@ -730,28 +730,28 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) {
sd_id128_t mid;
mid = result == JOB_DONE ? SD_MESSAGE_UNIT_STARTED : SD_MESSAGE_UNIT_FAILED;
log_unit_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
u->id,
MESSAGE_ID(mid),
"RESULT=%s", job_result_to_string(result),
"MESSAGE=%s", buf,
NULL);
log_unit_struct(u->id,
result == JOB_DONE ? LOG_INFO : LOG_ERR,
LOG_MESSAGE_ID(mid),
LOG_MESSAGE("%s", buf),
"RESULT=%s", job_result_to_string(result),
NULL);
} else if (t == JOB_STOP)
log_unit_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
u->id,
MESSAGE_ID(SD_MESSAGE_UNIT_STOPPED),
"RESULT=%s", job_result_to_string(result),
"MESSAGE=%s", buf,
NULL);
log_unit_struct(u->id,
result == JOB_DONE ? LOG_INFO : LOG_ERR,
LOG_MESSAGE_ID(SD_MESSAGE_UNIT_STOPPED),
LOG_MESSAGE("%s", buf),
"RESULT=%s", job_result_to_string(result),
NULL);
else if (t == JOB_RELOAD)
log_unit_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
u->id,
MESSAGE_ID(SD_MESSAGE_UNIT_RELOADED),
"RESULT=%s", job_result_to_string(result),
"MESSAGE=%s", buf,
NULL);
log_unit_struct(u->id,
result == JOB_DONE ? LOG_INFO : LOG_ERR,
LOG_MESSAGE_ID(SD_MESSAGE_UNIT_RELOADED),
LOG_MESSAGE("%s", buf),
"RESULT=%s", job_result_to_string(result),
NULL);
}
int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
@@ -837,15 +837,15 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
* this context. And JOB_FAILURE is already handled by the
* unit itself. */
if (result == JOB_TIMEOUT || result == JOB_DEPENDENCY) {
log_unit_struct(LOG_NOTICE,
u->id,
"JOB_TYPE=%s", job_type_to_string(t),
"JOB_RESULT=%s", job_result_to_string(result),
"Job %s/%s failed with result '%s'.",
u->id,
job_type_to_string(t),
job_result_to_string(result),
NULL);
log_unit_struct(u->id,
LOG_NOTICE,
"JOB_TYPE=%s", job_type_to_string(t),
"JOB_RESULT=%s", job_result_to_string(result),
LOG_MESSAGE("Job %s/%s failed with result '%s'.",
u->id,
job_type_to_string(t),
job_result_to_string(result)),
NULL);
unit_start_on_failure(u);
}
+16 -16
View File
@@ -1881,8 +1881,8 @@ static int manager_dispatch_time_change_fd(sd_event_source *source, int fd, uint
assert(m->time_change_fd == fd);
log_struct(LOG_INFO,
MESSAGE_ID(SD_MESSAGE_TIME_CHANGE),
"MESSAGE=Time has been changed",
LOG_MESSAGE_ID(SD_MESSAGE_TIME_CHANGE),
LOG_MESSAGE("Time has been changed"),
NULL);
/* Restart the watch */
@@ -2590,28 +2590,28 @@ static void manager_notify_finished(Manager *m) {
initrd_usec = m->userspace_timestamp.monotonic - m->initrd_timestamp.monotonic;
log_struct(LOG_INFO,
MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
"KERNEL_USEC="USEC_FMT, kernel_usec,
"INITRD_USEC="USEC_FMT, initrd_usec,
"USERSPACE_USEC="USEC_FMT, userspace_usec,
"MESSAGE=Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.",
format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC),
format_timespan(initrd, sizeof(initrd), initrd_usec, USEC_PER_MSEC),
format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC),
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC),
LOG_MESSAGE("Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.",
format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC),
format_timespan(initrd, sizeof(initrd), initrd_usec, USEC_PER_MSEC),
format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC),
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)),
NULL);
} else {
kernel_usec = m->userspace_timestamp.monotonic - m->kernel_timestamp.monotonic;
initrd_usec = 0;
log_struct(LOG_INFO,
MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
"KERNEL_USEC="USEC_FMT, kernel_usec,
"USERSPACE_USEC="USEC_FMT, userspace_usec,
"MESSAGE=Startup finished in %s (kernel) + %s (userspace) = %s.",
format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC),
format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC),
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC),
LOG_MESSAGE("Startup finished in %s (kernel) + %s (userspace) = %s.",
format_timespan(kernel, sizeof(kernel), kernel_usec, USEC_PER_MSEC),
format_timespan(userspace, sizeof(userspace), userspace_usec, USEC_PER_MSEC),
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)),
NULL);
}
} else {
@@ -2619,10 +2619,10 @@ static void manager_notify_finished(Manager *m) {
total_usec = userspace_usec = m->finish_timestamp.monotonic - m->userspace_timestamp.monotonic;
log_struct(LOG_INFO,
MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
LOG_MESSAGE_ID(SD_MESSAGE_STARTUP_FINISHED),
"USERSPACE_USEC="USEC_FMT, userspace_usec,
"MESSAGE=Startup finished in %s.",
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC),
LOG_MESSAGE("Startup finished in %s.",
format_timespan(sum, sizeof(sum), total_usec, USEC_PER_MSEC)),
NULL);
}
+10 -10
View File
@@ -823,12 +823,12 @@ void warn_if_dir_nonempty(const char *unit, const char* where) {
if (r > 0)
return;
else if (r == 0)
log_unit_struct(LOG_NOTICE,
unit,
"MESSAGE=%s: Directory %s to mount over is not empty, mounting anyway.",
unit, where,
log_unit_struct(unit,
LOG_NOTICE,
LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING),
LOG_MESSAGE("%s: Directory %s to mount over is not empty, mounting anyway.",
unit, where),
"WHERE=%s", where,
MESSAGE_ID(SD_MESSAGE_OVERMOUNTING),
NULL);
else
log_unit_warning(unit,
@@ -840,12 +840,12 @@ static int fail_if_symlink(const char *unit, const char* where) {
assert(where);
if (is_symlink(where) > 0) {
log_unit_struct(LOG_WARNING,
unit,
"MESSAGE=%s: Mount on symlink %s not allowed.",
unit, where,
log_unit_struct(unit,
LOG_ERR,
LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING),
LOG_MESSAGE("%s: Mount on symlink %s not allowed.",
unit, where),
"WHERE=%s", where,
MESSAGE_ID(SD_MESSAGE_OVERMOUNTING),
NULL);
return -ELOOP;
+10 -10
View File
@@ -2205,16 +2205,16 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) {
f = SERVICE_SUCCESS;
}
log_unit_struct(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
u->id,
"MESSAGE=%s: main process exited, code=%s, status=%i/%s",
u->id, 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,
NULL);
log_unit_struct(u->id,
f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
LOG_MESSAGE("%s: main process exited, code=%s, status=%i/%s",
u->id, 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,
NULL);
if (f != SERVICE_SUCCESS)
s->result = f;
+4 -4
View File
@@ -1394,10 +1394,10 @@ static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) {
t == JOB_STOP ? SD_MESSAGE_UNIT_STOPPING :
SD_MESSAGE_UNIT_RELOADING;
log_unit_struct(LOG_INFO,
u->id,
MESSAGE_ID(mid),
"MESSAGE=%s", buf,
log_unit_struct(u->id,
LOG_INFO,
LOG_MESSAGE_ID(mid),
LOG_MESSAGE("%s", buf),
NULL);
}
+1 -1
View File
@@ -605,4 +605,4 @@ UnitActiveState unit_active_state_from_string(const char *s) _pure_;
#define log_unit_warning(unit, ...) log_unit_full(unit, LOG_WARNING, __VA_ARGS__)
#define log_unit_error(unit, ...) log_unit_full(unit, LOG_ERR, __VA_ARGS__)
#define log_unit_struct(level, unit, ...) log_struct(level, getpid() == 1 ? "UNIT=%s" : "USER_UNIT=%s", unit, __VA_ARGS__)
#define log_unit_struct(unit, level, ...) log_struct(level, getpid() == 1 ? "UNIT=%s" : "USER_UNIT=%s", unit, __VA_ARGS__)