[ClusterLabs] DRBD resource not failing over upon putting node into standby

Simon Lawrence simon.lawrence at navaho.co.uk
Thu Feb 26 14:30:53 UTC 2015


Hi

I am in the early stages of building a 2 node cluster running 
Centos6.6/DRBD8.4/Cman/Pacemaker1.1.12

So far I have just two resources: a drbd volume (centos1_drbd) and a KVM 
VM (centos1) that uses the drbd volume.
The /shared filesystem containing the VM config is currently manually 
replicated on both nodes.

The cluster correctly brings up the drbd resouce in primary/secondary 
mode. It is fully synced.

I have colocation and order constraints relating to the DRBD and VM 
resources, so the VM starts up correctly on the master node.

I am able to move VM from node to node using 'pcs resource move centos1 
<node>'. The drbd resource gets promoted/demoted accordingly.

However if I put one of the nodes into standby ('pcs cluster standby 
node1.bcn'), the drbd resource does not failover.


Here are my configs.......


[root at node1 tmp]# pcs config
Cluster Name: cluster1
Corosync Nodes:
  node1.bcn node2.bcn
Pacemaker Nodes:
  node1.bcn node2.bcn

Resources:
  Resource: centos1 (class=ocf provider=heartbeat type=VirtualDomain)
   Attributes: hypervisor=qemu:///system config=/shared/xml/centos1.xml
   Meta Attrs: allow-migration=true
   Operations: start interval=0s timeout=90 (centos1-start-timeout-90)
               stop interval=0s timeout=90 (centos1-stop-timeout-90)
               monitor interval=30 (centos1-monitor-interval-30)
  Master: centos1_drbd_clone
   Meta Attrs: master-max=1 master-node-max=1 clone-max=2 
clone-node-max=1 notify=true
   Resource: centos1_drbd (class=ocf provider=linbit type=drbd)
    Attributes: drbd_resource=drbd1
    Operations: start interval=0s timeout=240 
(centos1_drbd-start-timeout-240)
                promote interval=0s timeout=90 
(centos1_drbd-promote-timeout-90)
                demote interval=0s timeout=90 
(centos1_drbd-demote-timeout-90)
                stop interval=0s timeout=100 (centos1_drbd-stop-timeout-100)
                monitor interval=60s (centos1_drbd-monitor-interval-60s)
                monitor interval=29s role=Master 
(centos1_drbd-monitor-interval-29s-role-Master)
                monitor interval=31s role=Slave 
(centos1_drbd-monitor-interval-31s-role-Slave)

Stonith Devices:
  Resource: fence_n01_ipmi (class=stonith type=fence_ipmilan)
   Attributes: pcmk_host_list=node1.bcn ipaddr=node1.ipmi action=reboot 
login=<username> passwd=<password> auth=password lanplus=1 delay=15
   Operations: monitor interval=60s (fence_n01_ipmi-monitor-interval-60s)
  Resource: fence_n02_ipmi (class=stonith type=fence_ipmilan)
   Attributes: pcmk_host_list=node2.bcn ipaddr=node2.ipmi action=reboot 
login=<username> passwd=<password> auth=password lanplus=1
   Operations: monitor interval=60s (fence_n02_ipmi-monitor-interval-60s)
Fencing Levels:

Location Constraints:
Ordering Constraints:
   promote centos1_drbd_clone then start centos1 (kind:Mandatory) 
(id:order-centos1_drbd_clone-centos1-mandatory)
Colocation Constraints:
   centos1 with centos1_drbd_clone (score:INFINITY) 
(with-rsc-role:Master) (id:colocation-centos1-centos1_drbd_clone-INFINITY)

Cluster Properties:
  cluster-infrastructure: cman
  dc-version: 1.1.11-97629de
  last-lrm-refresh: 1424958819
  no-quorum-policy: ignore
  stonith-enabled: true




cat /etc/drbd.d/global_common.conf

global {
     usage-count no;
}

common {
         protocol C;

         handlers {
                 # Hook into Pacemaker's fencing.
                 fence-peer "/usr/lib/drbd/crm-fence-peer.sh";
                 after-resync-target "/usr/lib/drbd/crm-unfence-peer.sh";
         }

         startup {
                 wfc-timeout             300;
                 degr-wfc-timeout        120;
                 outdated-wfc-timeout    120;
         }

         disk {
                 fencing                 resource-only;
         }
}

resource drbd1 {
     meta-disk    internal;
     device        /dev/drbd1;

     net {
         allow-two-primaries;
         after-sb-0pri        discard-zero-changes;
         after-sb-1pri        discard-secondary;
         after-sb-2pri        disconnect;
     }

     syncer {
         rate            30M;
     }

     on node1 {
         address        10.0.10.101:7789;
         disk        /dev/vg0/guest1;
     }

     on node2 {
         address        10.0.10.102:7789;
         disk        /dev/vg0/guest1;
     }
}

-----------------------------------------------------------------

Here is the cluster status after putting node1 into standby.....

Last change: Thu Feb 26 14:09:29 2015
Stack: cman
Current DC: node1.bcn - partition with quorum
Version: 1.1.11-97629de
2 Nodes configured
5 Resources configured


Node node1.bcn: standby
Online: [ node2.bcn ]

  Master/Slave Set: centos1_drbd_clone [centos1_drbd]
      Slaves: [ node2.bcn ]
      Stopped: [ node1.bcn ]
  fence_n01_ipmi    (stonith:fence_ipmilan):    Started node2.bcn
  fence_n02_ipmi    (stonith:fence_ipmilan):    Started node2.bcn

Failed actions:
     centos1_drbd_promote_0 on node2.bcn 'unknown error' (1): call=109, 
status=Timed Out, last-rc-change='Thu Feb 26 14:07:58 2015', queued=0ms, 
exec=90002ms






Here is a snippet from corosync.log on node1.bcn when I put node1.bcn 
into standby....



Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section nodes to master 
(origin=local/crm_attribute/4)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.99.4 2
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.0 bd4c01cddf69be50ee49e7a641c3b579
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @epoch=100, @num_updates=0
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
++ 
/cib/configuration/nodes/node[@id='node1.bcn']/instance_attributes[@id='nodes-node1.bcn']: 
<nvpair id="nodes-node1.bcn-standby" name="standby" value="on"/>
Feb 26 14:07:52 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
nodes-node1.bcn-standby, standby=on: Non-status change (create 
cib=0.100.0, source=te_update_diff:383, 
path=/cib/configuration/nodes/node[@id='node1.bcn']/instance_attributes[@id='nodes-node1.bcn'], 
1)
Feb 26 14:07:52 [10146] node1       crmd:   notice: do_state_transition: 
     State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC 
cause=C_FSA_INTERNAL origin=abort_transition_graph ]
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section nodes: OK (rc=0, 
origin=node1.bcn/crm_attribute/4, version=0.100.0)
Feb 26 14:07:52 [10142] node1 stonith-ng:     info: xml_apply_patchset: 
     v2 digest mis-match: expected bd4c01cddf69be50ee49e7a641c3b579, 
calculated 349c52472e4e6a3d7d93f3b6bee16267
Feb 26 14:07:52 [10142] node1 stonith-ng:   notice: update_cib_cache_cb: 
     [cib_diff_notify] Patch aborted: Application of an update diff 
failed (-206)
Feb 26 14:07:52 [10142] node1 stonith-ng:     info: update_cib_cache_cb: 
     Updating stonith device and topology lists now that stonith is enabled
Feb 26 14:07:52 [10142] node1 stonith-ng:     info: cib_devices_update: 
     Updating devices to version 0.100.0
Feb 26 14:07:52 [10142] node1 stonith-ng:   notice: unpack_config:     
On loss of CCM Quorum: Ignore
Feb 26 14:07:52 [10145] node1    pengine:   notice: unpack_config:     
On loss of CCM Quorum: Ignore
Feb 26 14:07:52 [10145] node1    pengine:     info: 
determine_online_status_fencing:     Node node2.bcn is active
Feb 26 14:07:52 [10145] node1    pengine:     info: 
determine_online_status:     Node node2.bcn is online
Feb 26 14:07:52 [10145] node1    pengine:     info: unpack_status:     
Node node1.bcn is in standby-mode
Feb 26 14:07:52 [10145] node1    pengine:     info: 
determine_online_status_fencing:     Node node1.bcn is active
Feb 26 14:07:52 [10145] node1    pengine:     info: 
determine_online_status:     Node node1.bcn is standby
Feb 26 14:07:52 [10145] node1    pengine:     info: determine_op_status: 
     Operation monitor found resource centos1_drbd:0 active on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: determine_op_status: 
     Operation monitor found resource centos1_drbd:1 active in master 
mode on node1.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: determine_op_status: 
     Operation monitor found resource centos1_drbd:1 active in master 
mode on node1.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: native_print:     
centos1    (ocf::heartbeat:VirtualDomain):    Started node1.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: clone_print: 
  Master/Slave Set: centos1_drbd_clone [centos1_drbd]
Feb 26 14:07:52 [10145] node1    pengine:     info: short_print:      
Masters: [ node1.bcn ]
Feb 26 14:07:52 [10145] node1    pengine:     info: short_print:      
Slaves: [ node2.bcn ]
Feb 26 14:07:52 [10145] node1    pengine:     info: native_print:     
fence_n01_ipmi    (stonith:fence_ipmilan):    Started node1.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: native_print:     
fence_n02_ipmi    (stonith:fence_ipmilan):    Started node1.bcn
Feb 26 14:07:52 [10141] node1        cib:     info: write_cib_contents: 
     Archived previous version as /var/lib/pacemaker/cib/cib-0.raw
Feb 26 14:07:52 [10145] node1    pengine:     info: native_color:     
Resource centos1_drbd:1 cannot run anywhere
Feb 26 14:07:52 [10145] node1    pengine:     info: master_color:     
Promoting centos1_drbd:0 (Slave node2.bcn)
Feb 26 14:07:52 [10145] node1    pengine:     info: master_color:     
centos1_drbd_clone: Promoted 1 instances of a possible 1 to master
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (30s) for centos1 on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp: 
Cancelling action centos1_drbd:0_monitor_60000 (Slave vs. Master)
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (29s) for centos1_drbd:0 on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp: 
Cancelling action centos1_drbd:0_monitor_31000 (Slave vs. Master)
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp: 
Cancelling action centos1_drbd:0_monitor_60000 (Slave vs. Master)
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (29s) for centos1_drbd:0 on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp: 
Cancelling action centos1_drbd:0_monitor_31000 (Slave vs. Master)
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (60s) for fence_n01_ipmi on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (60s) for fence_n02_ipmi on node2.bcn
Feb 26 14:07:52 [10145] node1    pengine:   notice: LogActions: Move    
centos1    (Started node1.bcn -> node2.bcn)
Feb 26 14:07:52 [10145] node1    pengine:   notice: LogActions: Promote 
centos1_drbd:0    (Slave -> Master node2.bcn)
Feb 26 14:07:52 [10145] node1    pengine:   notice: LogActions: Demote  
centos1_drbd:1    (Master -> Stopped node1.bcn)
Feb 26 14:07:52 [10145] node1    pengine:   notice: LogActions: Move    
fence_n01_ipmi    (Started node1.bcn -> node2.bcn)
Feb 26 14:07:52 [10145] node1    pengine:   notice: LogActions: Move    
fence_n02_ipmi    (Started node1.bcn -> node2.bcn)
Feb 26 14:07:52 [10141] node1        cib:     info: write_cib_contents: 
     Wrote version 0.100.0 of the CIB to disk (digest: 
b31601df4bf6ec81a8204edc2b5c1223)
Feb 26 14:07:52 [10141] node1        cib:     info: retrieveCib: Reading 
cluster configuration from: /var/lib/pacemaker/cib/cib.Qr9JBB (digest: 
/var/lib/pacemaker/cib/cib.hUptro)
Feb 26 14:07:52 [10145] node1    pengine:   notice: process_pe_message: 
     Calculated Transition 69: /var/lib/pacemaker/pengine/pe-input-139.bz2
Feb 26 14:07:52 [10146] node1       crmd:     info: do_state_transition: 
     State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ 
input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Feb 26 14:07:52 [10146] node1       crmd:     info: do_te_invoke:     
Processing graph 69 (ref=pe_calc-dc-1424959672-288) derived from 
/var/lib/pacemaker/pengine/pe-input-139.bz2
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 11: stop centos1_stop_0 on node1.bcn (local)
Feb 26 14:07:52 [10143] node1       lrmd:     info: 
cancel_recurring_action:     Cancelling operation centos1_monitor_30000
Feb 26 14:07:52 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=11:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_stop_0
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1 action:stop call_id:133
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 2: cancel centos1_drbd_monitor_60000 on node2.bcn
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 1: cancel centos1_drbd_monitor_31000 on node2.bcn
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 44: stop fence_n01_ipmi_stop_0 on node1.bcn (local)
Feb 26 14:07:52 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=44:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n01_ipmi_stop_0
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:fence_n01_ipmi action:stop call_id:135
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 47: stop fence_n02_ipmi_stop_0 on node1.bcn (local)
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:fence_n01_ipmi action:stop call_id:135 exit-code:0 
exec-time:1ms queue-time:0ms
Feb 26 14:07:52 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=47:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n02_ipmi_stop_0
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.0 2
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.1 (null)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_monitor_60000']
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=1
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:fence_n02_ipmi action:stop call_id:137
Feb 26 14:07:52 [10146] node1       crmd:     info: process_lrm_event: 
     Operation centos1_monitor_30000: Cancelled (node=node1.bcn, 
call=118, confirmed=true)
Feb 26 14:07:52 [10146] node1       crmd:     info: process_lrm_event: 
     Operation fence_n01_ipmi_monitor_60000: Cancelled (node=node1.bcn, 
call=86, confirmed=true)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/76, version=0.100.1)
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:fence_n02_ipmi action:stop call_id:137 exit-code:0 
exec-time:0ms queue-time:1ms
Feb 26 14:07:52 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation fence_n01_ipmi_stop_0: ok (node=node1.bcn, call=135, 
rc=0, cib-update=242, confirmed=true)
Feb 26 14:07:52 [10146] node1       crmd:     info: process_lrm_event: 
     Operation fence_n02_ipmi_monitor_60000: Cancelled (node=node1.bcn, 
call=92, confirmed=true)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.1 2
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.2 (null)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_monitor_31000']
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=2
Feb 26 14:07:52 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation fence_n02_ipmi_stop_0: ok (node=node1.bcn, call=137, 
rc=0, cib-update=243, confirmed=true)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/77, version=0.100.2)
Feb 26 14:07:52 [10146] node1       crmd:     info: te_update_diff:     
Cancellation of centos1_drbd_monitor_60000 on node2.bcn confirmed (2)
Feb 26 14:07:52 [10146] node1       crmd:     info: te_update_diff:     
Cancellation of centos1_drbd_monitor_31000 on node2.bcn confirmed (1)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/242)
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 60: notify centos1_drbd_pre_notify_demote_0 on node2.bcn
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 62: notify centos1_drbd_pre_notify_demote_0 on 
node1.bcn (local)
Feb 26 14:07:52 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=62:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/243)
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:138
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.2 2
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.3 (null)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=3
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']/lrm_rsc_op[@id='fence_n01_ipmi_last_0']: 
@operation_key=fence_n01_ipmi_stop_0, @operation=stop, 
@transition-key=44:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;44:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=135, @last-run=1424959672, @last-rc-change=1424959672, @exec-time=1
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/242, version=0.100.3)
Feb 26 14:07:52 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n01_ipmi_stop_0 (44) confirmed on node1.bcn (rc=0)
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 45: start fence_n01_ipmi_start_0 on node2.bcn
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.3 2
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.4 (null)
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=4
Feb 26 14:07:52 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']/lrm_rsc_op[@id='fence_n02_ipmi_last_0']: 
@operation_key=fence_n02_ipmi_stop_0, @operation=stop, 
@transition-key=47:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;47:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=137, @last-run=1424959672, @last-rc-change=1424959672, 
@exec-time=0, @queue-time=1
Feb 26 14:07:52 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/243, version=0.100.4)
Feb 26 14:07:52 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n02_ipmi_stop_0 (47) confirmed on node1.bcn (rc=0)
Feb 26 14:07:52 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 48: start fence_n02_ipmi_start_0 on node2.bcn
Feb 26 14:07:52 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1_drbd action:notify call_id:138 pid:34987 
exit-code:0 exec-time:52ms queue-time:0ms
Feb 26 14:07:52 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (62) confirmed on node1.bcn (rc=0)
Feb 26 14:07:52 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node1.bcn, call=138, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:52 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (60) confirmed on node2.bcn (rc=0)
VirtualDomain(centos1)[34984]:    2015/02/26_14:07:52 INFO: Issuing 
graceful shutdown request for domain centos1.
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.4 2
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.5 (null)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=5
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']/lrm_rsc_op[@id='fence_n01_ipmi_last_0']: 
@operation_key=fence_n01_ipmi_start_0, @operation=start, 
@transition-key=45:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;45:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=101, @rc-code=0, @last-run=1424959672, 
@last-rc-change=1424959672, @exec-time=80
Feb 26 14:07:53 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/78, version=0.100.5)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.5 2
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.6 (null)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=6
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']/lrm_rsc_op[@id='fence_n02_ipmi_last_0']: 
@operation_key=fence_n02_ipmi_start_0, @operation=start, 
@transition-key=48:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;48:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=102, @rc-code=0, @last-run=1424959672, 
@last-rc-change=1424959672, @exec-time=84
Feb 26 14:07:53 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n01_ipmi_start_0 (45) confirmed on node2.bcn (rc=0)
Feb 26 14:07:53 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 46: monitor fence_n01_ipmi_monitor_60000 on node2.bcn
Feb 26 14:07:53 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/79, version=0.100.6)
Feb 26 14:07:53 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n02_ipmi_start_0 (48) confirmed on node2.bcn (rc=0)
Feb 26 14:07:53 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 49: monitor fence_n02_ipmi_monitor_60000 on node2.bcn
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.6 2
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.7 (null)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=7
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']: 
<lrm_rsc_op id="fence_n01_ipmi_monitor_60000" 
operation_key="fence_n01_ipmi_monitor_60000" operation="monitor" 
crm-debug-origin="do_update_resource" crm_feature_set="3.0.9" 
transition-key="46:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
transition-magic="0:0;46:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
call-id="103" rc-code="0
Feb 26 14:07:53 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/80, version=0.100.7)
Feb 26 14:07:53 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n01_ipmi_monitor_60000 (46) confirmed on node2.bcn (rc=0)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.7 2
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.8 (null)
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=8
Feb 26 14:07:53 [10141] node1        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']: 
<lrm_rsc_op id="fence_n02_ipmi_monitor_60000" 
operation_key="fence_n02_ipmi_monitor_60000" operation="monitor" 
crm-debug-origin="do_update_resource" crm_feature_set="3.0.9" 
transition-key="49:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
transition-magic="0:0;49:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
call-id="104" rc-code="0
Feb 26 14:07:53 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/81, version=0.100.8)
Feb 26 14:07:53 [10146] node1       crmd:     info: match_graph_event: 
     Action fence_n02_ipmi_monitor_60000 (49) confirmed on node2.bcn (rc=0)
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1 action:stop call_id:133 pid:34984 exit-code:0 
exec-time:5324ms queue-time:0ms
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_stop_0: ok (node=node1.bcn, call=133, rc=0, 
cib-update=244, confirmed=true)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/244)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.8 2
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.9 (null)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=9
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1']/lrm_rsc_op[@id='centos1_last_0']: 
@operation_key=centos1_stop_0, @operation=stop, 
@transition-key=11:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;11:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=133, @last-run=1424959672, @last-rc-change=1424959672, 
@exec-time=5324
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/244, version=0.100.9)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_stop_0 (11) confirmed on node1.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 18: demote centos1_drbd_demote_0 on node1.bcn (local)
Feb 26 14:07:58 [10143] node1       lrmd:     info: 
cancel_recurring_action:     Cancelling operation centos1_drbd_monitor_29000
Feb 26 14:07:58 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=18:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_demote_0
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:demote call_id:140
Feb 26 14:07:58 [10146] node1       crmd:     info: process_lrm_event: 
     Operation centos1_drbd_monitor_29000: Cancelled (node=node1.bcn, 
call=129, confirmed=true)
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     node1.bcn-centos1_drbd_monitor_29000:129 [ \n ]
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1_drbd action:demote call_id:140 pid:35097 
exit-code:0 exec-time:62ms queue-time:0ms
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_demote_0: ok (node=node1.bcn, call=140, 
rc=0, cib-update=245, confirmed=true)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/245)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.9 2
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.10 (null)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=10
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_demote_0, @operation=demote, 
@transition-key=18:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;18:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=140, @rc-code=0, @last-run=1424959678, 
@last-rc-change=1424959678, @exec-time=62, @queue-time=0
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/245, version=0.100.10)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_demote_0 (18) confirmed on node1.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 61: notify centos1_drbd_post_notify_demote_0 on node2.bcn
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 63: notify centos1_drbd_post_notify_demote_0 on 
node1.bcn (local)
Feb 26 14:07:58 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=63:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:141
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1_drbd action:notify call_id:141 pid:35129 
exit-code:0 exec-time:79ms queue-time:0ms
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (63) confirmed on node1.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node1.bcn, call=141, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (61) confirmed on node2.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 55: notify centos1_drbd_pre_notify_stop_0 on node2.bcn
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 57: notify centos1_drbd_pre_notify_stop_0 on node1.bcn 
(local)
Feb 26 14:07:58 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=57:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:142
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1_drbd action:notify call_id:142 pid:35156 
exit-code:0 exec-time:50ms queue-time:0ms
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (57) confirmed on node1.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node1.bcn, call=142, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (55) confirmed on node2.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 19: stop centos1_drbd_stop_0 on node1.bcn (local)
Feb 26 14:07:58 [10146] node1       crmd:     info: do_lrm_rsc_op:     
Performing key=19:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_stop_0
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:stop call_id:143
Feb 26 14:07:58 [10144] node1      attrd:   notice: 
attrd_trigger_update:     Sending flush op to all hosts for: 
master-centos1_drbd (<null>)
Feb 26 14:07:58 [10144] node1      attrd:   notice: 
attrd_perform_update:     Sent delete 193: node=node1.bcn, 
attr=master-centos1_drbd, id=<n/a>, set=(null), section=status
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_delete operation for section status to master 
(origin=local/attrd/193)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.10 2
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.11 (null)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node1.bcn']/transient_attributes[@id='node1.bcn']/instance_attributes[@id='status-node1.bcn']/nvpair[@id='status-node1.bcn-master-centos1_drbd']
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=11
Feb 26 14:07:58 [10143] node1       lrmd:     info: log_finished:     
finished - rsc:centos1_drbd action:stop call_id:143 pid:35178 
exit-code:0 exec-time:130ms queue-time:0ms
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/193, version=0.100.11)
Feb 26 14:07:58 [10146] node1       crmd:   notice: 
abort_transition_graph:     Transition aborted by deletion of 
nvpair[@id='status-node1.bcn-master-centos1_drbd']: Transient attribute 
change (cib=0.100.11, source=te_update_diff:391, 
path=/cib/status/node_state[@id='node1.bcn']/transient_attributes[@id='node1.bcn']/instance_attributes[@id='status-node1.bcn']/nvpair[@id='status-node1.bcn-master-centos1_drbd'], 
0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_stop_0: ok (node=node1.bcn, call=143, rc=0, 
cib-update=246, confirmed=true)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/246)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/126, version=0.100.11)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.11 2
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.12 (null)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=12
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_stop_0, @operation=stop, 
@transition-key=19:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;19:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=143, @exec-time=130
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/246, version=0.100.12)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_stop_0 (19) confirmed on node1.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 56: notify centos1_drbd_post_notify_stop_0 on node2.bcn
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.12 2
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.13 (null)
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=13
Feb 26 14:07:58 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-master-centos1_drbd']: 
@value=1000
Feb 26 14:07:58 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/128, version=0.100.13)
Feb 26 14:07:58 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-master-centos1_drbd, master-centos1_drbd=1000: 
Transient attribute change (modify cib=0.100.13, 
source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-master-centos1_drbd'], 
0)
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (56) confirmed on node2.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: run_graph: 
Transition 69 (Complete=30, Pending=0, Fired=0, Skipped=9, Incomplete=4, 
Source=/var/lib/pacemaker/pengine/pe-input-139.bz2): Stopped
Feb 26 14:07:58 [10146] node1       crmd:     info: do_state_transition: 
     State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ 
input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ]
Feb 26 14:07:58 [10145] node1    pengine:   notice: unpack_config:     
On loss of CCM Quorum: Ignore
Feb 26 14:07:58 [10145] node1    pengine:     info: 
determine_online_status_fencing:     Node node2.bcn is active
Feb 26 14:07:58 [10145] node1    pengine:     info: 
determine_online_status:     Node node2.bcn is online
Feb 26 14:07:58 [10145] node1    pengine:     info: unpack_status:     
Node node1.bcn is in standby-mode
Feb 26 14:07:58 [10145] node1    pengine:     info: 
determine_online_status_fencing:     Node node1.bcn is active
Feb 26 14:07:58 [10145] node1    pengine:     info: 
determine_online_status:     Node node1.bcn is standby
Feb 26 14:07:58 [10145] node1    pengine:     info: determine_op_status: 
     Operation monitor found resource centos1_drbd:0 active on node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: determine_op_status: 
     Operation monitor found resource centos1_drbd:1 active in master 
mode on node1.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: native_print:     
centos1    (ocf::heartbeat:VirtualDomain):    Stopped
Feb 26 14:07:58 [10145] node1    pengine:     info: clone_print: 
  Master/Slave Set: centos1_drbd_clone [centos1_drbd]
Feb 26 14:07:58 [10145] node1    pengine:     info: short_print:      
Slaves: [ node2.bcn ]
Feb 26 14:07:58 [10145] node1    pengine:     info: short_print:      
Stopped: [ node1.bcn ]
Feb 26 14:07:58 [10145] node1    pengine:     info: native_print:     
fence_n01_ipmi    (stonith:fence_ipmilan):    Started node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: native_print:     
fence_n02_ipmi    (stonith:fence_ipmilan):    Started node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: native_color:     
Resource centos1_drbd:1 cannot run anywhere
Feb 26 14:07:58 [10145] node1    pengine:     info: master_color:     
Promoting centos1_drbd:0 (Slave node2.bcn)
Feb 26 14:07:58 [10145] node1    pengine:     info: master_color:     
centos1_drbd_clone: Promoted 1 instances of a possible 1 to master
Feb 26 14:07:58 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (30s) for centos1 on node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (29s) for centos1_drbd:0 on node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:     info: RecurringOp:  Start 
recurring monitor (29s) for centos1_drbd:0 on node2.bcn
Feb 26 14:07:58 [10145] node1    pengine:   notice: LogActions: Start   
centos1    (node2.bcn)
Feb 26 14:07:58 [10145] node1    pengine:   notice: LogActions: Promote 
centos1_drbd:0    (Slave -> Master node2.bcn)
Feb 26 14:07:58 [10145] node1    pengine:     info: LogActions: Leave   
centos1_drbd:1    (Stopped)
Feb 26 14:07:58 [10145] node1    pengine:     info: LogActions: Leave   
fence_n01_ipmi    (Started node2.bcn)
Feb 26 14:07:58 [10145] node1    pengine:     info: LogActions: Leave   
fence_n02_ipmi    (Started node2.bcn)
Feb 26 14:07:58 [10145] node1    pengine:   notice: process_pe_message: 
     Calculated Transition 70: /var/lib/pacemaker/pengine/pe-input-140.bz2
Feb 26 14:07:58 [10146] node1       crmd:     info: do_state_transition: 
     State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ 
input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Feb 26 14:07:58 [10146] node1       crmd:     info: do_te_invoke:     
Processing graph 70 (ref=pe_calc-dc-1424959678-310) derived from 
/var/lib/pacemaker/pengine/pe-input-140.bz2
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 49: notify centos1_drbd_pre_notify_promote_0 on node2.bcn
Feb 26 14:07:58 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (49) confirmed on node2.bcn (rc=0)
Feb 26 14:07:58 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 11: promote centos1_drbd_promote_0 on node2.bcn
Feb 26 14:08:03 [10141] node1        cib:     info: cib_process_ping: 
     Reporting our current digest to node1.bcn: 
1c019a2b8538206ae895683d59879068 for 0.100.13 (0xba24c0 0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.13 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.14 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=14
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_failure_0']: 
@operation_key=centos1_drbd_promote_0, @operation=promote, 
@transition-key=11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=109, @rc-code=1, @op-status=2, @last-run=1424959678, 
@last-rc-change=1424959678, @exe
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_promote_0, @operation=promote, 
@transition-key=11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=109, @rc-code=1, @op-status=2, @last-run=1424959678, 
@last-rc-change=1424959678, @exec-time=9
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/82, version=0.100.14)
Feb 26 14:09:28 [10146] node1       crmd:  warning: status_from_rc:     
Action 11 (centos1_drbd_promote_0) on node2.bcn failed (target: 0 vs. 
rc: 1): Error
Feb 26 14:09:28 [10146] node1       crmd:  warning: update_failcount: 
     Updating failcount for centos1_drbd on node2.bcn after failed 
promote: rc=1 (update=value++, time=1424959768)
Feb 26 14:09:28 [10146] node1       crmd:   notice: 
abort_transition_graph:     Transition aborted by centos1_drbd_promote_0 
'modify' on (null): Event failed 
(magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, cib=0.100.14, 
source=match_graph_event:344, 0)
Feb 26 14:09:28 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_promote_0 (11) confirmed on node2.bcn (rc=4)
Feb 26 14:09:28 [10146] node1       crmd:  warning: update_failcount: 
     Updating failcount for centos1_drbd on node2.bcn after failed 
promote: rc=1 (update=value++, time=1424959768)
Feb 26 14:09:28 [10146] node1       crmd:     info: process_graph_event: 
     Detected action (70.11) centos1_drbd_promote_0.109=unknown error: 
failed
Feb 26 14:09:28 [10146] node1       crmd:  warning: status_from_rc:     
Action 11 (centos1_drbd_promote_0) on node2.bcn failed (target: 0 vs. 
rc: 1): Error
Feb 26 14:09:28 [10146] node1       crmd:  warning: update_failcount: 
     Updating failcount for centos1_drbd on node2.bcn after failed 
promote: rc=1 (update=value++, time=1424959768)
Feb 26 14:09:28 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by centos1_drbd_promote_0 
'modify' on node2.bcn: Event failed 
(magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, cib=0.100.14, 
source=match_graph_event:344, 0)
Feb 26 14:09:28 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_promote_0 (11) confirmed on node2.bcn (rc=4)
Feb 26 14:09:28 [10146] node1       crmd:  warning: update_failcount: 
     Updating failcount for centos1_drbd on node2.bcn after failed 
promote: rc=1 (update=value++, time=1424959768)
Feb 26 14:09:28 [10146] node1       crmd:     info: process_graph_event: 
     Detected action (70.11) centos1_drbd_promote_0.109=unknown error: 
failed
Feb 26 14:09:28 [10146] node1       crmd:   notice: te_rsc_command:     
Initiating action 50: notify centos1_drbd_post_notify_promote_0 on node2.bcn
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.14 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.15 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=15
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']: 
<nvpair id="status-node2.bcn-fail-count-centos1_drbd" 
name="fail-count-centos1_drbd" value="1"/>
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/130, version=0.100.15)
Feb 26 14:09:28 [10146] node1       crmd:   notice: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-fail-count-centos1_drbd, fail-count-centos1_drbd=1: 
Transient attribute change (create cib=0.100.15, 
source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn'], 
0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.15 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.16 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=16
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']: 
<nvpair id="status-node2.bcn-last-failure-centos1_drbd" 
name="last-failure-centos1_drbd" value="1424959768"/>
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/132, version=0.100.16)
Feb 26 14:09:28 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-last-failure-centos1_drbd, 
last-failure-centos1_drbd=1424959768: Transient attribute change (create 
cib=0.100.16, source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn'], 
0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.16 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.17 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=17
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/134, version=0.100.17)
Feb 26 14:09:28 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-fail-count-centos1_drbd, fail-count-centos1_drbd=2: 
Transient attribute change (modify cib=0.100.17, 
source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd'], 
0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/136, version=0.100.17)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/198)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.17 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.18 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=18
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=3
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/138, version=0.100.18)
Feb 26 14:09:28 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-fail-count-centos1_drbd, fail-count-centos1_drbd=3: 
Transient attribute change (modify cib=0.100.18, 
source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd'], 
0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/198, version=0.100.18)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/201)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: --- 0.100.18 2
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
Diff: +++ 0.100.19 (null)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=19
Feb 26 14:09:28 [10141] node1        cib:     info: cib_perform_op:     
+ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=4
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/140, version=0.100.19)
Feb 26 14:09:28 [10146] node1       crmd:     info: 
abort_transition_graph:     Transition aborted by 
status-node2.bcn-fail-count-centos1_drbd, fail-count-centos1_drbd=4: 
Transient attribute change (modify cib=0.100.19, 
source=te_update_diff:391, 
path=/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd'], 
0)
Feb 26 14:09:28 [10141] node1        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/201, version=0.100.19)
Feb 26 14:09:28 [10146] node1       crmd:     info: match_graph_event: 
     Action centos1_drbd_notify_0 (50) confirmed on node2.bcn (rc=0)
Feb 26 14:09:28 [10146] node1       crmd:   notice: run_graph: 
Transition 70 (Complete=9, Pending=0, Fired=0, Skipped=3, Incomplete=0, 
Source=/var/lib/pacemaker/pengine/pe-input-140.bz2): Stopped
Feb 26 14:09:28 [10146] node1       crmd:     info: do_state_transition: 
     State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ 
input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ]




...And here is the corosync.log from node2.bcn......


Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.99.4 2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.0 bd4c01cddf69be50ee49e7a641c3b579
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @epoch=100, @num_updates=0
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
++ 
/cib/configuration/nodes/node[@id='node1.bcn']/instance_attributes[@id='nodes-node1.bcn']: 
<nvpair id="nodes-node1.bcn-standby" name="standby" value="on"/>
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section nodes: OK (rc=0, 
origin=node1.bcn/crm_attribute/4, version=0.100.0)
Feb 26 14:07:52 [3355] node2 stonith-ng:     info: xml_apply_patchset: 
     v2 digest mis-match: expected bd4c01cddf69be50ee49e7a641c3b579, 
calculated 349c52472e4e6a3d7d93f3b6bee16267
Feb 26 14:07:52 [3355] node2 stonith-ng:   notice: update_cib_cache_cb: 
     [cib_diff_notify] Patch aborted: Application of an update diff 
failed (-206)
Feb 26 14:07:52 [3354] node2        cib:     info: write_cib_contents: 
     Archived previous version as /var/lib/pacemaker/cib/cib-1.raw
Feb 26 14:07:52 [3355] node2 stonith-ng:     info: update_cib_cache_cb: 
     Updating stonith device and topology lists now that stonith is enabled
Feb 26 14:07:52 [3355] node2 stonith-ng:     info: cib_devices_update: 
     Updating devices to version 0.100.0
Feb 26 14:07:52 [3355] node2 stonith-ng:   notice: unpack_config:     On 
loss of CCM Quorum: Ignore
Feb 26 14:07:52 [3354] node2        cib:     info: write_cib_contents: 
     Wrote version 0.100.0 of the CIB to disk (digest: 
b31601df4bf6ec81a8204edc2b5c1223)
Feb 26 14:07:52 [3354] node2        cib:     info: retrieveCib: Reading 
cluster configuration from: /var/lib/pacemaker/cib/cib.vgSQL5 (digest: 
/var/lib/pacemaker/cib/cib.91LIj8)
Feb 26 14:07:52 [3356] node2       lrmd:     info: 
cancel_recurring_action:     Cancelling operation centos1_drbd_monitor_60000
Feb 26 14:07:52 [3359] node2       crmd:     info: process_lrm_event: 
     Operation centos1_drbd_monitor_60000: Cancelled (node=node2.bcn, 
call=97, confirmed=true)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_delete operation for section status to master 
(origin=local/crmd/76)
Feb 26 14:07:52 [3356] node2       lrmd:     info: 
cancel_recurring_action:     Cancelling operation centos1_drbd_monitor_31000
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.0 2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.1 (null)
Feb 26 14:07:52 [3359] node2       crmd:     info: process_lrm_event: 
     Operation centos1_drbd_monitor_31000: Cancelled (node=node2.bcn, 
call=96, confirmed=true)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_monitor_60000']
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=1
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/76, version=0.100.1)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_delete operation for section status to master 
(origin=local/crmd/77)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.1 2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.2 (null)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_monitor_31000']
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/77, version=0.100.2)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.2 2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.3 (null)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=3
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']/lrm_rsc_op[@id='fence_n01_ipmi_last_0']: 
@operation_key=fence_n01_ipmi_stop_0, @operation=stop, 
@transition-key=44:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;44:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=135, @last-run=1424959672, @last-rc-change=1424959672, @exec-time=1
Feb 26 14:07:52 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=60:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/242, version=0.100.3)
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:100
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.3 2
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.4 (null)
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=4
Feb 26 14:07:52 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']/lrm_rsc_op[@id='fence_n02_ipmi_last_0']: 
@operation_key=fence_n02_ipmi_stop_0, @operation=stop, 
@transition-key=47:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;47:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=137, @last-run=1424959672, @last-rc-change=1424959672, 
@exec-time=0, @queue-time=1
Feb 26 14:07:52 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/243, version=0.100.4)
Feb 26 14:07:52 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=45:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n01_ipmi_start_0
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:fence_n01_ipmi action:start call_id:101
Feb 26 14:07:52 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=48:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n02_ipmi_start_0
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:fence_n02_ipmi action:start call_id:102
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:100 pid:14953 
exit-code:0 exec-time:52ms queue-time:0ms
Feb 26 14:07:52 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=100, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:fence_n01_ipmi action:start call_id:101  exit-code:0 
exec-time:80ms queue-time:0ms
Feb 26 14:07:52 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:fence_n02_ipmi action:start call_id:102  exit-code:0 
exec-time:84ms queue-time:0ms
Feb 26 14:07:53 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation fence_n01_ipmi_start_0: ok (node=node2.bcn, call=101, 
rc=0, cib-update=78, confirmed=true)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/78)
Feb 26 14:07:53 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation fence_n02_ipmi_start_0: ok (node=node2.bcn, call=102, 
rc=0, cib-update=79, confirmed=true)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/79)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.4 2
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.5 (null)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=5
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']/lrm_rsc_op[@id='fence_n01_ipmi_last_0']: 
@operation_key=fence_n01_ipmi_start_0, @operation=start, 
@transition-key=45:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;45:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=101, @rc-code=0, @last-run=1424959672, 
@last-rc-change=1424959672, @exec-time=80
Feb 26 14:07:53 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/78, version=0.100.5)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.5 2
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.6 (null)
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=6
Feb 26 14:07:53 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']/lrm_rsc_op[@id='fence_n02_ipmi_last_0']: 
@operation_key=fence_n02_ipmi_start_0, @operation=start, 
@transition-key=48:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;48:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=102, @rc-code=0, @last-run=1424959672, 
@last-rc-change=1424959672, @exec-time=84
Feb 26 14:07:53 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/79, version=0.100.6)
Feb 26 14:07:53 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=46:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n01_ipmi_monitor_60000
Feb 26 14:07:53 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=49:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=fence_n02_ipmi_monitor_60000
Feb 26 14:07:54 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation fence_n01_ipmi_monitor_60000: ok (node=node2.bcn, 
call=103, rc=0, cib-update=80, confirmed=false)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/80)
Feb 26 14:07:54 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation fence_n02_ipmi_monitor_60000: ok (node=node2.bcn, 
call=104, rc=0, cib-update=81, confirmed=false)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/81)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.6 2
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.7 (null)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=7
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n01_ipmi']: 
<lrm_rsc_op id="fence_n01_ipmi_monitor_60000" 
operation_key="fence_n01_ipmi_monitor_60000" operation="monitor" 
crm-debug-origin="do_update_resource" crm_feature_set="3.0.9" 
transition-key="46:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
transition-magic="0:0;46:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
call-id="103" rc-code="0"
Feb 26 14:07:54 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/80, version=0.100.7)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.7 2
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.8 (null)
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=8
Feb 26 14:07:54 [3354] node2        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='fence_n02_ipmi']: 
<lrm_rsc_op id="fence_n02_ipmi_monitor_60000" 
operation_key="fence_n02_ipmi_monitor_60000" operation="monitor" 
crm-debug-origin="do_update_resource" crm_feature_set="3.0.9" 
transition-key="49:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
transition-magic="0:0;49:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b" 
call-id="104" rc-code="0"
Feb 26 14:07:54 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/81, version=0.100.8)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.8 2
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.9 (null)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=9
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1']/lrm_rsc_op[@id='centos1_last_0']: 
@operation_key=centos1_stop_0, @operation=stop, 
@transition-key=11:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;11:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=133, @last-run=1424959672, @last-rc-change=1424959672, 
@exec-time=5324
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/244, version=0.100.9)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.9 2
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.10 (null)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=10
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_demote_0, @operation=demote, 
@transition-key=18:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;18:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=140, @rc-code=0, @last-run=1424959678, 
@last-rc-change=1424959678, @exec-time=62, @queue-time=0
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/245, version=0.100.10)
Feb 26 14:07:58 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=61:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:105
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:105 pid:14985 
exit-code:0 exec-time:80ms queue-time:0ms
Feb 26 14:07:58 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=105, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=55:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:106
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:106 pid:15012 
exit-code:0 exec-time:50ms queue-time:0ms
Feb 26 14:07:58 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=106, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.10 2
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.11 (null)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
-- 
/cib/status/node_state[@id='node1.bcn']/transient_attributes[@id='node1.bcn']/instance_attributes[@id='status-node1.bcn']/nvpair[@id='status-node1.bcn-master-centos1_drbd']
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=11
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_delete operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/193, version=0.100.11)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/126)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/126, version=0.100.11)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.11 2
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.12 (null)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=12
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node1.bcn']/lrm[@id='node1.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_stop_0, @operation=stop, 
@transition-key=19:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;19:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=143, @exec-time=130
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/crmd/246, version=0.100.12)
Feb 26 14:07:58 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=56:69:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:107
Feb 26 14:07:58 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: master-centos1_drbd (1000)
Feb 26 14:07:58 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 128: master-centos1_drbd=1000
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/128)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.12 2
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.13 (null)
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=13
Feb 26 14:07:58 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-master-centos1_drbd']: 
@value=1000
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:107 pid:15034 
exit-code:0 exec-time:79ms queue-time:0ms
Feb 26 14:07:58 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/128, version=0.100.13)
Feb 26 14:07:58 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=107, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=49:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:108
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:108 pid:15061 
exit-code:0 exec-time:50ms queue-time:0ms
Feb 26 14:07:58 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=108, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:07:58 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_promote_0
Feb 26 14:07:58 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:promote call_id:109
Feb 26 14:08:03 [3354] node2        cib:     info: cib_process_ping:     
Reporting our current digest to node1.bcn: 
1c019a2b8538206ae895683d59879068 for 0.100.13 (0xd1a070 0)
Feb 26 14:09:28 [3356] node2       lrmd:  warning: 
child_timeout_callback:     centos1_drbd_promote_0 process (PID 15083) 
timed out
Feb 26 14:09:28 [3356] node2       lrmd:  warning: operation_finished: 
     centos1_drbd_promote_0:15083 - timed out after 90000ms
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:promote call_id:109 pid:15083 
exit-code:1 exec-time:90002ms queue-time:0ms
Feb 26 14:09:28 [3359] node2       crmd:    error: process_lrm_event: 
     Operation centos1_drbd_promote_0: Timed Out (node=node2.bcn, 
call=109, timeout=90000ms)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/82)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.13 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.14 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=14
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_failure_0']: 
@operation_key=centos1_drbd_promote_0, @operation=promote, 
@transition-key=11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=109, @rc-code=1, @op-status=2, @last-run=1424959678, 
@last-rc-change=1424959678, @exec
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_promote_0, @operation=promote, 
@transition-key=11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=2:1;11:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=109, @rc-code=1, @op-status=2, @last-run=1424959678, 
@last-rc-change=1424959678, @exec-time=90
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/82, version=0.100.14)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: fail-count-centos1_drbd (1)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 130: fail-count-centos1_drbd=1
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/130)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: last-failure-centos1_drbd 
(1424959768)
Feb 26 14:09:28 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=50:70:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 132: last-failure-centos1_drbd=1424959768
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: fail-count-centos1_drbd (2)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.14 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.15 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=15
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']: 
<nvpair id="status-node2.bcn-fail-count-centos1_drbd" 
name="fail-count-centos1_drbd" value="1"/>
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:110
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/130, version=0.100.15)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/132)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 134: fail-count-centos1_drbd=2
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.15 2
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: last-failure-centos1_drbd 
(1424959768)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.16 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=16
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
++ 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']: 
<nvpair id="status-node2.bcn-last-failure-centos1_drbd" 
name="last-failure-centos1_drbd" value="1424959768"/>
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/132, version=0.100.16)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/134)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 136: last-failure-centos1_drbd=1424959768
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.16 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.17 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=17
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=2
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: fail-count-centos1_drbd (3)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/134, version=0.100.17)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/136)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 138: fail-count-centos1_drbd=3
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/136, version=0.100.17)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/138)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_trigger_update: 
     Sending flush op to all hosts for: fail-count-centos1_drbd (4)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.17 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.18 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=18
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=3
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/138, version=0.100.18)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/198, version=0.100.18)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_perform_update: 
     Sent update 140: fail-count-centos1_drbd=4
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/attrd/140)
Feb 26 14:09:28 [3357] node2      attrd:   notice: attrd_cs_dispatch: 
     Update relayed from node1.bcn
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.18 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.19 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=19
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/transient_attributes[@id='node2.bcn']/instance_attributes[@id='status-node2.bcn']/nvpair[@id='status-node2.bcn-fail-count-centos1_drbd']: 
@value=4
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/attrd/140, version=0.100.19)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node1.bcn/attrd/201, version=0.100.19)
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:110 pid:15617 
exit-code:0 exec-time:81ms queue-time:0ms
Feb 26 14:09:28 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=110, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:09:28 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=47:71:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_notify_0
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:notify call_id:111
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:notify call_id:111 pid:15644 
exit-code:0 exec-time:50ms queue-time:0ms
Feb 26 14:09:28 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_notify_0: ok (node=node2.bcn, call=111, 
rc=0, cib-update=0, confirmed=true)
Feb 26 14:09:28 [3359] node2       crmd:     info: do_lrm_rsc_op:     
Performing key=8:71:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b 
op=centos1_drbd_demote_0
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_execute: 
executing - rsc:centos1_drbd action:demote call_id:112
Feb 26 14:09:28 [3356] node2       lrmd:     info: log_finished: 
finished - rsc:centos1_drbd action:demote call_id:112 pid:15666 
exit-code:0 exec-time:53ms queue-time:0ms
Feb 26 14:09:28 [3359] node2       crmd:   notice: process_lrm_event: 
     Operation centos1_drbd_demote_0: ok (node=node2.bcn, call=112, 
rc=0, cib-update=83, confirmed=true)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Forwarding cib_modify operation for section status to master 
(origin=local/crmd/83)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: --- 0.100.19 2
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
Diff: +++ 0.100.20 (null)
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     
+  /cib:  @num_updates=20
Feb 26 14:09:28 [3354] node2        cib:     info: cib_perform_op:     + 
/cib/status/node_state[@id='node2.bcn']/lrm[@id='node2.bcn']/lrm_resources/lrm_resource[@id='centos1_drbd']/lrm_rsc_op[@id='centos1_drbd_last_0']: 
@operation_key=centos1_drbd_demote_0, @operation=demote, 
@transition-key=8:71:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@transition-magic=0:0;8:71:0:d8bfc2ef-dbfa-4871-994d-e562ea8ab63b, 
@call-id=112, @rc-code=0, @op-status=0, @last-run=1424959768, 
@last-rc-change=1424959768, @exec-time=53
Feb 26 14:09:28 [3354] node2        cib:     info: cib_process_request: 
     Completed cib_modify operation for section status: OK (rc=0, 
origin=node2.bcn/crmd/83, version=0.100.20)









More information about the Users mailing list