From: Zbigniew Jędrzejewski-Szmek Date: Wed, 10 Oct 2012 22:11:24 +0000 (+0000) Subject: systemd: use structured logging for unit changes X-Git-Tag: v195~63 X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=commitdiff_plain;h=23635a8547eac0c05922609f5930badc86faf080 systemd: use structured logging for unit changes Information which unit a log entry pertains to enables systemctl status to display more log messages. --- diff --git a/src/core/execute.c b/src/core/execute.c index 5faeee869..e502c2490 100644 --- a/src/core/execute.c +++ b/src/core/execute.c @@ -62,6 +62,8 @@ #include "loopback-setup.h" #include "path-util.h" #include "syscall-list.h" +#include "sd-id128.h" +#include "sd-messages.h" #define IDLE_TIMEOUT_USEC (5*USEC_PER_SEC) @@ -1022,7 +1024,11 @@ int exec_spawn(ExecCommand *command, r = exec_context_load_environment(context, &files_env); if (r < 0) { - log_error("Failed to load environment files: %s", strerror(-r)); + log_struct(LOG_ERR, + "UNIT=%s", unit_id, + "MESSAGE=Failed to load environment files: %s", strerror(-r), + "ERRNO=%d", -r, + NULL); return r; } @@ -1033,7 +1039,10 @@ int exec_spawn(ExecCommand *command, if (!line) return log_oom(); - log_debug("About to execute: %s", line); + log_struct(LOG_DEBUG, + "UNIT=%s", unit_id, + "MESSAGE=About to execute %s", line, + NULL); free(line); r = cgroup_bonding_realize_list(cgroup_bondings); @@ -1490,14 +1499,25 @@ int exec_spawn(ExecCommand *command, fail_child: if (r != 0) { log_open(); - log_warning("Failed at step %s spawning %s: %s", - exit_status_to_string(r, EXIT_STATUS_SYSTEMD), - command->path, strerror(-err)); + log_struct(LOG_ERR, 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, + NULL); + log_close(); } _exit(r); } + log_struct(LOG_DEBUG, + "UNIT=%s", unit_id, + "MESSAGE=Forked %s as %lu", + command->path, (unsigned long) pid, + NULL); + /* We add the new process to the cgroup both in the child (so * that we can be sure that no user code is ever executed * outside of the cgroup) and in the parent (so that we can be @@ -1506,8 +1526,6 @@ int exec_spawn(ExecCommand *command, if (cgroup_bondings) cgroup_bonding_install_list(cgroup_bondings, pid, cgroup_suffix); - log_debug("Forked %s as %lu", command->path, (unsigned long) pid); - exec_status_start(&command->exec_status, pid); *ret = pid; diff --git a/src/core/selinux-access.c b/src/core/selinux-access.c index 852a328b7..6dfe8b45f 100644 --- a/src/core/selinux-access.c +++ b/src/core/selinux-access.c @@ -314,7 +314,7 @@ static int get_calling_context( if (r >= 0) return r; - log_error("bus_get_selinux_security_context failed %m"); + log_error("bus_get_selinux_security_context failed: %m"); return r; } diff --git a/src/core/service.c b/src/core/service.c index 5742968d9..2febdb69d 100644 --- a/src/core/service.c +++ b/src/core/service.c @@ -1614,7 +1614,12 @@ static void service_set_state(Service *s, ServiceState state) { cgroup_bonding_trim_list(UNIT(s)->cgroup_bondings, true); if (old_state != state) - log_debug("%s changed %s -> %s", UNIT(s)->id, service_state_to_string(old_state), service_state_to_string(state)); + log_struct(LOG_DEBUG, + "UNIT=%s", UNIT(s)->id, + "MESSAGE=%s changed %s -> %s", UNIT(s)->id, + service_state_to_string(old_state), + service_state_to_string(state), + NULL); unit_notify(UNIT(s), table[old_state], table[state], s->reload_result == SERVICE_SUCCESS); s->reload_result = SERVICE_SUCCESS; @@ -2948,8 +2953,16 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SERVICE_SUCCESS; } - log_full(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s: main process exited, code=%s, status=%i", u->id, sigchld_code_to_string(code), status); + log_struct(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + "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)), + "UNIT=%s", u->id, + "EXIT_CODE=%s", sigchld_code_to_string(code), + "EXIT_STATUS=%i", status, + NULL); if (f != SERVICE_SUCCESS) s->result = f; diff --git a/src/core/unit.c b/src/core/unit.c index 6396bfc09..99e1c2794 100644 --- a/src/core/unit.c +++ b/src/core/unit.c @@ -1438,7 +1438,10 @@ void unit_notify(Unit *u, UnitActiveState os, UnitActiveState ns, bool reload_su check_unneeded_dependencies(u); if (ns != os && ns == UNIT_FAILED) { - log_notice("Unit %s entered failed state.", u->id); + log_struct(LOG_NOTICE, + "MESSAGE=Unit %s entered failed state", u->id, + "UNIT=%s", u->id, + NULL); unit_trigger_on_failure(u); } } diff --git a/src/systemd/sd-messages.h b/src/systemd/sd-messages.h index 698aa60eb..5099a36e6 100644 --- a/src/systemd/sd-messages.h +++ b/src/systemd/sd-messages.h @@ -58,6 +58,8 @@ extern "C" { #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_RELOADED SD_ID128_MAKE(7b,05,eb,c6,68,38,42,22,ba,a8,88,11,79,cf,da,54) +#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_FORWARD_SYSLOG_MISSED SD_ID128_MAKE(00,27,22,9c,a0,64,41,81,a7,6c,4e,92,45,8a,fa,2e) #ifdef __cplusplus