From: Zbigniew Jędrzejewski-Szmek <zbyszek@in.waw.pl>
Date: Thu, 13 Jun 2019 16:11:56 +0000 (+0200)
Subject: logind: log operation details when starting actions
X-Git-Tag: v243-rc1~240^2~2
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=b81b40d4c42ea0c65f71dbd2ccad8bdc4b464c78;p=thirdparty%2Fsystemd.git

logind: log operation details when starting actions

For some reason, systemd-logind is trying to handle idle action in one of my containers:

Jun 07 10:28:08 rawhide systemd-logind[42]: System idle. Taking action.
Jun 07 10:28:08 rawhide systemd-logind[42]: Requested operation not supported, ignoring.

But we didn't log what exactly was being done. Let's put the name of the action in messages.
---

diff --git a/src/login/logind-action.c b/src/login/logind-action.c
index f6de918c4d2..fa92f4870a2 100644
--- a/src/login/logind-action.c
+++ b/src/login/logind-action.c
@@ -78,7 +78,9 @@ int manager_handle_action(
         /* If the key handling is inhibited, don't do anything */
         if (inhibit_key > 0) {
                 if (manager_is_inhibited(m, inhibit_key, INHIBIT_BLOCK, NULL, true, false, 0, NULL)) {
-                        log_debug("Refusing operation, %s is inhibited.", inhibit_what_to_string(inhibit_key));
+                        log_debug("Refusing %s operation, %s is inhibited.",
+                                  handle_action_to_string(handle),
+                                  inhibit_what_to_string(inhibit_key));
                         return 0;
                 }
         }
@@ -109,20 +111,21 @@ int manager_handle_action(
         if (!supported && IN_SET(handle, HANDLE_HIBERNATE, HANDLE_HYBRID_SLEEP, HANDLE_SUSPEND_THEN_HIBERNATE)) {
                 supported = can_sleep("suspend") > 0;
                 if (supported) {
-                        log_notice("Operation '%s' requested but not supported, using regular suspend instead.", handle_action_to_string(handle));
+                        log_notice("Requested %s operation is not supported, using regular suspend instead.",
+                                   handle_action_to_string(handle));
                         handle = HANDLE_SUSPEND;
                 }
         }
 
-        if (!supported) {
-                log_warning("Requested operation not supported, ignoring.");
-                return -EOPNOTSUPP;
-        }
+        if (!supported)
+                return log_warning_errno(SYNTHETIC_ERRNO(EOPNOTSUPP),
+                                         "Requested %s operation not supported, ignoring.", handle_action_to_string(handle));
 
-        if (m->action_what > 0) {
-                log_debug("Action already in progress, ignoring.");
-                return -EALREADY;
-        }
+        if (m->action_what > 0)
+                return log_debug_errno(SYNTHETIC_ERRNO(EALREADY),
+                                       "Action already in progress (%s), ignoring requested %s operation.",
+                                       inhibit_what_to_string(m->action_what),
+                                       handle_action_to_string(handle));
 
         assert_se(target = manager_target_for_action(handle));
 
@@ -139,27 +142,23 @@ int manager_handle_action(
                 u = uid_to_name(offending->uid);
 
                 /* If this is just a recheck of the lid switch then don't warn about anything */
-                if (!is_edge) {
-                        log_debug("Refusing operation, %s is inhibited by UID "UID_FMT"/%s, PID "PID_FMT"/%s.",
-                                  inhibit_what_to_string(inhibit_operation),
-                                  offending->uid, strna(u),
-                                  offending->pid, strna(comm));
-                        return 0;
-                }
-
-                log_error("Refusing operation, %s is inhibited by UID "UID_FMT"/%s, PID "PID_FMT"/%s.",
-                          inhibit_what_to_string(inhibit_operation),
-                          offending->uid, strna(u),
-                          offending->pid, strna(comm));
-
-                return -EPERM;
+                log_full(is_edge ? LOG_ERR : LOG_DEBUG,
+                         "Refusing %s operation, %s is inhibited by UID "UID_FMT"/%s, PID "PID_FMT"/%s.",
+                         handle_action_to_string(handle),
+                         inhibit_what_to_string(inhibit_operation),
+                         offending->uid, strna(u),
+                         offending->pid, strna(comm));
+
+                return is_edge ? -EPERM : 0;
         }
 
         log_info("%s", message_table[handle]);
 
         r = bus_manager_shutdown_or_sleep_now_or_later(m, target, inhibit_operation, &error);
         if (r < 0)
-                return log_error_errno(r, "Failed to execute operation: %s", bus_error_message(&error, r));
+                return log_error_errno(r, "Failed to execute %s operation: %s",
+                                       handle_action_to_string(handle),
+                                       bus_error_message(&error, r));
 
         return 1;
 }
diff --git a/src/login/logind.c b/src/login/logind.c
index d60223db686..f4bc1d2eb73 100644
--- a/src/login/logind.c
+++ b/src/login/logind.c
@@ -1021,7 +1021,7 @@ static int manager_dispatch_idle_action(sd_event_source *s, uint64_t t, void *us
 
                 if (n >= since.monotonic + m->idle_action_usec &&
                     (m->idle_action_not_before_usec <= 0 || n >= m->idle_action_not_before_usec + m->idle_action_usec)) {
-                        log_info("System idle. Taking action.");
+                        log_info("System idle. Doing %s operation.", handle_action_to_string(m->idle_action));
 
                         manager_handle_action(m, 0, m->idle_action, false, false);
                         m->idle_action_not_before_usec = n;