systemd: use structured logging for unit changes

Information which unit a log entry pertains to enables systemctl
status to display more log messages.

4 files changed, 46 insertions, 12 deletions

diff --git a/src/core/execute.c b/src/core/execute.c
index 5faeee8691..e502c2490f 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 852a328b7c..6dfe8b45f3 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 5742968d91..2febdb69d1 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 6396bfc09f..99e1c27948 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);
                 }
         }