From: Zbigniew Jędrzejewski-Szmek <zbyszek@in.waw.pl>
Date: Wed, 30 Jun 2021 15:02:45 +0000 (+0200)
Subject: core: emit nicer log message for exiting ConditionExec processes
X-Git-Tag: v249-rc3~16^2~2
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=58441bc177bb1bcdeceff74d3ae6b6d9f93a7fbe;p=thirdparty%2Fsystemd.git

core: emit nicer log message for exiting ConditionExec processes

See https://bugzilla.redhat.com/show_bug.cgi?id=1973058:

we would log something like:
systemd[244]: Starting willskip.service...
systemd[244]: willskip.service: Control process exited, code=exited, status=2/INVALIDARGUMENT
systemd[244]: willskip.service: Skipped due to 'exec-condition'.
systemd[244]: Condition check resulted in willskip.service being skipped.

The line with 'Control process exited' would be at LOG_NOTICE level.

With the patch:
systemd[244]: Starting willskip.service...
systemd[244]: willskip.service: Skipped due to 'exec-condition'.
systemd[244]: Condition check resulted in willskip.service being skipped.

Debug logs:
systemd[244]: Starting willskip.service...
systemd[244]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1/unit/willskip_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=8 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
systemd[244]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1/unit/willskip_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=9 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
systemd[244]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1/job/46 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=10 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
systemd[11020]: Skipping PR_SET_MM, as we don't have privileges.
systemd[11020]: willskip.service: Executing: sh -c 'exit 2'
systemd[244]: Received SIGCHLD from PID 11020 (sh).
systemd[244]: Child 11020 (sh) died (code=exited, status=2/INVALIDARGUMENT)
systemd[244]: willskip.service: Child 11020 belongs to willskip.service.
systemd[244]: willskip.service: Condition check process exited, code=exited, status=2/INVALIDARGUMENT (success)
systemd[244]: willskip.service: Got final SIGCHLD for state condition.
systemd[244]: willskip.service: Skipped due to 'exec-condition'.
systemd[244]: willskip.service: Service will not restart (restart setting)
systemd[244]: willskip.service: Changed condition -> dead
systemd[244]: willskip.service: Job 46 willskip.service/start finished, result=done
systemd[244]: Condition check resulted in willskip.service being skipped.
---

diff --git a/src/core/service.c b/src/core/service.c
index af5a2decf11..11b22c94467 100644
--- a/src/core/service.c
+++ b/src/core/service.c
@@ -3538,6 +3538,9 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) {
                 }
 
         } else if (s->control_pid == pid) {
+                const char *kind;
+                bool success;
+
                 s->control_pid = 0;
 
                 if (s->control_command) {
@@ -3552,15 +3555,24 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) {
                         if (f == SERVICE_FAILURE_EXIT_CODE && status < 255) {
                                 UNIT(s)->condition_result = false;
                                 f = SERVICE_SKIP_CONDITION;
-                        } else if (f == SERVICE_SUCCESS)
+                                success = true;
+                        } else if (f == SERVICE_SUCCESS) {
                                 UNIT(s)->condition_result = true;
+                                success = true;
+                        } else
+                                success = false;
+
+                        kind = "Condition check process";
+                } else {
+                        kind = "Control process";
+                        success = f == SERVICE_SUCCESS;
                 }
 
                 unit_log_process_exit(
                                 u,
-                                "Control process",
+                                kind,
                                 service_exec_command_to_string(s->control_command_id),
-                                f == SERVICE_SUCCESS,
+                                success,
                                 code, status);
 
                 if (s->state != SERVICE_RELOAD && s->result == SERVICE_SUCCESS)
diff --git a/src/core/unit.c b/src/core/unit.c
index 3792cee7112..be8e0ddef20 100644
--- a/src/core/unit.c
+++ b/src/core/unit.c
@@ -5576,12 +5576,13 @@ void unit_log_process_exit(
 
         log_unit_struct(u, level,
                         "MESSAGE_ID=" SD_MESSAGE_UNIT_PROCESS_EXIT_STR,
-                        LOG_UNIT_MESSAGE(u, "%s exited, code=%s, status=%i/%s",
+                        LOG_UNIT_MESSAGE(u, "%s exited, code=%s, status=%i/%s%s",
                                          kind,
                                          sigchld_code_to_string(code), status,
                                          strna(code == CLD_EXITED
                                                ? exit_status_to_string(status, EXIT_STATUS_FULL)
-                                               : signal_to_string(status))),
+                                               : signal_to_string(status)),
+                                         success ? " (success)" : ""),
                         "EXIT_CODE=%s", sigchld_code_to_string(code),
                         "EXIT_STATUS=%i", status,
                         "COMMAND=%s", strna(command),