From dac669b390cfb1be265c71cb588fa0a67ecdd929 Mon Sep 17 00:00:00 2001
From: "Gao,Yan" <ygao@suse.com>
Date: Thu, 9 May 2019 13:24:35 +0200
Subject: [PATCH 5/5] Fix: controller: confirm cancel of failed monitors

Usually after a monitor has been cancelled from executor, contoller
erases the corresponding lrm_rsc_op from the cib, and DC will confirm
the cancel action by process_op_deletion() according to the cib diff.

But if a monitor has failed, the lrm_rsc_op will be recorded as
"last_failure". When cancelling it, the lrm_rsc_op won't get erased from
the cib given the logic on purpose in erase_lrm_history_by_op(). So that
the cancel action won't have a chance to get confirmed by DC with
process_op_deletion().

Previously cluster transition would get stuck waiting for the remaining
action timer to time out.

This commit fixes the issue by directly acknowledging the cancel action
in this case and enabling DC to be able to confirm it.

This also moves get_node_id() function into controld_utils.c for common
use.

Producer:
```
 # Insert a 10s sleep in the monitor action of RA
 # /usr/lib/ocf/resource.d/pacemaker/Stateful:

  stateful_monitor() {
 +    sleep 10
      stateful_check_state "master"

 # Add a promotable clone resource:

 crm configure primitive stateful ocf:pacemaker:Stateful \
         op monitor interval=5 role=Master \
         op monitor interval=10 role=Slave
 crm configure clone p-clone stateful \
         meta promotable=true

 # Wait for the resource instance to be started, promoted to be master,
 # and monitor for master role to complete.

 # Set is-managed=false for the promotable clone:
 crm_resource --meta -p is-managed -v false -r p-clone

 # Change the status of the master instance to be slave and immediately
 # enforce refresh of it:
 echo slave > /var/run/Stateful-stateful.state; crm_resource --refresh -r stateful --force

 # Wait for probe to complete, and then monitor for slave role to be
 # issued:
 sleep 15

 # While the monitor for slave role is still in progress, change the
 # status to be master again:
 echo master > /var/run/Stateful-stateful.state

 # The monitor for slave role returns error. Cluster issues monitor for
 # master role instead and tries to cancel the failed one for slave role.
 # But cluster transition gets stuck. Depending on the monitor timeout
 # configured for the slave role plus cluster-delay, only after that
 # controller eventually says:

 pacemaker-controld[21205] error: Node opensuse150 did not send cancel result (via controller) within 20000ms (action timeout plus cluster-delay)
 pacemaker-controld[21205] error: [Action    1]: In-flight rsc op stateful_monitor_10000            on opensuse150 (priority: 0, waiting: none)
 pacemaker-controld[21205] notice: Transition 6 aborted: Action lost

```
---
 crmd/crmd_utils.h   |  2 ++
 crmd/lrm.c          | 38 ++++++++++++++++++++++++++++++++++++++
 crmd/te_callbacks.c | 21 ++-------------------
 crmd/te_events.c    | 32 ++++++++++++++++++++++++++++++++
 crmd/tengine.h      |  1 +
 crmd/utils.c        | 13 +++++++++++++
 6 files changed, 88 insertions(+), 19 deletions(-)

Index: pacemaker/crmd/crmd_utils.h
===================================================================
--- pacemaker.orig/crmd/crmd_utils.h
+++ pacemaker/crmd/crmd_utils.h
@@ -104,6 +104,8 @@ void abort_for_stonith_failure(enum tran
 void crmd_peer_down(crm_node_t *peer, bool full);
 unsigned int cib_op_timeout(unsigned int max);
 
+const char *get_node_id(xmlNode *lrm_rsc_op);
+
 /* Convenience macro for registering a CIB callback
  * (assumes that data can be freed with free())
  */
Index: pacemaker/crmd/lrm.c
===================================================================
--- pacemaker.orig/crmd/lrm.c
+++ pacemaker/crmd/lrm.c
@@ -2448,6 +2448,30 @@ do_lrm_event(long long action,
     CRM_CHECK(FALSE, return);
 }
 
+static bool
+did_lrm_rsc_op_fail(lrm_state_t *lrm_state, const char * rsc_id,
+                    const char * op_type, guint interval_ms)
+{
+    rsc_history_t *entry = NULL;
+
+    CRM_CHECK(lrm_state != NULL, return FALSE);
+    CRM_CHECK(rsc_id != NULL, return FALSE);
+    CRM_CHECK(op_type != NULL, return FALSE);
+
+    entry = g_hash_table_lookup(lrm_state->resource_history, rsc_id);
+    if (entry == NULL || entry->failed == NULL) {
+        return FALSE;
+    }
+
+    if (crm_str_eq(entry->failed->rsc_id, rsc_id, TRUE)
+        && safe_str_eq(entry->failed->op_type, op_type)
+        && entry->failed->interval == interval_ms) {
+        return TRUE;
+    }
+
+    return FALSE;
+}
+
 gboolean
 process_lrm_event(lrm_state_t * lrm_state, lrmd_event_data_t * op, struct recurring_op_s *pending)
 {
@@ -2511,6 +2535,20 @@ process_lrm_event(lrm_state_t * lrm_stat
         /* The tengine canceled this op, we have been waiting for the cancel to finish. */
         delete_op_entry(lrm_state, op, op->rsc_id, op_key, op->call_id);
 
+        /* If the recurring operation had failed, the lrm_rsc_op is recorded as
+         * "last_failure" which won't get erased from the cib given the logic on
+         * purpose in erase_lrm_history_by_op(). So that the cancel action won't
+         * have a chance to get confirmed by DC with process_op_deletion().
+         * Cluster transition would get stuck waiting for the remaining action
+         * timer to time out.
+         *
+         * Directly acknowledge the cancel operation in this case.
+         */
+        if (did_lrm_rsc_op_fail(lrm_state, pending->rsc_id,
+                                pending->op_type, pending->interval)) {
+            send_direct_ack(NULL, NULL, NULL, op, op->rsc_id);
+        }
+
     } else if (pending && op->rsc_deleted) {
         /* The tengine initiated this op, but it was cancelled outside of the
          * tengine's control during a resource cleanup/re-probe request. The tengine
Index: pacemaker/crmd/te_callbacks.c
===================================================================
--- pacemaker.orig/crmd/te_callbacks.c
+++ pacemaker/crmd/te_callbacks.c
@@ -40,19 +40,6 @@ crm_trigger_t *transition_trigger = NULL
 /* #define rsc_op_template "//"XML_TAG_DIFF_ADDED"//"XML_TAG_CIB"//"XML_CIB_TAG_STATE"[@uname='%s']"//"XML_LRM_TAG_RSC_OP"[@id='%s]" */
 #define rsc_op_template "//"XML_TAG_DIFF_ADDED"//"XML_TAG_CIB"//"XML_LRM_TAG_RSC_OP"[@id='%s']"
 
-static const char *
-get_node_id(xmlNode * rsc_op)
-{
-    xmlNode *node = rsc_op;
-
-    while (node != NULL && safe_str_neq(XML_CIB_TAG_STATE, TYPE(node))) {
-        node = node->parent;
-    }
-
-    CRM_CHECK(node != NULL, return NULL);
-    return ID(node);
-}
-
 static void
 te_legacy_update_diff(const char *event, xmlNode * diff)
 {
@@ -478,13 +465,7 @@ te_update_diff(const char *event, xmlNod
                 abort_transition(INFINITY, tg_restart, "Resource operation removal", change);
 
             } else {
-                crm_info("Cancellation of %s on %s confirmed (%d)", key, node_uuid, cancel->id);
-                stop_te_timer(cancel->timer);
-                te_action_confirmed(cancel);
-
-                update_graph(transition_graph, cancel);
-                trigger_graph();
-
+                confirm_cancel_action(cancel);
             }
             free(mutable_key);
             free(node_uuid);
Index: pacemaker/crmd/te_events.c
===================================================================
--- pacemaker.orig/crmd/te_events.c
+++ pacemaker/crmd/te_events.c
@@ -373,6 +373,27 @@ get_cancel_action(const char *id, const
     return NULL;
 }
 
+void
+confirm_cancel_action(crm_action_t *cancel)
+{
+    const char *op_key = NULL;
+    const char *node_name = NULL;
+
+    CRM_ASSERT(cancel != NULL);
+
+    op_key = crm_element_value(cancel->xml, XML_LRM_ATTR_TASK_KEY);
+    node_name = crm_element_value(cancel->xml, XML_LRM_ATTR_TARGET);
+
+    stop_te_timer(cancel->timer);
+    te_action_confirmed(cancel);
+    update_graph(transition_graph, cancel);
+
+    crm_info("Cancellation of %s on %s confirmed (action %d)",
+             op_key, node_name, cancel->id);
+
+    trigger_graph();
+}
+
 /* downed nodes are listed like: <downed> <node id="UUID1" /> ... </downed> */
 #define XPATH_DOWNED "//" XML_GRAPH_TAG_DOWNED \
                      "/" XML_CIB_TAG_NODE "[@" XML_ATTR_UUID "='%s']"
@@ -494,6 +515,17 @@ process_graph_event(xmlNode *event, cons
             /* Recurring actions have the transition number they were first
              * scheduled in.
              */
+
+            if (status == PCMK_LRM_OP_CANCELLED) {
+                const char *node_id = get_node_id(event);
+
+                action = get_cancel_action(id, node_id);
+                if (action) {
+                    confirm_cancel_action(action);
+                }
+                goto bail;
+            }
+
             desc = "arrived after initial scheduling";
             abort_transition(INFINITY, tg_restart, "Change in recurring result",
                              event);
Index: pacemaker/crmd/tengine.h
===================================================================
--- pacemaker.orig/crmd/tengine.h
+++ pacemaker/crmd/tengine.h
@@ -35,6 +35,7 @@ void execute_stonith_cleanup(void);
 /* tengine */
 extern crm_action_t *match_down_event(const char *target, bool quiet);
 extern crm_action_t *get_cancel_action(const char *id, const char *node);
+void confirm_cancel_action(crm_action_t *cancel);
 
 extern gboolean cib_action_update(crm_action_t * action, int status, int op_rc);
 extern gboolean fail_incompletable_actions(crm_graph_t * graph, const char *down_node);
Index: pacemaker/crmd/utils.c
===================================================================
--- pacemaker.orig/crmd/utils.c
+++ pacemaker/crmd/utils.c
@@ -1170,3 +1170,15 @@ cib_op_timeout(unsigned int max)
     return QB_MAX(max, global_max);
 }
 
+const char *
+get_node_id(xmlNode *lrm_rsc_op)
+{
+    xmlNode *node = lrm_rsc_op;
+
+    while (node != NULL && safe_str_neq(XML_CIB_TAG_STATE, TYPE(node))) {
+        node = node->parent;
+    }
+
+    CRM_CHECK(node != NULL, return NULL);
+    return ID(node);
+}
