From dfa19402ce9ad40d6b6674eb1d7c351d6876b557 Mon Sep 17 00:00:00 2001
From: "Gao,Yan" <ygao@suse.com>
Date: Mon, 14 Oct 2019 14:25:55 +0200
Subject: [PATCH 5/5] Log: fencer: improved log messages regarding fencing
 actions

* Quote fencing actions
* Fencing actions "targeting ..." instead of "for node ..."
---
 cts/cts-fencing.in               | 20 ++++++++---------
 daemons/fenced/fenced_commands.c | 46 ++++++++++++++++++++--------------------
 lib/fencing/st_client.c          |  2 +-
 3 files changed, 34 insertions(+), 34 deletions(-)

Index: pacemaker-2.0.1+20190417.13d370ca9/cts/cts-fencing.in
===================================================================
--- pacemaker-2.0.1+20190417.13d370ca9.orig/cts/cts-fencing.in
+++ pacemaker-2.0.1+20190417.13d370ca9/cts/cts-fencing.in
@@ -594,7 +594,7 @@ class Tests(object):
         test.add_cmd_no_wait("stonith_admin", "-F node3 -t 10")
         test.add_cmd("stonith_admin", "-F node3 -t 10")
         ### one merger will happen
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
         ### the pattern below signifies that both the original and duplicate operation completed
         test.add_stonith_log_pattern("Operation off of node3 by")
         test.add_stonith_log_pattern("Operation off of node3 by")
@@ -612,10 +612,10 @@ class Tests(object):
         test.add_cmd_no_wait("stonith_admin", "-F node3 -t 10")
         test.add_cmd("stonith_admin", "-F node3 -t 10")
         ### 4 mergers should occur
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
         ### the pattern below signifies that both the original and duplicate operation completed
         test.add_stonith_log_pattern("Operation off of node3 by")
         test.add_stonith_log_pattern("Operation off of node3 by")
@@ -639,10 +639,10 @@ class Tests(object):
         test.add_cmd_no_wait("stonith_admin", "-F node3 -t 10")
         test.add_cmd("stonith_admin", "-F node3 -t 10")
         ### 4 mergers should occur
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
-        test.add_stonith_log_pattern("Merging stonith action off for node node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
+        test.add_stonith_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
         ### the pattern below signifies that both the original and duplicate operation completed
         test.add_stonith_log_pattern("Operation off of node3 by")
         test.add_stonith_log_pattern("Operation off of node3 by")
@@ -663,7 +663,7 @@ class Tests(object):
         test.add_cmd("stonith_admin", "-r node3 -i 2 -v true1")
         test.add_cmd_no_wait("stonith_admin", "-F node2 -t 10")
         test.add_cmd("stonith_admin", "-F node3 -t 10")
-        test.add_stonith_neg_log_pattern("Merging stonith action off for node node3 originating from client")
+        test.add_stonith_neg_log_pattern("Merging stonith action 'off' targeting node3 originating from client")
 
     def build_standalone_tests(self):
         """ Register a grab bag of tests that can be executed in standalone or corosync mode """
Index: pacemaker-2.0.1+20190417.13d370ca9/daemons/fenced/fenced_commands.c
===================================================================
--- pacemaker-2.0.1+20190417.13d370ca9.orig/daemons/fenced/fenced_commands.c
+++ pacemaker-2.0.1+20190417.13d370ca9/daemons/fenced/fenced_commands.c
@@ -330,7 +330,7 @@ stonith_device_execute(stonith_device_t
 
         if (pending_op && pending_op->delay_id) {
             crm_trace
-                ("Operation %s%s%s on %s was asked to run too early, waiting for start_delay timeout of %dms",
+                ("Operation '%s'%s%s on %s was asked to run too early, waiting for start_delay timeout of %dms",
                  pending_op->action, pending_op->victim ? " targeting " : "",
                  pending_op->victim ? pending_op->victim : "",
                  device->id, pending_op->start_delay);
@@ -398,14 +398,14 @@ stonith_device_execute(stonith_device_t
     exec_rc = stonith_action_execute_async(action, (void *)cmd, cmd->done_cb);
 
     if (exec_rc > 0) {
-        crm_debug("Operation %s%s%s on %s now running with pid=%d, timeout=%ds",
-                  cmd->action, cmd->victim ? " for node " : "", cmd->victim ? cmd->victim : "",
+        crm_debug("Operation '%s'%s%s on %s now running with pid=%d, timeout=%ds",
+                  cmd->action, cmd->victim ? " targeting " : "", cmd->victim ? cmd->victim : "",
                   device->id, exec_rc, cmd->timeout);
         cmd->active_on = device;
 
     } else {
-        crm_warn("Operation %s%s%s on %s failed: %s (%d)",
-                 cmd->action, cmd->victim ? " for node " : "", cmd->victim ? cmd->victim : "",
+        crm_warn("Operation '%s'%s%s on %s failed: %s (%d)",
+                 cmd->action, cmd->victim ? " targeting " : "", cmd->victim ? cmd->victim : "",
                  device->id, pcmk_strerror(exec_rc), exec_rc);
         cmd->done_cb(0, exec_rc, NULL, cmd);
     }
@@ -465,12 +465,12 @@ schedule_stonith_command(async_command_t
     cmd->timeout = get_action_timeout(device, cmd->action, cmd->default_timeout);
 
     if (cmd->remote_op_id) {
-        crm_debug("Scheduling %s%s%s on %s for remote peer %s with op id (%s) (timeout=%ds)",
+        crm_debug("Scheduling '%s' action%s%s on %s for remote peer %s with op id (%s) (timeout=%ds)",
                   cmd->action,
                   cmd->victim ? " targeting " : "", cmd->victim ? cmd->victim : "",
                   device->id, cmd->origin, cmd->remote_op_id, cmd->timeout);
     } else {
-        crm_debug("Scheduling %s%s%s on %s for %s (timeout=%ds)",
+        crm_debug("Scheduling '%s' action%s%s on %s for %s (timeout=%ds)",
                   cmd->action,
                   cmd->victim ? " targeting " : "", cmd->victim ? cmd->victim : "",
                   device->id, cmd->client, cmd->timeout);
@@ -495,7 +495,7 @@ schedule_stonith_command(async_command_t
         cmd->start_delay =
             ((delay_max != delay_base)?(rand() % (delay_max - delay_base)):0)
             + delay_base;
-        crm_notice("Delaying %s%s%s on %s for %dms (timeout=%ds, base=%dms, "
+        crm_notice("Delaying '%s' action%s%s on %s for %dms (timeout=%ds, base=%dms, "
                    "max=%dms)",
                     cmd->action,
                     cmd->victim ? " targeting " : "", cmd->victim ? cmd->victim : "",
@@ -518,7 +518,7 @@ free_device(gpointer data)
     for (gIter = device->pending_ops; gIter != NULL; gIter = gIter->next) {
         async_command_t *cmd = gIter->data;
 
-        crm_warn("Removal of device '%s' purged operation %s", device->id, cmd->action);
+        crm_warn("Removal of device '%s' purged operation '%s'", device->id, cmd->action);
         cmd->done_cb(0, -ENODEV, NULL, cmd);
     }
     g_list_free(device->pending_ops);
@@ -1612,13 +1612,13 @@ localhost_is_eligible(const stonith_devi
     if (device && action && device->on_target_actions
         && strstr(device->on_target_actions, action)) {
         if (!localhost_is_target) {
-            crm_trace("%s operation with %s can only be executed for localhost not %s",
+            crm_trace("'%s' operation with %s can only be executed for localhost not %s",
                       action, device->id, target);
             return FALSE;
         }
 
     } else if (localhost_is_target && !allow_suicide) {
-        crm_trace("%s operation does not support self-fencing", action);
+        crm_trace("'%s' operation does not support self-fencing", action);
         return FALSE;
     }
     return TRUE;
@@ -1826,20 +1826,20 @@ add_action_specific_attributes(xmlNode *
     CRM_CHECK(xml && action && device, return);
 
     if (is_action_required(action, device)) {
-        crm_trace("Action %s is required on %s", action, device->id);
+        crm_trace("Action '%s' is required on %s", action, device->id);
         crm_xml_add_int(xml, F_STONITH_DEVICE_REQUIRED, 1);
     }
 
     action_specific_timeout = get_action_timeout(device, action, 0);
     if (action_specific_timeout) {
-        crm_trace("Action %s has timeout %dms on %s",
+        crm_trace("Action '%s' has timeout %dms on %s",
                   action, action_specific_timeout, device->id);
         crm_xml_add_int(xml, F_STONITH_ACTION_TIMEOUT, action_specific_timeout);
     }
 
     delay_max = get_action_delay_max(device, action);
     if (delay_max > 0) {
-        crm_trace("Action %s has maximum random delay %dms on %s",
+        crm_trace("Action '%s' has maximum random delay %dms on %s",
                   action, delay_max, device->id);
         crm_xml_add_int(xml, F_STONITH_DELAY_MAX, delay_max / 1000);
     }
@@ -1850,13 +1850,13 @@ add_action_specific_attributes(xmlNode *
     }
 
     if ((delay_max > 0) && (delay_base == 0)) {
-        crm_trace("Action %s has maximum random delay %dms on %s",
+        crm_trace("Action '%s' has maximum random delay %dms on %s",
                   action, delay_max, device->id);
     } else if ((delay_max == 0) && (delay_base > 0)) {
-        crm_trace("Action %s has a static delay of %dms on %s",
+        crm_trace("Action '%s' has a static delay of %dms on %s",
                   action, delay_base, device->id);
     } else if ((delay_max > 0) && (delay_base > 0)) {
-        crm_trace("Action %s has a minimum delay of %dms and a randomly chosen "
+        crm_trace("Action '%s' has a minimum delay of %dms and a randomly chosen "
                   "maximum delay of %dms on %s",
                   action, delay_base, delay_max, device->id);
     }
@@ -1877,7 +1877,7 @@ add_disallowed(xmlNode *xml, const char
                const char *target, gboolean allow_suicide)
 {
     if (!localhost_is_eligible(device, action, target, allow_suicide)) {
-        crm_trace("Action %s on %s is disallowed for local host",
+        crm_trace("Action '%s' on %s is disallowed for local host",
                   action, device->id);
         crm_xml_add(xml, F_STONITH_ACTION_DISALLOWED, XML_BOOLEAN_TRUE);
     }
@@ -2077,10 +2077,10 @@ stonith_send_async_reply(async_command_t
 
     } else if (crm_str_eq(cmd->action, "monitor", TRUE) ||
                crm_str_eq(cmd->action, "list", TRUE) || crm_str_eq(cmd->action, "status", TRUE)) {
-        crm_trace("Never broadcast %s replies", cmd->action);
+        crm_trace("Never broadcast '%s' replies", cmd->action);
 
     } else if (!stand_alone && safe_str_eq(cmd->origin, cmd->victim) && safe_str_neq(cmd->action, "on")) {
-        crm_trace("Broadcast %s reply for %s", cmd->action, cmd->victim);
+        crm_trace("Broadcast '%s' reply for %s", cmd->action, cmd->victim);
         crm_xml_add(reply, F_SUBTYPE, "broadcast");
         bcast = TRUE;
     }
@@ -2135,7 +2135,7 @@ cancel_stonith_command(async_command_t *
     device = g_hash_table_lookup(device_list, cmd->device);
 
     if (device) {
-        crm_trace("Cancel scheduled %s on %s", cmd->action, device->id);
+        crm_trace("Cancel scheduled '%s' action on %s", cmd->action, device->id);
         device->pending_ops = g_list_remove(device->pending_ops, cmd);
     }
 }
@@ -2242,7 +2242,7 @@ st_child_done(GPid pid, int rc, const ch
          * separately with similar requests.
          */
         crm_notice
-            ("Merging stonith action %s for node %s originating from client %s with identical stonith request from client %s",
+            ("Merging stonith action '%s' targeting %s originating from client %s with identical stonith request from client %s",
              cmd_other->action, cmd_other->victim, cmd_other->client_name, cmd->client_name);
 
         cmd_list = g_list_remove_link(cmd_list, gIter);
Index: pacemaker-2.0.1+20190417.13d370ca9/lib/fencing/st_client.c
===================================================================
--- pacemaker-2.0.1+20190417.13d370ca9.orig/lib/fencing/st_client.c
+++ pacemaker-2.0.1+20190417.13d370ca9/lib/fencing/st_client.c
@@ -534,7 +534,7 @@ make_args(const char *agent, const char
 
         /* Don't overwrite explictly set values for $param */
         if (value == NULL || safe_str_eq(value, "dynamic")) {
-            crm_debug("Performing %s action for node '%s' as '%s=%s'", action, victim, param,
+            crm_debug("Performing '%s' action targeting '%s' as '%s=%s'", action, victim, param,
                       alias);
             append_arg(param, alias, &arg_list);
         }
Index: pacemaker-2.0.1+20190417.13d370ca9/daemons/fenced/fenced_remote.c
===================================================================
--- pacemaker-2.0.1+20190417.13d370ca9.orig/daemons/fenced/fenced_remote.c
+++ pacemaker-2.0.1+20190417.13d370ca9/daemons/fenced/fenced_remote.c
@@ -890,7 +890,7 @@ merge_duplicates(remote_fencing_op_t * o
                 TIMEOUT_MULTIPLY_FACTOR * get_op_total_timeout(op, NULL);
         }
         crm_notice
-            ("Merging stonith action %s for node %s originating from client %s.%.8s with identical request from %s@%s.%.8s (%ds)",
+            ("Merging stonith action '%s' targeting %s originating from client %s.%.8s with identical request from %s@%s.%.8s (%ds)",
              op->action, op->target, op->client_name, op->id, other->client_name, other->originator,
              other->id, other->total_timeout);
         report_timeout_period(op, other->total_timeout);
