[ClusterLabs] In N+1 cluster, add/delete of one resource result in other node resources to restart
Anu Pillai
anu.pillai.subscrib at gmail.com
Tue May 16 09:34:54 UTC 2017
Hi,
Please find attached debug logs for the stated problem as well as crm_mon
command outputs.
In this case we are trying to remove/delete res3 and system/node (
0005B94238BC) from the cluster.
*Test reproduction steps*
Current Configuration of the cluster:
0005B9423910 - res2
0005B9427C5A - res1
0005B94238BC - res3
*crm_mon output:*
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:23 2017 Last change: Tue May 16
12:13:40 2017 by root via crm_attribute on 0005B9423910
3 nodes and 3 resources configured
Online: [ 0005B94238BC 0005B9423910 0005B9427C5A ]
res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
res3 (ocf::redundancy:RedundancyRA): Started 0005B94238BC
Trigger the delete operation for res3 and node 0005B94238BC.
Following commands applied from node 0005B94238BC
$ pcs resource delete res3 --force
$ crm_resource -C res3
$ pcs cluster stop --force
Following command applied from DC(0005B9423910)
$ crm_node -R 0005B94238BC --force
*crm_mon output:*
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:27 2017 Last change: Tue May 16
12:21:26 2017 by root via cibadmin on 0005B94238BC
3 nodes and 2 resources configured
Online: [ 0005B94238BC 0005B9423910 0005B9427C5A ]
Observation is remaining two resources res2 and res1 were stopped and
started.
Regards,
Aswathi
On Mon, May 15, 2017 at 8:11 PM, Ken Gaillot <kgaillot at redhat.com> wrote:
> On 05/15/2017 06:59 AM, Klaus Wenninger wrote:
> > On 05/15/2017 12:25 PM, Anu Pillai wrote:
> >> Hi Klaus,
> >>
> >> Please find attached cib.xml as well as corosync.conf.
>
> Maybe you're only setting this while testing, but having
> stonith-enabled=false and no-quorum-policy=ignore is highly dangerous in
> any kind of network split.
>
> FYI, default-action-timeout is deprecated in favor of setting a timeout
> in op_defaults, but it doesn't hurt anything.
>
> > Why wouldn't you keep placement-strategy with default
> > to keep things simple. You aren't using any load-balancing
> > anyway as far as I understood it.
>
> It looks like the intent is to use placement-strategy to limit each node
> to 1 resource. The configuration looks good for that.
>
> > Haven't used resource-stickiness=INF. No idea which strange
> > behavior that triggers. Try to have it just higher than what
> > the other scores might some up to.
>
> Either way would be fine. Using INFINITY ensures that no other
> combination of scores will override it.
>
> > I might have overseen something in your scores but otherwise
> > there is nothing obvious to me.
> >
> > Regards,
> > Klaus
>
> I don't see anything obvious either. If you have logs around the time of
> the incident, that might help.
>
> >> Regards,
> >> Aswathi
> >>
> >> On Mon, May 15, 2017 at 2:46 PM, Klaus Wenninger <kwenning at redhat.com
> >> <mailto:kwenning at redhat.com>> wrote:
> >>
> >> On 05/15/2017 09:36 AM, Anu Pillai wrote:
> >> > Hi,
> >> >
> >> > We are running pacemaker cluster for managing our resources. We
> >> have 6
> >> > system running 5 resources and one is acting as standby. We have a
> >> > restriction that, only one resource can run in one node. But our
> >> > observation is whenever we add or delete a resource from cluster
> all
> >> > the remaining resources in the cluster are stopped and started
> back.
> >> >
> >> > Can you please guide us whether this normal behavior or we are
> >> missing
> >> > any configuration that is leading to this issue.
> >>
> >> It should definitely be possible to prevent this behavior.
> >> If you share your config with us we might be able to
> >> track that down.
> >>
> >> Regards,
> >> Klaus
> >>
> >> >
> >> > Regards
> >> > Aswathi
>
> _______________________________________________
> Users mailing list: Users at clusterlabs.org
> http://lists.clusterlabs.org/mailman/listinfo/users
>
> Project Home: http://www.clusterlabs.org
> Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf
> Bugs: http://bugs.clusterlabs.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.clusterlabs.org/pipermail/users/attachments/20170516/95734fd5/attachment-0002.html>
-------------- next part --------------
May 16 12:21:20 [4658] 0005B9423910 lrmd: debug: recurring_action_timer: Scheduling another invocation of res2_monitor_30000
RedundancyRA(res2)[3075]: 2017/05/16_12:21:20 INFO: failover_monitor: res2 is Running. Return Status 0
May 16 12:21:20 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_30000:3075 - exited with rc=0
May 16 12:21:20 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_30000:3075:stderr [ -- empty -- ]
May 16 12:21:20 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_30000:3075:stdout [ -- empty -- ]
May 16 12:21:20 [4658] 0005B9423910 lrmd: debug: log_finished: finished - rsc:res2 action:monitor call_id:41 pid:3075 exit-code:0 exec-time:0ms queue-time:0ms
May 16 12:21:20 [4661] 0005B9423910 crmd: debug: throttle_cib_load: cib load: 0.000000 (0 ticks in 30s)
May 16 12:21:20 [4661] 0005B9423910 crmd: debug: throttle_load_avg: Current load is 2.510000 (full: 2.51 4.28 3.78 10/297 3081)
May 16 12:21:20 [4661] 0005B9423910 crmd: debug: throttle_io_load: Current IO load is 0.000000
May 16 12:21:24 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.186.0 2
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.187.0 1c9e6240aee4ec7717e9128f204734f6
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=187
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/configuration/resources/primitive[@id='res3']/meta_attributes[@id='res3-meta_attributes']: <nvpair id="res3-meta_attributes-target-role" name="target-role" value="Stopped"/>
May 16 12:21:24 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_modify op
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.186.0 -> 0.187.0 (S_IDLE)
May 16 12:21:24 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by res3-meta_attributes-target-role, target-role=Stopped: Non-status change (create cib=0.187.0, source=te_update_diff:436, path=/cib/configuration/resources/primitive[@id='res3']/meta_attributes[@id='res3-meta_attributes'], 1)
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_IDLE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:24 [4661] 0005B9423910 crmd: notice: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: do_state_transition: All 3 cluster nodes are eligible to run resources.
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 263: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:24 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.187.0 to 0.186.0
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section resources: OK (rc=0, origin=0005B94238BC/crm_resource/6, version=0.187.0)
May 16 12:21:24 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: do_pe_invoke_callback: Invoking the PE: query=263, ref=pe_calc-dc-1494937284-214, seq=12, quorate=1
May 16 12:21:24 [4660] 0005B9423910 pengine: notice: unpack_config: Relying on watchdog integration for fencing
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH timeout: 60000
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH of failed nodes is disabled
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: Concurrent fencing is disabled
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: Stop all active resources: false
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: Default stickiness: 0
May 16 12:21:24 [4660] 0005B9423910 pengine: notice: unpack_config: On loss of CCM Quorum: Ignore
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
May 16 12:21:24 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9423910 is online
May 16 12:21:24 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B94238BC is online
May 16 12:21:24 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9427C5A is online
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:24 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:24 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:24 [4660] 0005B9423910 pengine: info: native_print: res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
May 16 12:21:24 [4660] 0005B9423910 pengine: info: native_print: res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
May 16 12:21:24 [4660] 0005B9423910 pengine: info: native_print: res3 (ocf::redundancy:RedundancyRA): Started 0005B94238BC ( disabled )
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res3: preferring current location (node=0005B94238BC, weight=1000000)
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res2: preferring current location (node=0005B9423910, weight=1000000)
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res1: preferring current location (node=0005B9427C5A, weight=1000000)
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-52.raw
May 16 12:21:24 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: native_assign_node: All nodes for resource res3 are unavailable, unclean or shutting down (0005B94238BC: 1, -1000000)
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: native_assign_node: Could not allocate a node for res3
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: native_assign_node: Processing res3_monitor_30000
May 16 12:21:24 [4660] 0005B9423910 pengine: info: native_color: Resource res3 cannot run anywhere
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9423910 to res2
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: process_utilization: Resource res1 and its colocated resources cannot be allocated to node 0005B9423910: no enough capacity
May 16 12:21:24 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9427C5A to res1
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.187.0 of the CIB to disk (digest: 3bbb7979615549308cf8a2bfc5e57602)
May 16 12:21:24 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest 3bbb7979615549308cf8a2bfc5e57602 to disk
May 16 12:21:24 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.XoclS1 (digest: /dev/shm/lib/pacemaker/cib/cib.yXpHYU)
May 16 12:21:24 [4660] 0005B9423910 pengine: notice: LogActions: Stop res3 (0005B94238BC)
May 16 12:21:24 [4660] 0005B9423910 pengine: info: LogActions: Leave res2 (Started 0005B9423910)
May 16 12:21:24 [4660] 0005B9423910 pengine: info: LogActions: Leave res1 (Started 0005B9427C5A)
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_SUCCESS: [ state=S_POLICY_ENGINE cause=C_IPC_MESSAGE origin=handle_response ]
May 16 12:21:24 [4661] 0005B9423910 crmd: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: unpack_graph: Unpacked transition 131: 5 actions in 5 synapses
May 16 12:21:24 [4661] 0005B9423910 crmd: info: do_te_invoke: Processing graph 131 (ref=pe_calc-dc-1494937284-214) derived from /dev/shm/lib/pacemaker/pengine/pe-input-131.bz2
May 16 12:21:24 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 8: stop res3_stop_0 on 0005B94238BC
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 7 fired and confirmed
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 5 fired and confirmed
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: run_graph: Transition 131 (Complete=0, Pending=1, Fired=3, Skipped=0, Incomplete=2, Source=/dev/shm/lib/pacemaker/pengine/pe-input-131.bz2): In-progress
May 16 12:21:24 [4661] 0005B9423910 crmd: debug: run_graph: Transition 131 (Complete=2, Pending=1, Fired=0, Skipped=0, Incomplete=2, Source=/dev/shm/lib/pacemaker/pengine/pe-input-131.bz2): In-progress
May 16 12:21:24 [4660] 0005B9423910 pengine: notice: process_pe_message: Calculated Transition 131: /dev/shm/lib/pacemaker/pengine/pe-input-131.bz2
May 16 12:21:24 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.XoclS1
May 16 12:21:25 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:25 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.187.0 2
May 16 12:21:25 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.187.1 (null)
May 16 12:21:25 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=1
May 16 12:21:25 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res3']/lrm_rsc_op[@id='res3_last_0']: @operation_key=res3_stop_0, @operation=stop, @transition-key=8:131:0:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, @transition-magic=0:0;8:131:0:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, @call-id=38, @last-run=1494937284, @last-rc-change=1494937284, @exec-time=445, @queue-time=0
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.187.0 -> 0.187.1 (S_TRANSITION_ENGINE)
May 16 12:21:25 [4661] 0005B9423910 crmd: info: match_graph_event: Action res3_stop_0 (8) confirmed on 0005B94238BC (rc=0)
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 6 fired and confirmed
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 4 fired and confirmed
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: run_graph: Transition 131 (Complete=3, Pending=0, Fired=2, Skipped=0, Incomplete=0, Source=/dev/shm/lib/pacemaker/pengine/pe-input-131.bz2): In-progress
May 16 12:21:25 [4661] 0005B9423910 crmd: notice: run_graph: Transition 131 (Complete=5, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/dev/shm/lib/pacemaker/pengine/pe-input-131.bz2): Complete
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: te_graph_trigger: Transition 131 is now complete
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: notify_crmd: Processing transition completion in state S_TRANSITION_ENGINE
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: notify_crmd: Transition 131 status: done - <null>
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_TE_SUCCESS: [ state=S_TRANSITION_ENGINE cause=C_FSA_INTERNAL origin=notify_crmd ]
May 16 12:21:25 [4661] 0005B9423910 crmd: info: do_log: FSA: Input I_TE_SUCCESS from notify_crmd() received in state S_TRANSITION_ENGINE
May 16 12:21:25 [4661] 0005B9423910 crmd: notice: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: do_state_transition: Starting PEngine Recheck Timer
May 16 12:21:25 [4661] 0005B9423910 crmd: debug: crm_timer_start: Started PEngine Recheck Timer (I_PE_CALC:900000ms), src=413
May 16 12:21:25 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.187.1 to 0.187.0
May 16 12:21:25 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B94238BC/crmd/37, version=0.187.1)
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.187.1 2
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.188.0 (null)
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/configuration/constraints/rsc_location[@id='location-res3-0005B9423910-0']
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/configuration/constraints/rsc_location[@id='location-res3-0005B9427C5A-0']
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/configuration/constraints/rsc_location[@id='location-res3-0005B94238BC-100']
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=188, @num_updates=0
May 16 12:21:26 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_replace op
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_replace) diff: 0.187.1 -> 0.188.0 (S_IDLE)
May 16 12:21:26 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of rsc_location[@id='location-res3-0005B9423910-0']: Non-status change (cib=0.188.0, source=te_update_diff:436, path=/cib/configuration/constraints/rsc_location[@id='location-res3-0005B9423910-0'], 1)
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_IDLE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:26 [4661] 0005B9423910 crmd: notice: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: do_state_transition: All 3 cluster nodes are eligible to run resources.
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 264: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:26 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.188.0 to 0.187.1
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_replace operation for section configuration: OK (rc=0, origin=0005B94238BC/cibadmin/2, version=0.188.0)
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: do_pe_invoke_callback: Invoking the PE: query=264, ref=pe_calc-dc-1494937286-216, seq=12, quorate=1
May 16 12:21:26 [4660] 0005B9423910 pengine: notice: unpack_config: Relying on watchdog integration for fencing
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH timeout: 60000
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH of failed nodes is disabled
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: Concurrent fencing is disabled
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: Stop all active resources: false
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: Default stickiness: 0
May 16 12:21:26 [4660] 0005B9423910 pengine: notice: unpack_config: On loss of CCM Quorum: Ignore
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
May 16 12:21:26 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9423910 is online
May 16 12:21:26 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B94238BC is online
May 16 12:21:26 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9427C5A is online
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:26 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:26 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: unpack_lrm_rsc_state: res3: Overwriting calculated next role Unknown with requested next role Stopped
May 16 12:21:26 [4660] 0005B9423910 pengine: info: native_print: res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
May 16 12:21:26 [4660] 0005B9423910 pengine: info: native_print: res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
May 16 12:21:26 [4660] 0005B9423910 pengine: info: native_print: res3 (ocf::redundancy:RedundancyRA): Stopped ( disabled )
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res2: preferring current location (node=0005B9423910, weight=1000000)
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res1: preferring current location (node=0005B9427C5A, weight=1000000)
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //primitive[@id='res3'] with /cib/configuration/resources/primitive[3]
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.188.0 2
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.0 (null)
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/configuration/resources/primitive[@id='res3']
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=189
May 16 12:21:26 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_delete op
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-53.raw
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.188.0 -> 0.189.0 (S_POLICY_ENGINE)
May 16 12:21:26 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of primitive[@id='res3']: Non-status change (cib=0.189.0, source=te_update_diff:436, path=/cib/configuration/resources/primitive[@id='res3'], 1)
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 265: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:26 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.0 to 0.188.0
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //primitive[@id='res3']: OK (rc=0, origin=0005B94238BC/cibadmin/2, version=0.189.0)
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9423910 to res2
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: process_utilization: Resource res1 and its colocated resources cannot be allocated to node 0005B9423910: no enough capacity
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9427C5A to res1
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: native_assign_node: All nodes for resource res3 are unavailable, unclean or shutting down (0005B94238BC: 1, -1000000)
May 16 12:21:26 [4660] 0005B9423910 pengine: debug: native_assign_node: Could not allocate a node for res3
May 16 12:21:26 [4660] 0005B9423910 pengine: info: native_color: Resource res3 cannot run anywhere
May 16 12:21:26 [4660] 0005B9423910 pengine: info: LogActions: Leave res2 (Started 0005B9423910)
May 16 12:21:26 [4660] 0005B9423910 pengine: info: LogActions: Leave res1 (Started 0005B9427C5A)
May 16 12:21:26 [4660] 0005B9423910 pengine: info: LogActions: Leave res3 (Stopped)
May 16 12:21:26 [4661] 0005B9423910 crmd: info: handle_response: pe_calc calculation pe_calc-dc-1494937286-216 is obsolete
May 16 12:21:26 [4661] 0005B9423910 crmd: debug: do_pe_invoke_callback: Invoking the PE: query=265, ref=pe_calc-dc-1494937286-217, seq=12, quorate=1
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.188.0 of the CIB to disk (digest: 5ef8cbae0af15e07451d4a53012295cd)
May 16 12:21:26 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest 5ef8cbae0af15e07451d4a53012295cd to disk
May 16 12:21:26 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.vmIgRb (digest: /dev/shm/lib/pacemaker/cib/cib.kwtC2l)
May 16 12:21:26 [4660] 0005B9423910 pengine: notice: process_pe_message: Calculated Transition 132: /dev/shm/lib/pacemaker/pengine/pe-input-132.bz2
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.vmIgRb
May 16 12:21:27 [4659] 0005B9423910 attrd: debug: attrd_peer_update: Setting fail-count-res1 for all hosts to (null)
May 16 12:21:27 [4659] 0005B9423910 attrd: debug: attrd_peer_update: Setting fail-count-res2 for all hosts to (null)
May 16 12:21:27 [4661] 0005B9423910 crmd: notice: do_lrm_invoke: Forcing the status of all resources to be redetected
May 16 12:21:27 [4661] 0005B9423910 crmd: info: force_reprobe: clearing resource history on node 0005B9423910
May 16 12:21:27 [4661] 0005B9423910 crmd: info: delete_resource: Removing resource res2 for 9b7b8981-8069-4838-b62b-d9ba5d0e96e4 (root) on 0005B94238BC
May 16 12:21:27 [4658] 0005B9423910 lrmd: info: cancel_recurring_action: Cancelling ocf operation res2_monitor_30000
May 16 12:21:27 [4658] 0005B9423910 lrmd: debug: log_finished: finished - rsc:res2 action:monitor call_id:41 exit-code:0 exec-time:0ms queue-time:0ms
May 16 12:21:27 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_unregister operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=1, notify=1
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: delete_rsc_entry: sync: Sending delete op for res2
May 16 12:21:27 [4661] 0005B9423910 crmd: info: lrm_remove_deleted_op: Removing op res2_monitor_30000:41 for deleted resource res2
May 16 12:21:27 [4661] 0005B9423910 crmd: info: delete_resource: Removing resource res3 for 9b7b8981-8069-4838-b62b-d9ba5d0e96e4 (root) on 0005B94238BC
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] to all (origin=local/crmd/266)
May 16 12:21:27 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_unregister operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=1, notify=1
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: delete_rsc_entry: sync: Sending delete op for res3
May 16 12:21:27 [4661] 0005B9423910 crmd: info: delete_resource: Removing resource res1 for 9b7b8981-8069-4838-b62b-d9ba5d0e96e4 (root) on 0005B94238BC
May 16 12:21:27 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_unregister operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=1, notify=1
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: delete_rsc_entry: sync: Sending delete op for res1
May 16 12:21:27 [4661] 0005B9423910 crmd: info: erase_status_tag: Deleting xpath: //node_state[@uname='0005B9423910']/lrm
May 16 12:21:27 [4659] 0005B9423910 attrd: debug: attrd_client_update: Broadcasting probe_complete[0005B9423910] = (null)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: attrd_update_delegate: Sent update: probe_complete=(null) for 0005B9423910
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_lrm_invoke: ACK'ing re-probe from 9b7b8981-8069-4838-b62b-d9ba5d0e96e4 (0005B94238BC)
May 16 12:21:27 [4658] 0005B9423910 lrmd: info: process_lrmd_get_rsc_info: Resource 'res2' not found (0 active resources)
May 16 12:21:27 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_info operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=0, notify=0
May 16 12:21:27 [4661] 0005B9423910 crmd: info: process_lrm_event: Operation res2_monitor_30000: Cancelled (node=0005B9423910, call=41, confirmed=true)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: send_notification: Sending 'resource' notification to '/var/log/notify.log' via '/etc/sysconfig/notify.sh'
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4661] 0005B9423910 crmd: info: process_lrm_event: Deletion of resource 'res2' complete after res2_monitor_30000
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: delete_rsc_entry: sync: Sending delete op for res2
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: update_history_cache: Purged history for 'res2' after monitor
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B94238BC']//lrm_resource[@id='res2'] with /cib/status/node_state[2]/lrm/lrm_resources/lrm_resource[1]
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.0 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.1 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res2']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=1
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-54.raw
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.0 -> 0.189.1 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344358 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res2']: Resource state removal (cib=0.189.1, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res2'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 272: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.1 to 0.189.0
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B94238BC']//lrm_resource[@id='res2']: OK (rc=0, origin=0005B94238BC/crmd/38, version=0.189.1)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.189.0 of the CIB to disk (digest: 612d86b48694197abeb18d3536beb94b)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest 612d86b48694197abeb18d3536beb94b to disk
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.Xfrx9v (digest: /dev/shm/lib/pacemaker/cib/cib.83qxdW)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B94238BC']//lrm_resource[@id='res3'] with /cib/status/node_state[2]/lrm/lrm_resources/lrm_resource[1]
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: unpack_config: Relying on watchdog integration for fencing
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH timeout: 60000
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH of failed nodes is disabled
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: Concurrent fencing is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.1 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.2 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res3']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=2
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: Stop all active resources: false
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: Default stickiness: 0
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: unpack_config: On loss of CCM Quorum: Ignore
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
May 16 12:21:27 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9423910 is online
May 16 12:21:27 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B94238BC is online
May 16 12:21:27 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9427C5A is online
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: process_orphan_resource: Detected orphan resource res3 on 0005B9423910
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: create_fake_resource: Orphan resource <primitive id="res3" type="RedundancyRA" class="ocf" provider="redundancy"/>
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:27 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: determine_op_status: res2_monitor_0 on 0005B9423910 returned 'ok' (0) instead of the expected value: 'not running' (7)
May 16 12:21:27 [4660] 0005B9423910 pengine: info: determine_op_status: Operation monitor found resource res2 active on 0005B9423910
May 16 12:21:27 [4660] 0005B9423910 pengine: info: native_print: res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
May 16 12:21:27 [4660] 0005B9423910 pengine: info: native_print: res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res2: preferring current location (node=0005B9423910, weight=1000000)
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: common_apply_stickiness: Resource res1: preferring current location (node=0005B9427C5A, weight=1000000)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.Xfrx9v
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: DeleteRsc: Removing res3 from 0005B9423910
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.1 -> 0.189.2 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344358 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res3']: Resource state removal (cib=0.189.2, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res3'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 273: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.2 to 0.189.1
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B94238BC']//lrm_resource[@id='res3']: OK (rc=0, origin=0005B94238BC/crmd/39, version=0.189.2)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B94238BC']//lrm_resource[@id='res1'] with /cib/status/node_state[2]/lrm/lrm_resources/lrm_resource
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.2 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.3 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res1']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=3
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: DeleteRsc: Removing res3 from 0005B94238BC
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.2 -> 0.189.3 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344358 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res1']: Resource state removal (cib=0.189.3, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344358']/lrm[@id='181344358']/lrm_resources/lrm_resource[@id='res1'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 274: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.3 to 0.189.2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B94238BC']//lrm_resource[@id='res1']: OK (rc=0, origin=0005B94238BC/crmd/40, version=0.189.3)
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: DeleteRsc: Removing res3 from 0005B9427C5A
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9423910 to res2
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: process_utilization: Resource res1 and its colocated resources cannot be allocated to node 0005B9423910: no enough capacity
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9427C5A to res1
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: All nodes for resource res3 are unavailable, unclean or shutting down (0005B94238BC: 1, -1000000)
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Could not allocate a node for res3
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Processing res3_delete_0
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Processing res3_delete_0
May 16 12:21:27 [4660] 0005B9423910 pengine: debug: native_assign_node: Processing res3_delete_0
May 16 12:21:27 [4660] 0005B9423910 pengine: info: LogActions: Leave res2 (Started 0005B9423910)
May 16 12:21:27 [4660] 0005B9423910 pengine: info: LogActions: Leave res1 (Started 0005B9427C5A)
May 16 12:21:27 [4661] 0005B9423910 crmd: info: handle_response: pe_calc calculation pe_calc-dc-1494937286-217 is obsolete
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4660] 0005B9423910 pengine: notice: process_pe_message: Calculated Transition 133: /dev/shm/lib/pacemaker/pengine/pe-input-133.bz2
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B94238BC']/lrm with /cib/status/node_state[2]/lrm
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.3 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.4 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344358']/lrm[@id='181344358']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=4
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.3 -> 0.189.4 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344358 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='181344358']: Resource state removal (cib=0.189.4, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344358']/lrm[@id='181344358'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 275: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.4 to 0.189.3
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B94238BC']/lrm: OK (rc=0, origin=0005B94238BC/crmd/41, version=0.189.4)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res2'] with /cib/status/node_state[3]/lrm/lrm_resources/lrm_resource[1]
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.4 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.5 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res2']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=5
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.4 -> 0.189.5 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344359 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res2']: Resource state removal (cib=0.189.5, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res2'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 276: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.5 to 0.189.4
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res2']: OK (rc=0, origin=0005B9427C5A/crmd/44, version=0.189.5)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res3'] with /cib/status/node_state[3]/lrm/lrm_resources/lrm_resource[2]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3301 - exited with rc=0
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3301:stderr [ -- empty -- ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3301:stdout [ -- empty -- ]
May 16 12:21:27 [4661] 0005B9423910 crmd: info: crmd_notify_complete: Notification 16 (/etc/sysconfig/notify.sh) complete
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.5 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.6 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res3']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=6
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.5 -> 0.189.6 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344359 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res3']: Resource state removal (cib=0.189.6, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res3'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 277: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.6 to 0.189.5
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res3']: OK (rc=0, origin=0005B9427C5A/crmd/45, version=0.189.6)
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:27 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1'] with /cib/status/node_state[3]/lrm/lrm_resources/lrm_resource
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.6 2
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.7 (null)
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res1']
May 16 12:21:27 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=7
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.6 -> 0.189.7 (S_POLICY_ENGINE)
May 16 12:21:27 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344359 to be down
May 16 12:21:27 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res1']: Resource state removal (cib=0.189.7, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources/lrm_resource[@id='res1'], 1)
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:27 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 278: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:27 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.7 to 0.189.6
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1']: OK (rc=0, origin=0005B9427C5A/crmd/46, version=0.189.7)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9427C5A']/lrm with /cib/status/node_state[3]/lrm
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.7 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.8 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344359']/lrm[@id='181344359']
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=8
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.7 -> 0.189.8 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344359 to be down
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='181344359']: Resource state removal (cib=0.189.8, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344359']/lrm[@id='181344359'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 279: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.8 to 0.189.7
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']/lrm: OK (rc=0, origin=0005B9427C5A/crmd/47, version=0.189.8)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] with /cib/status/node_state[1]/lrm/lrm_resources/lrm_resource[2]
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.8 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.189.9 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res2']
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=9
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.189.8 -> 0.189.9 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344360 to be down
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res2']: Resource state removal (cib=0.189.9, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res2'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 280: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.189.9 to 0.189.8
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2']: OK (rc=0, origin=0005B9423910/crmd/266, version=0.189.9)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1'] was already removed
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1']: OK (rc=0, origin=0005B9427C5A/crmd/48, version=0.189.9)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1'] was already removed
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9427C5A']//lrm_resource[@id='res1']: OK (rc=0, origin=0005B9427C5A/crmd/49, version=0.189.9)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.189.9 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.0 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=190, @num_updates=0
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/configuration/nodes/node[@id='181344358']/instance_attributes[@id='nodes-181344358']/nvpair[@id='nodes-0005B94238BC-CLUSTER_MGMT_MARK_FOR_DELETE']: @value=1
May 16 12:21:28 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_modify op
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.189.9 -> 0.190.0 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by nodes-0005B94238BC-CLUSTER_MGMT_MARK_FOR_DELETE, CLUSTER_MGMT_MARK_FOR_DELETE=1: Non-status change (modify cib=0.190.0, source=te_update_diff:436, path=/cib/configuration/nodes/node[@id='181344358']/instance_attributes[@id='nodes-181344358']/nvpair[@id='nodes-0005B94238BC-CLUSTER_MGMT_MARK_FOR_DELETE'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 281: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.0 to 0.189.9
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=0005B94238BC/crm_attribute/4, version=0.190.0)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res3'] to all (origin=local/crmd/267)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res1'] to all (origin=local/crmd/268)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']/lrm to all (origin=local/crmd/269)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] to all (origin=local/crmd/270)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] to all (origin=local/crmd/271)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9423910']//lrm_resource[@id='res3'] with /cib/status/node_state[1]/lrm/lrm_resources/lrm_resource[1]
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.0 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.1 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res3']
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=1
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.190.0 -> 0.190.1 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344360 to be down
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res3']: Resource state removal (cib=0.190.1, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res3'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 282: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.1 to 0.190.0
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res3']: OK (rc=0, origin=0005B9423910/crmd/267, version=0.190.1)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9423910']//lrm_resource[@id='res1'] with /cib/status/node_state[1]/lrm/lrm_resources/lrm_resource
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.1 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.2 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res1']
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=2
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.190.1 -> 0.190.2 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344360 to be down
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm_resource[@id='res1']: Resource state removal (cib=0.190.2, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources/lrm_resource[@id='res1'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 283: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.2 to 0.190.1
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res1']: OK (rc=0, origin=0005B9423910/crmd/268, version=0.190.2)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B9423910']/lrm with /cib/status/node_state[1]/lrm
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.2 2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.3 (null)
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344360']/lrm[@id='181344360']
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=3
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.190.2 -> 0.190.3 (S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: warning: match_down_event: No reason to expect node 181344360 to be down
May 16 12:21:28 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by deletion of lrm[@id='181344360']: Resource state removal (cib=0.190.3, source=abort_unless_down:343, path=/cib/status/node_state[@id='181344360']/lrm[@id='181344360'], 1)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 284: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:28 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.3 to 0.190.2
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']/lrm: OK (rc=0, origin=0005B9423910/crmd/269, version=0.190.3)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: erase_xpath_callback: Deletion of "//node_state[@uname='0005B9423910']/lrm": OK (rc=0)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] was already removed
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2']: OK (rc=0, origin=0005B9423910/crmd/270, version=0.190.3)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_process_xpath: //node_state[@uname='0005B9423910']//lrm_resource[@id='res2'] was already removed
May 16 12:21:28 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B9423910']//lrm_resource[@id='res2']: OK (rc=0, origin=0005B9423910/crmd/271, version=0.190.3)
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:28 [4661] 0005B9423910 crmd: info: crm_update_peer_expected: handle_request: Node 0005B94238BC[181344358] - expected state is now down (was member)
May 16 12:21:28 [4661] 0005B9423910 crmd: info: handle_shutdown_request: Creating shutdown request for 0005B94238BC (state=S_POLICY_ENGINE)
May 16 12:21:28 [4661] 0005B9423910 crmd: debug: attrd_update_delegate: Sent update: shutdown=1494937288 for 0005B94238BC
May 16 12:21:28 [4659] 0005B9423910 attrd: debug: attrd_client_update: Broadcasting shutdown[0005B94238BC] = 1494937288
May 16 12:21:28 [4659] 0005B9423910 attrd: info: attrd_peer_update: Setting shutdown[0005B94238BC]: 0 -> 1494937288 from 0005B9423910
May 16 12:21:28 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.3 2
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.4 (null)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=4
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/status/node_state[@id='181344358']/transient_attributes[@id='181344358']/instance_attributes[@id='status-181344358']/nvpair[@id='status-181344358-shutdown']: @value=1494937288
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.3 -> 0.190.4 (S_POLICY_ENGINE)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by status-181344358-shutdown, shutdown=1494937288: Transient attribute change (modify cib=0.190.4, source=abort_unless_down:329, path=/cib/status/node_state[@id='181344358']/transient_attributes[@id='181344358']/instance_attributes[@id='status-181344358']/nvpair[@id='status-181344358-shutdown'], 1)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_CALC: [ state=S_POLICY_ENGINE cause=C_FSA_INTERNAL origin=abort_transition_graph ]
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: do_pe_invoke: Query 285: Requesting the current CIB: S_POLICY_ENGINE
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.4 to 0.190.3
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B94238BC/attrd/5, version=0.190.4)
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: do_pe_invoke_callback: Invoking the PE: query=285, ref=pe_calc-dc-1494937289-219, seq=12, quorate=1
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: unpack_config: Relying on watchdog integration for fencing
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH timeout: 60000
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: STONITH of failed nodes is disabled
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: Concurrent fencing is disabled
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: Stop all active resources: false
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: Default stickiness: 0
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: unpack_config: On loss of CCM Quorum: Ignore
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
May 16 12:21:29 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9423910 is online
May 16 12:21:29 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B94238BC is shutting down
May 16 12:21:29 [4660] 0005B9423910 pengine: info: determine_online_status: Node 0005B9427C5A is online
May 16 12:21:29 [4660] 0005B9423910 pengine: info: native_print: res2 (ocf::redundancy:RedundancyRA): Stopped
May 16 12:21:29 [4660] 0005B9423910 pengine: info: native_print: res1 (ocf::redundancy:RedundancyRA): Stopped
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9423910 to res2
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: check_capacity: Node 0005B9423910 has no enough RESOURCE_UTIL for res1 and its colocated resources: required=1 remaining=0
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: process_utilization: Resource res1 and its colocated resources cannot be allocated to node 0005B9423910: no enough capacity
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_assign_node: Assigning 0005B9427C5A to res1
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res2 on 0005B94238BC (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res1 on 0005B94238BC (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res2 on 0005B9423910 (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res1 on 0005B9423910 (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res2 on 0005B9427C5A (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: debug: native_create_probe: Probing res1 on 0005B9427C5A (Stopped) 1 (nil)
May 16 12:21:29 [4660] 0005B9423910 pengine: info: RecurringOp: Start recurring monitor (30s) for res2 on 0005B9423910
May 16 12:21:29 [4660] 0005B9423910 pengine: info: RecurringOp: Start recurring monitor (30s) for res1 on 0005B9427C5A
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: stage6: Scheduling Node 0005B94238BC for shutdown
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: LogActions: Start res2 (0005B9423910)
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: LogActions: Start res1 (0005B9427C5A)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-55.raw
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.190.0 of the CIB to disk (digest: c118b4c8ac40afd4391ea78a578a9d27)
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest c118b4c8ac40afd4391ea78a578a9d27 to disk
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.XiEMNI (digest: /dev/shm/lib/pacemaker/cib/cib.owSshi)
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.XiEMNI
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: s_crmd_fsa: Processing I_PE_SUCCESS: [ state=S_POLICY_ENGINE cause=C_IPC_MESSAGE origin=handle_response ]
May 16 12:21:29 [4661] 0005B9423910 crmd: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: unpack_graph: Unpacked transition 134: 14 actions in 14 synapses
May 16 12:21:29 [4661] 0005B9423910 crmd: info: do_te_invoke: Processing graph 134 (ref=pe_calc-dc-1494937289-219) derived from /dev/shm/lib/pacemaker/pengine/pe-input-134.bz2
May 16 12:21:29 [4660] 0005B9423910 pengine: notice: process_pe_message: Calculated Transition 134: /dev/shm/lib/pacemaker/pengine/pe-input-134.bz2
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 9: monitor res2_monitor_0 on 0005B9427C5A
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 7: monitor res2_monitor_0 on 0005B9423910 (local)
May 16 12:21:29 [4658] 0005B9423910 lrmd: info: process_lrmd_get_rsc_info: Resource 'res2' not found (0 active resources)
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_info operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=0, notify=0
May 16 12:21:29 [4658] 0005B9423910 lrmd: info: process_lrmd_rsc_register: Added 'res2' to the rsc list (1 active resources)
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_register operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=1, notify=1
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_info operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=0, notify=0
May 16 12:21:29 [4661] 0005B9423910 crmd: info: do_lrm_rsc_op: Performing key=7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e op=res2_monitor_0
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_exec operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=49, reply=1, notify=0
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: log_execute: executing - rsc:res2 action:monitor call_id:49
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 5: monitor res2_monitor_0 on 0005B94238BC
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 10: monitor res1_monitor_0 on 0005B9427C5A
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 8: monitor res1_monitor_0 on 0005B9423910 (local)
May 16 12:21:29 [4658] 0005B9423910 lrmd: info: process_lrmd_get_rsc_info: Resource 'res1' not found (1 active resources)
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_info operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=0, notify=0
May 16 12:21:29 [4658] 0005B9423910 lrmd: info: process_lrmd_rsc_register: Added 'res1' to the rsc list (2 active resources)
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_register operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=1, notify=1
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_info operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=0, reply=0, notify=0
May 16 12:21:29 [4661] 0005B9423910 crmd: info: do_lrm_rsc_op: Performing key=8:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e op=res1_monitor_0
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: process_lrmd_message: Processed lrmd_rsc_exec operation from adea40fa-a056-419a-9d88-49d4a7ccafa8: rc=53, reply=1, notify=0
May 16 12:21:29 [4658] 0005B9423910 lrmd: debug: log_execute: executing - rsc:res1 action:monitor call_id:53
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: te_rsc_command: Initiating action 6: monitor res1_monitor_0 on 0005B94238BC
May 16 12:21:29 [4661] 0005B9423910 crmd: info: te_crm_command: Executing crm-event (16): do_shutdown on 0005B94238BC
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.4 2
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.5 (null)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=5
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/status/node_state[@id='181344358']: <lrm id="181344358"/>
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resources>
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resource id="res2" type="RedundancyRA" class="ocf" provider="redundancy">
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res2_last_0" operation_key="res2_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="5:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:7;5:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B94238BC" call-id="45" rc-code="7" op-status="0" interval="0" last-run="1494937289" last-rc-change="
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resource>
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resources>
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm>
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.5 to 0.190.4
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B94238BC/crmd/42, version=0.190.5)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 4 fired and confirmed
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 3 fired and confirmed
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_pseudo_action: Pseudo action 2 fired and confirmed
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=0, Pending=6, Fired=10, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.4 -> 0.190.5 (S_TRANSITION_ENGINE)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: match_graph_event: Action res2_monitor_0 (5) confirmed on 0005B94238BC (rc=7)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=5, Pending=5, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:29 [4382] 0005B9423910 corosync debug [CPG ] got procleave message from cluster node 0xacf1866 (r(0) ip(10.207.24.102) r(1) ip(10.207.22.103) ) for pid 4988
May 16 12:21:29 [4661] 0005B9423910 crmd: info: pcmk_cpg_membership: Node 181344358 left group crmd (peer=0005B94238BC, counter=3.0)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: crm_update_peer_proc: pcmk_cpg_membership: Node 0005B94238BC[181344358] - corosync-cpg is now offline
May 16 12:21:29 [4661] 0005B9423910 crmd: info: peer_update_callback: Client 0005B94238BC/peer now has status [offline] (DC=true, changed=4000000)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: peer_update_callback: Peer 0005B94238BC left us
May 16 12:21:29 [4661] 0005B9423910 crmd: info: erase_status_tag: Deleting xpath: //node_state[@uname='0005B94238BC']/transient_attributes
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_delete operation for section //node_state[@uname='0005B94238BC']/transient_attributes to all (origin=local/crmd/286)
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_delete op for //node_state[@uname='0005B94238BC']/transient_attributes with /cib/status/node_state[2]/transient_attributes
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.5 2
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.6 (null)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: -- /cib/status/node_state[@id='181344358']/transient_attributes[@id='181344358']
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=6
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: match_down_event: Shutdown action found for node 181344358: action 16 (do_shutdown-0005B94238BC)
May 16 12:21:29 [4661] 0005B9423910 crmd: notice: peer_update_callback: do_shutdown of 0005B94238BC (op 16) is complete
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.6 to 0.190.5
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_delete operation for section //node_state[@uname='0005B94238BC']/transient_attributes: OK (rc=0, origin=0005B9423910/crmd/286, version=0.190.6)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: crm_update_peer_join: crmd_peer_down: Node 0005B94238BC[181344358] - join-2 phase 4 -> 0
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: check_join_state: Invoked by peer_update_callback in state: S_TRANSITION_ENGINE
May 16 12:21:29 [4661] 0005B9423910 crmd: info: pcmk_cpg_membership: Node 181344359 still member of group crmd (peer=0005B9427C5A, counter=3.0)
May 16 12:21:29 [4661] 0005B9423910 crmd: info: pcmk_cpg_membership: Node 181344360 still member of group crmd (peer=0005B9423910, counter=3.1)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_delete) diff: 0.190.5 -> 0.190.6 (S_TRANSITION_ENGINE)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: match_down_event: Shutdown action found for node 181344358: action 16 (do_shutdown-0005B94238BC)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: erase_xpath_callback: Deletion of "//node_state[@uname='0005B94238BC']/transient_attributes": OK (rc=0)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/287)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=5, Pending=5, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:29 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004111110 (was 00000000000000000000000004111310)
May 16 12:21:29 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004101110 (was 00000000000000000000000004111110)
May 16 12:21:29 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004100110 (was 00000000000000000000000004101110)
May 16 12:21:29 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004100100 (was 00000000000000000000000004100110)
May 16 12:21:29 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004000100 (was 00000000000000000000000004100100)
May 16 12:21:29 [4382] 0005B9423910 corosync debug [SERV ] got procleave message from cluster node 0xacf1866 (r(0) ip(10.207.24.102) r(1) ip(10.207.22.103) ) for pid 4986
May 16 12:21:29 [4659] 0005B9423910 attrd: info: pcmk_cpg_membership: Node 181344358 left group attrd (peer=0005B94238BC, counter=3.0)
May 16 12:21:29 [4659] 0005B9423910 attrd: info: crm_update_peer_proc: pcmk_cpg_membership: Node 0005B94238BC[181344358] - corosync-cpg is now offline
May 16 12:21:29 [4659] 0005B9423910 attrd: notice: crm_update_peer_state_iter: crm_update_peer_proc: Node 0005B94238BC[181344358] - state is now lost (was member)
May 16 12:21:29 [4659] 0005B9423910 attrd: notice: attrd_peer_remove: Removing all 0005B94238BC (181344358) attributes for attrd_peer_change_cb
May 16 12:21:29 [4659] 0005B9423910 attrd: debug: attrd_peer_remove: Removed shutdown[0005B94238BC]=(null) for attrd_peer_change_cb
May 16 12:21:29 [4659] 0005B9423910 attrd: notice: attrd_peer_change_cb: Lost attribute writer 0005B94238BC
May 16 12:21:29 [4659] 0005B9423910 attrd: notice: crm_reap_dead_member: Removing 0005B94238BC/181344358 from the membership list
May 16 12:21:29 [4659] 0005B9423910 attrd: notice: reap_crm_member: Purged 1 peers with id=181344358 and/or uname=0005B94238BC from the membership cache
May 16 12:21:29 [4659] 0005B9423910 attrd: info: pcmk_cpg_membership: Node 181344359 still member of group attrd (peer=0005B9427C5A, counter=3.0)
May 16 12:21:29 [4659] 0005B9423910 attrd: info: pcmk_cpg_membership: Node 181344360 still member of group attrd (peer=0005B9423910, counter=3.1)
May 16 12:21:29 [4382] 0005B9423910 corosync debug [SERV ] got procleave message from cluster node 0xacf1866 (r(0) ip(10.207.24.102) r(1) ip(10.207.22.103) ) for pid 4984
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: info: pcmk_cpg_membership: Node 181344358 left group stonith-ng (peer=0005B94238BC, counter=3.0)
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: info: crm_update_peer_proc: pcmk_cpg_membership: Node 0005B94238BC[181344358] - corosync-cpg is now offline
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.6 2
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.7 (null)
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=7
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/status/node_state[@id='181344358']: @crmd=offline, @crm-debug-origin=peer_update_callback, @join=down, @expected=down
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B9423910/crmd/287, version=0.190.7)
May 16 12:21:29 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.6 -> 0.190.7 (S_TRANSITION_ENGINE)
May 16 12:21:29 [4656] 0005B9423910 cib: debug: parse_peer_options_v2: Legacy handling of cib_shutdown_req message from 0005B94238BC
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_shutdown_req: Shutdown REQ from 0005B94238BC
May 16 12:21:29 [4656] 0005B9423910 cib: debug: parse_peer_options_v2: Legacy handling of cib_shutdown_req message from 0005B94238BC
May 16 12:21:29 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:29 [4656] 0005B9423910 cib: info: cib_process_shutdown_req: Shutdown REQ from 0005B94238BC
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: notice: crm_update_peer_state_iter: crm_update_peer_proc: Node 0005B94238BC[181344358] - state is now lost (was member)
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: debug: st_peer_update_callback: Broadcasting our uname because of node 181344358
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: notice: crm_reap_dead_member: Removing 0005B94238BC/181344358 from the membership list
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: notice: reap_crm_member: Purged 1 peers with id=181344358 and/or uname=0005B94238BC from the membership cache
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: info: pcmk_cpg_membership: Node 181344359 still member of group stonith-ng (peer=0005B9427C5A, counter=3.0)
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: info: pcmk_cpg_membership: Node 181344360 still member of group stonith-ng (peer=0005B9423910, counter=3.1)
May 16 12:21:29 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.7 to 0.190.6
May 16 12:21:29 [4382] 0005B9423910 corosync debug [SERV ] got procleave message from cluster node 0xacf1866 (r(0) ip(10.207.24.102) r(1) ip(10.207.22.103) ) for pid 4983
May 16 12:21:29 [4656] 0005B9423910 cib: info: pcmk_cpg_membership: Node 181344358 left group cib (peer=0005B94238BC, counter=3.0)
May 16 12:21:29 [4656] 0005B9423910 cib: info: crm_update_peer_proc: pcmk_cpg_membership: Node 0005B94238BC[181344358] - corosync-cpg is now offline
May 16 12:21:29 [4656] 0005B9423910 cib: notice: crm_update_peer_state_iter: crm_update_peer_proc: Node 0005B94238BC[181344358] - state is now lost (was member)
May 16 12:21:29 [4656] 0005B9423910 cib: notice: crm_reap_dead_member: Removing 0005B94238BC/181344358 from the membership list
May 16 12:21:29 [4656] 0005B9423910 cib: notice: reap_crm_member: Purged 1 peers with id=181344358 and/or uname=0005B94238BC from the membership cache
May 16 12:21:29 [4656] 0005B9423910 cib: info: pcmk_cpg_membership: Node 181344359 still member of group cib (peer=0005B9427C5A, counter=3.0)
May 16 12:21:29 [4656] 0005B9423910 cib: info: pcmk_cpg_membership: Node 181344360 still member of group cib (peer=0005B9423910, counter=3.1)
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: debug: update_node_processes: Node 0005B94238BC now has process list: 00000000000000000000000004000000 (was 00000000000000000000000004000100)
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: info: pcmk_cpg_membership: Node 181344358 left group pacemakerd (peer=0005B94238BC, counter=3.0)
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: info: crm_update_peer_proc: pcmk_cpg_membership: Node 0005B94238BC[181344358] - corosync-cpg is now offline
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: info: pcmk_cpg_membership: Node 181344359 still member of group pacemakerd (peer=0005B9427C5A, counter=3.0)
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: info: pcmk_cpg_membership: Node 181344360 still member of group pacemakerd (peer=0005B9423910, counter=3.1)
May 16 12:21:30 [4382] 0005B9423910 corosync debug [SERV ] got procleave message from cluster node 0xacf1866 (r(0) ip(10.207.24.102) r(1) ip(10.207.22.103) ) for pid 4918
May 16 12:21:30 [4564] 0005B9423910 pacemakerd: info: mcp_cpg_deliver: Ignoring process list sent by peer for local node
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.7 2
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.8 (null)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=8
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/status/node_state[@id='181344359']: <lrm id="181344359"/>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resources>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resource id="res2" type="RedundancyRA" class="ocf" provider="redundancy">
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res2_last_0" operation_key="res2_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="9:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:7;9:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9427C5A" call-id="50" rc-code="7" op-status="0" interval="0" last-run="1494937289" last-rc-change="
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resource>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resources>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm>
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.7 -> 0.190.8 (S_TRANSITION_ENGINE)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res2_monitor_0 (9) confirmed on 0005B9427C5A (rc=7)
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=6, Pending=4, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:30 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.8 to 0.190.7
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B9427C5A/crmd/50, version=0.190.8)
RedundancyRA(res2)[3409]: 2017/05/16_12:21:30 INFO: failover_monitor: res2 is Running. Return Status 0
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_0:3409 - exited with rc=0
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_0:3409:stderr [ -- empty -- ]
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res2_monitor_0:3409:stdout [ -- empty -- ]
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: log_finished: finished - rsc:res2 action:monitor call_id:49 pid:3409 exit-code:0 exec-time:618ms queue-time:1ms
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: child_waitpid: wait(3410) = 0: Resource temporarily unavailable (11)
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: create_operation_update: do_update_resource: Updating resource res2 after monitor op complete (interval=0)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/288)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.8 2
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.9 (null)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=9
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/status/node_state[@id='181344360']: <lrm id="181344360"/>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resources>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_resource id="res2" type="RedundancyRA" class="ocf" provider="redundancy">
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res2_last_failure_0" operation_key="res2_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:0;7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9423910" call-id="49" rc-code="0" op-status="0" interval="0" last-run="1494937289" last-rc-
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res2_last_0" operation_key="res2_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:0;7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9423910" call-id="49" rc-code="0" op-status="0" interval="0" last-run="1494937289" last-rc-change="
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resource>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resources>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm>
May 16 12:21:30 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.9 to 0.190.8
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B9423910/crmd/288, version=0.190.9)
May 16 12:21:30 [4661] 0005B9423910 crmd: notice: process_lrm_event: Operation res2_monitor_0: ok (node=0005B9423910, call=49, rc=0, cib-update=288, confirmed=true)
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: send_notification: Sending 'resource' notification to '/var/log/notify.log' via '/etc/sysconfig/notify.sh'
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: update_history_cache: Updating history for 'res2' with monitor op
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.8 -> 0.190.9 (S_TRANSITION_ENGINE)
May 16 12:21:30 [4661] 0005B9423910 crmd: warning: status_from_rc: Action 7 (res2_monitor_0) on 0005B9423910 failed (target: 7 vs. rc: 0): Error
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: update_abort_priority: Abort priority upgraded from 0 to 1
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: update_abort_priority: Abort action done superseded by restart: Event failed
May 16 12:21:30 [4661] 0005B9423910 crmd: notice: abort_transition_graph: Transition aborted by res2_monitor_0 'create' on 0005B9423910: Event failed (magic=0:0;7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, cib=0.190.9, source=match_graph_event:310, 0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res2_monitor_0 (7) confirmed on 0005B9423910 (rc=0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: process_graph_event: Detected action (134.7) res2_monitor_0.49=ok: failed
May 16 12:21:30 [4661] 0005B9423910 crmd: warning: status_from_rc: Action 7 (res2_monitor_0) on 0005B9423910 failed (target: 7 vs. rc: 0): Error
May 16 12:21:30 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by res2_monitor_0 'create' on 0005B9423910: Event failed (magic=0:0;7:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, cib=0.190.9, source=match_graph_event:310, 0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res2_monitor_0 (7) confirmed on 0005B9423910 (rc=0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: process_graph_event: Detected action (134.7) res2_monitor_0.49=ok: failed
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=7, Pending=3, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
RedundancyRA(res1)[3410]: 2017/05/16_12:21:30 INFO: failover_monitor: res1 is Not Running. Return Status 0
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res1_monitor_0:3410 - exited with rc=7
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res1_monitor_0:3410:stderr [ -- empty -- ]
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: operation_finished: res1_monitor_0:3410:stdout [ -- empty -- ]
May 16 12:21:30 [4658] 0005B9423910 lrmd: debug: log_finished: finished - rsc:res1 action:monitor call_id:53 pid:3410 exit-code:7 exec-time:608ms queue-time:1ms
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: create_operation_update: do_update_resource: Updating resource res1 after monitor op complete (interval=0)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_modify operation for section status to all (origin=local/crmd/289)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.9 2
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.10 (null)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=10
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/status/node_state[@id='181344360']/lrm[@id='181344360']/lrm_resources: <lrm_resource id="res1" type="RedundancyRA" class="ocf" provider="redundancy"/>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res1_last_0" operation_key="res1_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="8:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:7;8:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9423910" call-id="53" rc-code="7" op-status="0" interval="0" last-ru
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resource>
May 16 12:21:30 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.10 to 0.190.9
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B9423910/crmd/289, version=0.190.10)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.10 2
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.190.11 (null)
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @num_updates=11
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ /cib/status/node_state[@id='181344359']/lrm[@id='181344359']/lrm_resources: <lrm_resource id="res1" type="RedundancyRA" class="ocf" provider="redundancy"/>
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res1_last_failure_0" operation_key="res1_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:0;10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9427C5A" call-id="54" rc-code="0" op-status="0" interval="
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ <lrm_rsc_op id="res1_last_0" operation_key="res1_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.0.10" transition-key="10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" transition-magic="0:0;10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e" on_node="0005B9427C5A" call-id="54" rc-code="0" op-status="0" interval="0" last-
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_perform_op: ++ </lrm_resource>
May 16 12:21:30 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.190.11 to 0.190.10
May 16 12:21:30 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section status: OK (rc=0, origin=0005B9427C5A/crmd/51, version=0.190.11)
May 16 12:21:30 [4661] 0005B9423910 crmd: notice: process_lrm_event: Operation res1_monitor_0: not running (node=0005B9423910, call=53, rc=7, cib-update=289, confirmed=true)
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: update_history_cache: Updating history for 'res1' with monitor op
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.9 -> 0.190.10 (S_TRANSITION_ENGINE)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res1_monitor_0 (8) confirmed on 0005B9423910 (rc=7)
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.10 -> 0.190.11 (S_TRANSITION_ENGINE)
May 16 12:21:30 [4661] 0005B9423910 crmd: warning: status_from_rc: Action 10 (res1_monitor_0) on 0005B9427C5A failed (target: 7 vs. rc: 0): Error
May 16 12:21:30 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by res1_monitor_0 'create' on 0005B9427C5A: Event failed (magic=0:0;10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, cib=0.190.11, source=match_graph_event:310, 0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res1_monitor_0 (10) confirmed on 0005B9427C5A (rc=0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: process_graph_event: Detected action (134.10) res1_monitor_0.54=ok: failed
May 16 12:21:30 [4661] 0005B9423910 crmd: warning: status_from_rc: Action 10 (res1_monitor_0) on 0005B9427C5A failed (target: 7 vs. rc: 0): Error
May 16 12:21:30 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by res1_monitor_0 'create' on 0005B9427C5A: Event failed (magic=0:0;10:134:7:f9b82bb4-73c5-4516-aa83-7cd38cc29e2e, cib=0.190.11, source=match_graph_event:310, 0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: match_graph_event: Action res1_monitor_0 (10) confirmed on 0005B9427C5A (rc=0)
May 16 12:21:30 [4661] 0005B9423910 crmd: info: process_graph_event: Detected action (134.10) res1_monitor_0.54=ok: failed
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=9, Pending=1, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3469 - exited with rc=0
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3469:stderr [ -- empty -- ]
May 16 12:21:30 [4661] 0005B9423910 crmd: debug: operation_finished: /etc/sysconfig/notify.sh:3469:stdout [ -- empty -- ]
May 16 12:21:30 [4661] 0005B9423910 crmd: info: crmd_notify_complete: Notification 17 (/etc/sysconfig/notify.sh) complete
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3471 id=54c5f54e-148c-400b-8a9f-f5657998d61b
May 16 12:21:30 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3471-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3471]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3471-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3471-13) state:2
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3471-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3471-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3471-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3485 id=34746f0b-4af7-49de-a8d4-0b1961159681
May 16 12:21:30 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3485-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3485]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344360']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[2]/instance_attributes/nvpair[1]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3485-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3485-13) state:2
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3485-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3485-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3485-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3487 id=fca8c41a-474e-43b1-a904-0f4a86019adc
May 16 12:21:30 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3487-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3487]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344359']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[3]/instance_attributes/nvpair[1]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3487-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3487-13) state:2
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3487-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3487-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3487-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3489 id=ad4240dc-790f-49f6-8795-0d61cb835201
May 16 12:21:30 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3489-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3489]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344359']//instance_attributes//nvpair[@name='CLUSTER_MGMT_MAC_ID'] with /cib/configuration/nodes/node[3]/instance_attributes/nvpair[2]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3489-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3489-13) state:2
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3489-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3489-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3489-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3491 id=2b2a217b-2d80-4ef0-bba6-ab23fb212ea8
May 16 12:21:30 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3491-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3491]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:30 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344358']//instance_attributes//nvpair[@name='CLUSTER_MGMT_MARK_FOR_DELETE'] with /cib/configuration/nodes/node[1]/instance_attributes/nvpair[5]
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3491-13)
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3491-13) state:2
May 16 12:21:30 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3491-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3491-13-header
May 16 12:21:30 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3491-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101b0470 for uid=0 gid=0 pid=3498 id=436c66b2-c2d6-4632-9612-10385a08184a
May 16 12:21:31 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3498-13)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3498]
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344360']//instance_attributes//nvpair[@id='nodes-0005B9423910-CLUSTER_MGMT_DISCOVERED_CONTROLLERS' and @name='CLUSTER_MGMT_DISCOVERED_CONTROLLERS'] with /cib/configuration/nodes/node[2]/instance_attributes/nvpair[11]
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_process_request: Forwarding cib_modify operation for section nodes to all (origin=local/crm_attribute/4)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.190.11 2
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.191.0 (null)
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=191, @num_updates=0
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/configuration/nodes/node[@id='181344360']/instance_attributes[@id='nodes-181344360']/nvpair[@id='nodes-0005B9423910-CLUSTER_MGMT_DISCOVERED_CONTROLLERS']: @value=0005B9427C5A
May 16 12:21:31 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_modify op
May 16 12:21:31 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.190.11 -> 0.191.0 (S_TRANSITION_ENGINE)
May 16 12:21:31 [4661] 0005B9423910 crmd: debug: update_abort_priority: Abort priority upgraded from 1 to 1000000
May 16 12:21:31 [4661] 0005B9423910 crmd: debug: update_abort_priority: 'Event failed' abort superseded by Non-status change
May 16 12:21:31 [4661] 0005B9423910 crmd: notice: abort_transition_graph: Transition aborted by nodes-0005B9423910-CLUSTER_MGMT_DISCOVERED_CONTROLLERS, CLUSTER_MGMT_DISCOVERED_CONTROLLERS=0005B9427C5A: Non-status change (modify cib=0.191.0, source=te_update_diff:436, path=/cib/configuration/nodes/node[@id='181344360']/instance_attributes[@id='nodes-181344360']/nvpair[@id='nodes-0005B9423910-CLUSTER_MGMT_DISCOVERED_CONTROLLERS'], 0)
May 16 12:21:31 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=9, Pending=1, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:31 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.191.0 to 0.190.11
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=0005B9423910/crm_attribute/4, version=0.191.0)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3498-13)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3498-13) state:2
May 16 12:21:31 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3498-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3498-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3498-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-56.raw
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.191.0 of the CIB to disk (digest: 286f57676c614c0e74029c5c5c8cb6ec)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest 286f57676c614c0e74029c5c5c8cb6ec to disk
May 16 12:21:31 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.d5vLnM (digest: /dev/shm/lib/pacemaker/cib/cib.yLNevq)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.d5vLnM
May 16 12:21:31 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3527 id=1ddf7e48-ebeb-4f73-af62-6dfe0c17ec12
May 16 12:21:31 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3527-13)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3527]
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:31 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3527-13)
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3527-13) state:2
May 16 12:21:31 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3527-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3527-13-header
May 16 12:21:31 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3527-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3540 id=907b3221-ad29-45e0-8af2-b766d5c4804f
May 16 12:21:32 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3540-13)
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3540]
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3540-13)
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3540-13) state:2
May 16 12:21:32 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3540-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3540-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3540-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3542 id=fa42f9c7-760d-4a43-aa95-61c9612882c6
May 16 12:21:32 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3542-13)
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3542]
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3542-13)
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3542-13) state:2
May 16 12:21:32 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3542-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3542-13-header
May 16 12:21:32 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3542-13-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-3577-31)
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] connecting to client [3577]
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-3577-31)
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-3577-31) state:2
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-3577-31-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-3577-31-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-3577-31-header
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: crm_client_new: Connecting 0x100275c0 for uid=0 gid=0 pid=3577 id=10194b5e-8e18-4b3d-920f-bd7a8dee919e
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: handle_new_connection: IPC credentials authenticated (4564-3577-10)
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_shm_connect: connecting to client [3577]
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_dispatch_connection_request: HUP conn (4564-3577-10)
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4564-3577-10) state:2
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-response-4564-3577-10-header
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-event-4564-3577-10-header
May 16 12:21:32 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-request-4564-3577-10-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-3580-31)
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] connecting to client [3580]
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-3580-31)
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-3580-31) state:2
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:32 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-3580-31-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-3580-31-header
May 16 12:21:32 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-3580-31-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3605 id=3504d41f-7153-4571-a7a3-141e98e4d350
May 16 12:21:33 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3605-13)
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3605]
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3605-13)
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3605-13) state:2
May 16 12:21:33 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3605-13-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3605-13-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3605-13-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3607 id=b2ac7f4c-e0a9-4251-81a7-170a967b0042
May 16 12:21:33 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3607-13)
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3607]
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3607-13)
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3607-13) state:2
May 16 12:21:33 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3607-13-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3607-13-header
May 16 12:21:33 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3607-13-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-3608-31)
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] connecting to client [3608]
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-3608-31)
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-3608-31) state:2
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-3608-31-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-3608-31-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-3608-31-header
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: crm_client_new: Connecting 0x100275c0 for uid=0 gid=0 pid=3608 id=ab6f7b34-5850-44c1-bef7-60df5fcc1cbb
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: handle_new_connection: IPC credentials authenticated (4564-3608-10)
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_shm_connect: connecting to client [3608]
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_dispatch_connection_request: HUP conn (4564-3608-10)
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4564-3608-10) state:2
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-response-4564-3608-10-header
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-event-4564-3608-10-header
May 16 12:21:33 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-request-4564-3608-10-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-3630-31)
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] connecting to client [3630]
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-3630-31)
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-3630-31) state:2
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:33 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-3630-31-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-3630-31-header
May 16 12:21:33 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-3630-31-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3647 id=6d433baa-42b0-4d41-b8b7-47caacf98ef9
May 16 12:21:34 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3647-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3647]
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3647-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3647-13) state:2
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3647-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3647-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3647-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3652 id=171d8c1d-f81a-4f59-a2f6-5d4245a1c09b
May 16 12:21:34 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3652-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3652]
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344360']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[2]/instance_attributes/nvpair[1]
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3652-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3652-13) state:2
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3652-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3652-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3652-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x1021f930 for uid=0 gid=0 pid=3673 id=592ce94d-78ff-493e-9849-cd6580c53346
May 16 12:21:34 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3673-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3673]
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:34 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344359']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[3]/instance_attributes/nvpair[1]
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3673-13)
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3673-13) state:2
May 16 12:21:34 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-3673-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-3673-13-header
May 16 12:21:34 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-3673-13-header
May 16 12:21:35 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:35 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: --- 0.191.0 2
May 16 12:21:35 [4656] 0005B9423910 cib: info: cib_perform_op: Diff: +++ 0.192.0 (null)
May 16 12:21:35 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib: @epoch=192
May 16 12:21:35 [4656] 0005B9423910 cib: info: cib_perform_op: + /cib/configuration/nodes/node[@id='181344359']/instance_attributes[@id='nodes-181344359']/nvpair[@id='nodes-0005B9427C5A-CLUSTER_MGMT_DISCOVERED_CONTROLLERS']: @value=0005B9423910
May 16 12:21:36 [4656] 0005B9423910 cib: debug: activateCibXml: Triggering CIB write for cib_modify op
May 16 12:21:36 [4661] 0005B9423910 crmd: debug: te_update_diff: Processing (cib_modify) diff: 0.191.0 -> 0.192.0 (S_TRANSITION_ENGINE)
May 16 12:21:36 [4661] 0005B9423910 crmd: info: abort_transition_graph: Transition aborted by nodes-0005B9427C5A-CLUSTER_MGMT_DISCOVERED_CONTROLLERS, CLUSTER_MGMT_DISCOVERED_CONTROLLERS=0005B9423910: Non-status change (modify cib=0.192.0, source=te_update_diff:436, path=/cib/configuration/nodes/node[@id='181344359']/instance_attributes[@id='nodes-181344359']/nvpair[@id='nodes-0005B9427C5A-CLUSTER_MGMT_DISCOVERED_CONTROLLERS'], 0)
May 16 12:21:36 [4661] 0005B9423910 crmd: debug: run_graph: Transition 134 (Complete=9, Pending=1, Fired=0, Skipped=0, Incomplete=4, Source=/dev/shm/lib/pacemaker/pengine/pe-input-134.bz2): In-progress
May 16 12:21:36 [4657] 0005B9423910 stonith-ng: debug: xml_patch_version_check: Can apply patch 0.192.0 to 0.191.0
May 16 12:21:36 [4656] 0005B9423910 cib: info: cib_process_request: Completed cib_modify operation for section nodes: OK (rc=0, origin=0005B9427C5A/crm_attribute/4, version=0.192.0)
May 16 12:21:36 [4656] 0005B9423910 cib: info: cib_file_backup: Archived previous version as /dev/shm/lib/pacemaker/cib/cib-57.raw
May 16 12:21:36 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Writing CIB to disk
May 16 12:21:36 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Wrote version 0.192.0 of the CIB to disk (digest: fe58c3985ff6aae1acf9b98127b99ccb)
May 16 12:21:36 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Wrote digest fe58c3985ff6aae1acf9b98127b99ccb to disk
May 16 12:21:36 [4656] 0005B9423910 cib: info: cib_file_write_with_digest: Reading cluster configuration file /dev/shm/lib/pacemaker/cib/cib.291BWn (digest: /dev/shm/lib/pacemaker/cib/cib.SmnxwA)
May 16 12:21:36 [4656] 0005B9423910 cib: debug: cib_file_write_with_digest: Activating /dev/shm/lib/pacemaker/cib/cib.291BWn
May 16 12:21:41 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:41 [4656] 0005B9423910 cib: info: cib_process_ping: Reporting our current digest to 0005B9423910: 7829bba1b8f69c8bf22709b61152f3d5 for 0.192.0 (0x10162738 0)
May 16 12:21:43 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=3931 id=ba8074c0-b33a-474c-ad30-c2b3a7db27c6
May 16 12:21:43 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-3931-13)
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [3931]
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:43 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-3931-13)
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-3931-13) state:2
May 16 12:21:43 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-3931-13-header
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-3931-13-header
May 16 12:21:43 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-3931-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4033 id=b7e747b6-7e1c-4c2c-b193-5083c5206cea
May 16 12:21:47 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4033-13)
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4033]
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4033-13)
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4033-13) state:2
May 16 12:21:47 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-4033-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-4033-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-4033-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4065 id=a201b116-a4f9-49c0-bdc1-833d3ffab420
May 16 12:21:47 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4065-13)
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4065]
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:47 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4065-13)
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4065-13) state:2
May 16 12:21:47 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-4065-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-4065-13-header
May 16 12:21:47 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-4065-13-header
May 16 12:21:47 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-4099-31)
May 16 12:21:47 [4382] 0005B9423910 corosync debug [QB ] connecting to client [4099]
May 16 12:21:47 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:47 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:47 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-4099-31)
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-4099-31) state:2
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-4099-31-header
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-4099-31-header
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-4099-31-header
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: crm_client_new: Connecting 0x100275c0 for uid=0 gid=0 pid=4099 id=755d8fb0-bc63-4370-932f-4895d600983b
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: handle_new_connection: IPC credentials authenticated (4564-4099-10)
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_shm_connect: connecting to client [4099]
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_dispatch_connection_request: HUP conn (4564-4099-10)
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4564-4099-10) state:2
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-response-4564-4099-10-header
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-event-4564-4099-10-header
May 16 12:21:48 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-request-4564-4099-10-header
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-4100-31)
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] connecting to client [4100]
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-4100-31)
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-4100-31) state:2
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:48 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-4100-31-header
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-4100-31-header
May 16 12:21:48 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-4100-31-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4136 id=a6155dc9-c147-4cff-bf3e-ed5034953652
May 16 12:21:49 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4136-13)
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4136]
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4136-13)
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4136-13) state:2
May 16 12:21:49 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-4136-13-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-4136-13-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-4136-13-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4138 id=1d64e6fc-e985-41b3-b0f9-5e72c161b2fe
May 16 12:21:49 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4138-13)
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4138]
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4138-13)
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4138-13) state:2
May 16 12:21:49 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-4138-13-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-4138-13-header
May 16 12:21:49 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-4138-13-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-4139-31)
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] connecting to client [4139]
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-4139-31)
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-4139-31) state:2
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-4139-31-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-4139-31-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-4139-31-header
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: crm_client_new: Connecting 0x100275c0 for uid=0 gid=0 pid=4139 id=beb7101c-5548-4183-a4f5-1e70682248bd
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: handle_new_connection: IPC credentials authenticated (4564-4139-10)
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_shm_connect: connecting to client [4139]
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_dispatch_connection_request: HUP conn (4564-4139-10)
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4564-4139-10) state:2
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-response-4564-4139-10-header
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-event-4564-4139-10-header
May 16 12:21:49 [4564] 0005B9423910 pacemakerd: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-pacemakerd-request-4564-4139-10-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] IPC credentials authenticated (4382-4141-31)
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] connecting to client [4141]
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] shm size:1048589; real_size:1064960; rb->word_size:266240
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] connection created
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] lib_init_fn: conn=0x101a9878
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] HUP conn (4382-4141-31)
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] qb_ipcs_disconnect(4382-4141-31) state:2
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_closed()
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] exit_fn for conn=0x101a9878
May 16 12:21:49 [4382] 0005B9423910 corosync debug [SERV ] cs_ipcs_connection_destroyed()
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-response-4382-4141-31-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-event-4382-4141-31-header
May 16 12:21:49 [4382] 0005B9423910 corosync debug [QB ] Free'ing ringbuffer: /dev/shm/qb-cmap-request-4382-4141-31-header
May 16 12:21:50 [4661] 0005B9423910 crmd: debug: throttle_cib_load: cib load: 0.050333 (151 ticks in 30s)
May 16 12:21:50 [4661] 0005B9423910 crmd: debug: throttle_load_avg: Current load is 3.250000 (full: 3.25 4.29 3.80 10/306 4189)
May 16 12:21:50 [4661] 0005B9423910 crmd: debug: throttle_io_load: Current IO load is 0.000000
May 16 12:21:50 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4190 id=36bf56a2-2c89-4d78-bcdf-77b086455dd6
May 16 12:21:50 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4190-13)
May 16 12:21:50 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4190]
May 16 12:21:50 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:50 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:50 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:50 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4190-13)
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4190-13) state:2
May 16 12:21:51 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-4190-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-4190-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-4190-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4222 id=886a9329-fac2-4fef-abdc-6c21f2076d49
May 16 12:21:51 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4222-13)
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4222]
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344360']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[2]/instance_attributes/nvpair[1]
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4222-13)
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4222-13) state:2
May 16 12:21:51 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-4222-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-4222-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-4222-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4224 id=53658217-dca8-43f3-8ceb-95e757b17821
May 16 12:21:51 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4224-13)
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4224]
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:51 [4656] 0005B9423910 cib: debug: cib_process_xpath: Processing cib_query op for //cib/configuration/nodes//node[@id='181344359']//instance_attributes//nvpair[@name='NODE_CLUSTER_STATE'] with /cib/configuration/nodes/node[3]/instance_attributes/nvpair[1]
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4224-13)
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4224-13) state:2
May 16 12:21:51 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-response-4656-4224-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-event-4656-4224-13-header
May 16 12:21:51 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_rw-request-4656-4224-13-header
May 16 12:21:52 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4241 id=ba39f00e-4401-4e2e-a354-5f17b1aff018
May 16 12:21:52 [4656] 0005B9423910 cib: debug: handle_new_connection: IPC credentials authenticated (4656-4241-13)
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_ipcs_shm_connect: connecting to client [4241]
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_open_2: shm size:2071657; real_size:2080768; rb->word_size:520192
May 16 12:21:52 [4656] 0005B9423910 cib: debug: cib_acl_enabled: CIB ACL is disabled
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_ipcs_dispatch_connection_request: HUP conn (4656-4241-13)
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_ipcs_disconnect: qb_ipcs_disconnect(4656-4241-13) state:2
May 16 12:21:52 [4656] 0005B9423910 cib: debug: crm_client_destroy: Destroying 0 events
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-response-4656-4241-13-header
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-event-4656-4241-13-header
May 16 12:21:52 [4656] 0005B9423910 cib: debug: qb_rb_close: Free'ing ringbuffer: /dev/shm/qb-cib_ro-request-4656-4241-13-header
May 16 12:21:52 [4656] 0005B9423910 cib: debug: crm_client_new: Connecting 0x101d11d8 for uid=0 gid=0 pid=4264 id=c5eb472b-8bcf-4472-ba2c-5e743e379559
-------------- next part --------------
Every 2s: crm_mon 2017-05-16 12:21:22
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:23 2017 Last change: Tue May 16 12:13:40 2017 by root via crm_attribute on 0005B9423910
3 nodes and 3 resources configured
Online: [ 0005B94238BC 0005B9423910 0005B9427C5A ]
res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
res3 (ocf::redundancy:RedundancyRA): Started 0005B94238BC
Every 2s: crm_mon 2017-05-16 12:21:25
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:25 2017 Last change: Tue May 16 12:21:24 2017 by root via crm_resource on 0005B94238BC
3 nodes and 3 resources configured: 1 resource DISABLED and 0 BLOCKED from being started due to failures
Online: [ 0005B94238BC 0005B9423910 0005B9427C5A ]
res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
res3 (ocf::redundancy:RedundancyRA): Started 0005B94238BC ( disabled )
Every 2s: crm_mon 2017-05-16 12:21:27
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:27 2017 Last change: Tue May 16 12:21:26 2017 by root via cibadmin on 0005B94238BC
3 nodes and 2 resources configured
Online: [ 0005B94238BC 0005B9423910 0005B9427C5A ]
Every 2s: crm_mon 2017-05-16 12:21:30
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:30 2017 Last change: Tue May 16 12:21:28 2017 by root via crm_attribute on 0005B94238BC
3 nodes and 2 resources configured
Online: [ 0005B9423910 0005B9427C5A ]
OFFLINE: [ 0005B94238BC ]
Every 2s: crm_mon 2017-05-16 12:21:32
Defaulting to one-shot mode
You need to have curses available at compile time to enable console mode
Stack: corosync
Current DC: 0005B9423910 (version 1.1.14-5a6cdd1) - partition with quorum
Last updated: Tue May 16 12:21:32 2017 Last change: Tue May 16 12:21:31 2017 by root via crm_attribute on 0005B9423910
3 nodes and 2 resources configured
Online: [ 0005B9423910 0005B9427C5A ]
OFFLINE: [ 0005B94238BC ]
res2 (ocf::redundancy:RedundancyRA): Started 0005B9423910
res1 (ocf::redundancy:RedundancyRA): Started 0005B9427C5A
More information about the Users
mailing list