[Pacemaker] Unusual crmd log

[Andrew Beekhof]

> On 29 Oct 2014, at 8:02 pm, Arjun Pandey <apandepublic at gmail.com> wrote:
> 
> Hi
> 
> I have a 2 node active-standby cluster setup.
> 
> Pacemaker packages that i have on CentOS 6.5
> 
> pacemaker-1.1.10-14.el6_5.3.x86_64
> pacemaker-libs-1.1.10-14.el6_5.3.x86_64
> pacemaker-cli-1.1.10-14.el6_5.3.x86_64
> pacemaker-cluster-libs-1.1.10-14.el6_5.3.x86_64
> 
> I saw the following logs a few days back.
> 
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: process_graph_event:520 - Triggered transition
> abort (complete=0, node=ram, tag=lrm_rsc_op, id=unicloud_last_0,
> magic=0:0;11:232:0:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.4)
> : Old event
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> process_graph_event: Detected action (232.11)
> unicloud_promote_0.1097=ok: arrived really late
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: process_graph_event:520 - Triggered transition
> abort (complete=0, node=ram, tag=lrm_rsc_op,
> id=unicloud_monitor_10000,
> magic=0:8;13:233:8:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.4)
> : Old event
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> process_graph_event: Detected action (233.13)
> unicloud_monitor_10000.1107=master: arrived really late
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: process_graph_event:520 - Triggered transition
> abort (complete=0, node=ram, tag=lrm_rsc_op, id=AC_FLT_last_0,
> magic=0:7;8:251:7:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.4) :
> Old event
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> process_graph_event: Detected action (251.8) AC_FLT_monitor_0.1140=not
> running: arrived really late
> Oct 21 14:30:24 [4760] bharat        cib:     info:
> cib_process_request: Completed cib_delete operation for section
> //node_state[@uname='bharat']/lrm: OK (rc=0, origin=local/crmd/1238,
> version=0.183.5)
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: te_update_diff:258 - Triggered transition
> abort (complete=0, node=bharat, tag=lrm_rsc_op, id=unicloud_last_0,
> magic=0:0;14:226:0:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.5)
> : Resource op removal
> Oct 21 14:30:24 [4760] bharat        cib:     info:
> cib_process_request: Completed cib_modify operation for section
> status: OK (rc=0, origin=local/crmd/1239, version=0.183.6)
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: process_graph_event:520 - Triggered transition
> abort (complete=0, node=bharat, tag=lrm_rsc_op, id=unicloud_last_0,
> magic=0:0;14:226:0:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.6)
> : Old event
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> process_graph_event: Detected action (226.14)
> unicloud_start_0.1043=ok: arrived really late
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> abort_transition_graph: process_graph_event:520 - Triggered transition
> abort (complete=0, node=bharat, tag=lrm_rsc_op,
> id=unicloud_monitor_11000,
> magic=0:0;16:233:0:0d6c27e7-10dd-4df1-a2b1-ba458acec5c0, cib=0.183.6)
> : Old event
> Oct 21 14:30:24 [4765] bharat       crmd:     info:
> process_graph_event: Detected action (233.16)
> unicloud_monitor_11000.1126=ok: arrived really late
> 
> Many similar logs were seen for monitor event on virtual IP's. This
> seems to trigger aborting of the current transaction. Is there
> something wrong ?

At a guess, I'd say someone used an old-ish version of crmsh at about this time.
There are other ways to trigger it, but that was the most common.