[Pacemaker] Help understanding why a failover occurred.
Jai
awayatm at gmail.com
Fri Oct 15 22:45:15 UTC 2010
I have setup a DRBD->Xen failover cluster. Last night at around 02:50 it failed the resources from server "bravo" to "alpha". I'm trying to find out what caused the failover of resources. I don't see anything in the logs that indicate the cause but I don't really know what to look for. If someone could help me understand these logs and what I'm looking for would be great. I'm not even sure how far back I need to go.
Thanks.
CONFIG
node alpha \
attributes standby="off"
node bravo \
attributes standby="off"
primitive drbd0 ocf:linbit:drbd \
params drbd_resource="r0" \
op monitor interval="20s" role="Slave" timeout="20s" \
op monitor interval="10s" role="Master" timeout="20s" \
op start interval="0" timeout="240s" \
op stop interval="0" timeout="100s" \
op promote interval="0" timeout="90s" \
op demote interval="0" timeout="90s" \
meta resource-stickiness="1"
primitive drbd1 ocf:linbit:drbd \
params drbd_resource="r1" \
op monitor interval="20s" role="Slave" timeout="20s" \
op monitor interval="10s" role="Master" timeout="20s" \
op start interval="0" timeout="240s" \
op stop interval="0" timeout="100s" \
op promote interval="0" timeout="90s" \
op demote interval="0" timeout="90s" \
meta resource-stickiness="1"
primitive mailAlert ocf:heartbeat:MailTo \
params email="email at domain.com" subject="NOTICE: Square Cluster Event" \
op monitor interval="120" timeout="20" \
op start interval="0" timeout="10" \
op stop interval="0" timeout="10" \
meta target-role="Started"
primitive ping ocf:pacemaker:ping \
op start interval="0" timeout="90s" \
op stop interval="0" timeout="100s" \
op monitor interval="10s" timeout="60s" \
params host_list="12.12.12.1" dampen="5s" attempts="2" name="pingval" multiplier="100"
primitive resMON ocf:pacemaker:ClusterMon \
operations $id="resMON-operations" \
op monitor interval="180" timeout="20" \
op start interval="0" timeout="90" \
op stop interval="0" timeout="100" \
params extra_options="--mail-to <root at localhost>" htmlfile="/tmp/ClusterMon.html" \
meta target-role="Started"
primitive squareDomU ocf:heartbeat:Xen \
params xmfile="/etc/xen/square.sxp" \
op monitor interval="120" timeout="30" on-fail="restart" start-delay="60" \
op start interval="0" timeout="300" \
op stop interval="0" timeout="300" \
op migrate_from interval="0" timeout="240" \
op migrate_to interval="0" timeout="240" \
meta target-role="Started" resource-stickiness="1"
ms squareRoot drbd0 \
meta globally-unique="false" master-max="1" master-node-max="1" clone-max="2" clone-node-max="1" notify="true" target-role="Started"
ms squareTmp drbd1 \
meta globally-unique="false" master-max="1" master-node-max="1" clone-max="2" clone-node-max="1" notify="true" target-role="Started"
clone clonePing ping \
meta globally-unique="false" target-role="Started"
location mailAlert_on_connectedNet mailAlert \
rule $id="mailAlert_on_connectedNet-rule" -inf: not_defined pingval or pingval lte 0
location resMON_on_connectedNet resMON \
rule $id="resMON_on_connectedNet-rule" -inf: not_defined pingval or pingval lte 0
location squareDomU_on_connectedNet squareDomU \
rule $id="squareDomU_on_connectedNet-rule" -inf: not_defined pingval or pingval lte 0
colocation mailAlert-with-squareDomU inf: squareDomU mailAlert
colocation squareDomU-with-squareRoot inf: squareDomU squareRoot:Master
colocation squareDomU-with-squareTmp inf: squareDomU squareTmp:Master
colocation squareTmp-with-squareRoot inf: squareRoot:Master squareTmp:Master
order order-squareRoot-before-squareDomU inf: squareRoot:promote squareDomU:start
order order-squareTmp-and-squareRoot inf: squareTmp:promote squareRoot:promote
property $id="cib-bootstrap-options" \
dc-version="1.0.9-89bd754939df5150de7cd76835f98fe90851b677" \
cluster-infrastructure="openais" \
expected-quorum-votes="2" \
stonith-enabled="false" \
no-quorum-policy="ignore" \
last-lrm-refresh="1284693021"
BRAVO LOGS /var/log/cluster/corosync.log:
<SECTION>
Oct 16 02:33:40 bravo cib: [25096]: info: cib_stats: Processed 120 operations (166.00us average, 0% utilization) in the last 10min
Oct 16 02:35:01 bravo crmd: [25100]: info: crm_timer_popped: PEngine Recheck Timer (I_PE_CALC) just popped!
Oct 16 02:35:01 bravo crmd: [25100]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ]
Oct 16 02:35:01 bravo crmd: [25100]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED
Oct 16 02:35:01 bravo crmd: [25100]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.
Oct 16 02:35:01 bravo crmd: [25100]: info: do_pe_invoke: Query 844: Requesting the current CIB: S_POLICY_ENGINE
Oct 16 02:35:01 bravo crmd: [25100]: info: do_pe_invoke_callback: Invoking the PE: query=844, ref=pe_calc-dc-1287156901-776, seq=10368, quorate=1
Oct 16 02:35:01 bravo pengine: [25099]: notice: unpack_config: On loss of CCM Quorum: Ignore
Oct 16 02:35:01 bravo pengine: [25099]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Oct 16 02:35:01 bravo pengine: [25099]: info: determine_online_status: Node bravo is online
Oct 16 02:35:01 bravo pengine: [25099]: info: determine_online_status: Node alpha is online
Oct 16 02:35:01 bravo pengine: [25099]: notice: native_print: squareDomU (ocf::heartbeat:Xen): Started bravo
Oct 16 02:35:01 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareRoot
Oct 16 02:35:01 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:35:01 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:35:01 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareTmp
Oct 16 02:35:01 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:35:01 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:35:01 bravo pengine: [25099]: notice: native_print: resMON (ocf::pacemaker:ClusterMon): Started alpha
Oct 16 02:35:01 bravo pengine: [25099]: notice: clone_print: Clone Set: clonePing
Oct 16 02:35:01 bravo pengine: [25099]: notice: short_print: Started: [ bravo alpha ]
Oct 16 02:35:01 bravo pengine: [25099]: notice: native_print: mailAlert (ocf::heartbeat:MailTo): Started bravo
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd1:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd1:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd0:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd1:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd0:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: Promoting drbd1:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:35:02 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource squareDomU (Started bravo)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource drbd0:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource drbd0:1 (Slave alpha)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource drbd1:0 (Master bravo)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource drbd1:1 (Slave alpha)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource resMON (Started alpha)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource ping:0 (Started bravo)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource ping:1 (Started alpha)
Oct 16 02:35:02 bravo pengine: [25099]: notice: LogActions: Leave resource mailAlert (Started bravo)
Oct 16 02:35:02 bravo crmd: [25100]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Oct 16 02:35:02 bravo crmd: [25100]: info: unpack_graph: Unpacked transition 712: 0 actions in 0 synapses
Oct 16 02:35:02 bravo crmd: [25100]: info: do_te_invoke: Processing graph 712 (ref=pe_calc-dc-1287156901-776) derived from /var/lib/pengine/pe-input-3736.bz2
Oct 16 02:35:02 bravo crmd: [25100]: info: run_graph: ====================================================
Oct 16 02:35:02 bravo crmd: [25100]: notice: run_graph: Transition 712 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-input-3736.bz2): Complete
Oct 16 02:35:02 bravo crmd: [25100]: info: te_graph_trigger: Transition 712 is now complete
Oct 16 02:35:02 bravo crmd: [25100]: info: notify_crmd: Transition 712 status: done - <null>
Oct 16 02:35:02 bravo crmd: [25100]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Oct 16 02:35:02 bravo crmd: [25100]: info: do_state_transition: Starting PEngine Recheck Timer
Oct 16 02:35:02 bravo pengine: [25099]: info: process_pe_message: Transition 712: PEngine Input stored in: /var/lib/pengine/pe-input-3736.bz2
Oct 16 02:38:29 bravo lrmd: [25097]: info: rsc:squareDomU:42: monitor
Oct 16 02:43:40 bravo cib: [25096]: info: cib_stats: Processed 119 operations (252.00us average, 0% utilization) in the last 10min
Oct 16 02:46:04 bravo attrd: [25098]: info: attrd_trigger_update: Sending flush op to all hosts for: pingval (0)
Oct 16 02:46:04 bravo attrd: [25098]: info: attrd_perform_update: Sent update 161: pingval=0
Oct 16 02:46:04 bravo crmd: [25100]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=1, tag=transient_attributes, id=bravo, magic=NA, cib=0.955.9) : Transient attribute: update
Oct 16 02:46:04 bravo crmd: [25100]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph ]
Oct 16 02:46:04 bravo crmd: [25100]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.
Oct 16 02:46:04 bravo crmd: [25100]: info: do_pe_invoke: Query 845: Requesting the current CIB: S_POLICY_ENGINE
Oct 16 02:46:04 bravo crmd: [25100]: info: do_pe_invoke_callback: Invoking the PE: query=845, ref=pe_calc-dc-1287157564-777, seq=10368, quorate=1
Oct 16 02:46:04 bravo pengine: [25099]: notice: unpack_config: On loss of CCM Quorum: Ignore
Oct 16 02:46:04 bravo pengine: [25099]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Oct 16 02:46:04 bravo pengine: [25099]: info: determine_online_status: Node bravo is online
Oct 16 02:46:04 bravo pengine: [25099]: info: determine_online_status: Node alpha is online
Oct 16 02:46:04 bravo pengine: [25099]: notice: native_print: squareDomU (ocf::heartbeat:Xen): Started bravo
Oct 16 02:46:04 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareRoot
Oct 16 02:46:04 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:46:04 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:46:04 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareTmp
Oct 16 02:46:04 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:46:04 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:46:04 bravo pengine: [25099]: notice: native_print: resMON (ocf::pacemaker:ClusterMon): Started alpha
Oct 16 02:46:04 bravo pengine: [25099]: notice: clone_print: Clone Set: clonePing
Oct 16 02:46:04 bravo pengine: [25099]: notice: short_print: Started: [ bravo alpha ]
Oct 16 02:46:04 bravo pengine: [25099]: notice: native_print: mailAlert (ocf::heartbeat:MailTo): Started bravo
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd0:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd0:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (120s) for squareDomU on alpha
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd0:0 on bravo
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd0:0_monitor_10000 (Master vs. Slave)
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd0:1_monitor_20000 (Slave vs. Master)
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd0:1 on alpha
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd0:0 on bravo
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd0:0_monitor_10000 (Master vs. Slave)
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd0:1_monitor_20000 (Slave vs. Master)
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd0:1 on alpha
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd1:0 on bravo
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd1:0_monitor_10000 (Master vs. Slave)
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd1:1_monitor_20000 (Slave vs. Master)
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd1:1 on alpha
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd1:0 on bravo
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd1:0_monitor_10000 (Master vs. Slave)
Oct 16 02:46:04 bravo pengine: [25099]: info: RecurringOp: Cancelling action drbd1:1_monitor_20000 (Slave vs. Master)
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd1:1 on alpha
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:04 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:04 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (120s) for mailAlert on alpha
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Move resource squareDomU (Started bravo -> alpha)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Demote drbd0:0 (Master -> Slave bravo)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Promote drbd0:1 (Slave -> Master alpha)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Demote drbd1:0 (Master -> Slave bravo)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Promote drbd1:1 (Slave -> Master alpha)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Leave resource resMON (Started alpha)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Leave resource ping:0 (Started bravo)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Leave resource ping:1 (Started alpha)
Oct 16 02:46:04 bravo pengine: [25099]: notice: LogActions: Move resource mailAlert (Started bravo -> alpha)
Oct 16 02:46:04 bravo pengine: [25099]: info: process_pe_message: Transition 713: PEngine Input stored in: /var/lib/pengine/pe-input-3737.bz2Oct 16 02:46:04 bravo crmd: [25100]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Oct 16 02:46:04 bravo crmd: [25100]: info: unpack_graph: Unpacked transition 713: 59 actions in 59 synapses
Oct 16 02:46:04 bravo crmd: [25100]: info: do_te_invoke: Processing graph 713 (ref=pe_calc-dc-1287157564-777) derived from /var/lib/pengine/pe-input-3737.bz2
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 14: stop squareDomU_stop_0 on bravo (local)
Oct 16 02:46:04 bravo lrmd: [25097]: info: cancel_op: operation monitor[42] on ocf::Xen::squareDomU for client 25100, its parameters: CRM_meta_interval=[120000] xmfile=[/etc/xen/square.sxp] CRM_meta_start_delay=[60000] CRM_meta_on_fail=[restart] CRM_meta_timeout=[90000] crm_feature_set=[3.0.1] CRM_meta_name=[monitor] cancelledOct 16 02:46:04 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=14:713:0:a3273222-947d-4891-b5fa-138e2789787a op=squareDomU_stop_0 )
Oct 16 02:46:04 bravo lrmd: [25097]: info: rsc:squareDomU:51: stop
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 5: cancel drbd0:0_monitor_10000 on bravo (local)
Oct 16 02:46:04 bravo lrmd: [25097]: info: cancel_op: operation monitor[41] on ocf::drbd::drbd0:0 for client 25100, its parameters: CRM_meta_interval=[10000] CRM_meta_role=[Master] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_active_resource=[ ] CRM_meta_notify_sla
ve_resource=[ ] CRM_meta_notify_start_resource=[drbd0:0 ] CRM_meta_notify_active_uname=[ ] CRM_meta_notify_promote_resource=[ ] CRM_meta_notify_stop_uname=[ ] drbd_resource=[r0] CRM_meta_notify_master_uname=[alpha ] CRM_meta_master_max=[1] CRM_meta_notify_demote_uname=[
] CRM_meta_notify_master cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: send_direct_ack: ACK'ing resource op drbd0:0_monitor_10000 from 5:713:0:a3273222-947d-4891-b5fa-138e2789787a: lrm_invoke-lrmd-1287157564-780
Oct 16 02:46:04 bravo crmd: [25100]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1287157564-780 from bravoOct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_monitor_10000 (5) confirmed on bravo (rc=0)Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 9: cancel drbd0:1_monitor_20000 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 46 fired and confirmed
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 1: cancel drbd1:0_monitor_10000 on bravo (local)
Oct 16 02:46:04 bravo lrmd: [25097]: info: cancel_op: operation monitor[36] on ocf::drbd::drbd1:0 for client 25100, its parameters: CRM_meta_interval=[10000] CRM_meta_role=[Master] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_active_resource=[ ] CRM_meta_notify_slave_resource=[ ] CRM_meta_notify_start_resource=[drbd1:0 ] CRM_meta_notify_active_uname=[ ] CRM_meta_notify_promote_resource=[ ] CRM_meta_notify_stop_uname=[ ] drbd_resource=[r1] CRM_meta_notify_master_uname=[alpha ] CRM_meta_master_max=[1] CRM_meta_notify_demote_uname=[ ] CRM_meta_notify_master cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: send_direct_ack: ACK'ing resource op drbd1:0_monitor_10000 from 1:713:0:a3273222-947d-4891-b5fa-138e2789787a: lrm_invoke-lrmd-1287157564-783
Oct 16 02:46:04 bravo crmd: [25100]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1287157564-783 from bravo
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_monitor_10000 (1) confirmed on bravo (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 6: cancel drbd1:1_monitor_20000 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 79 fired and confirmed
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 93: stop mailAlert_stop_0 on bravo (local)
Oct 16 02:46:04 bravo lrmd: [25097]: info: cancel_op: operation monitor[50] on ocf::MailTo::mailAlert for client 25100, its parameters: CRM_meta_interval=[120000] CRM_meta_timeout=[20000] email=[hostmaster at ntechhosting.com] crm_feature_set=[3.0.1] subject=[NOTICE: Square Cluster Event] CRM_meta_name=[monitor] cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=93:713:0:a3273222-947d-4891-b5fa-138e2789787a op=mailAlert_stop_0 )
Oct 16 02:46:04 bravo lrmd: [25097]: info: rsc:mailAlert:52: stop
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation squareDomU_monitor_120000 (call=42, status=1, cib-update=0, confirmed=true) Cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_monitor_10000 (call=41, status=1, cib-update=0, confirmed=true) Cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_monitor_10000 (call=36, status=1, cib-update=0, confirmed=true) Cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation mailAlert_monitor_120000 (call=50, status=1, cib-update=0, confirmed=true) Cancelled
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 112: notify drbd0:0_pre_notify_demote_0 on bravo (local)
Oct 16 02:46:04 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=112:713:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_notify_0 )
Oct 16 02:46:04 bravo lrmd: [25097]: info: rsc:drbd0:0:53: notify
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 114: notify drbd0:1_pre_notify_demote_0 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 128: notify drbd1:0_pre_notify_demote_0 on bravo (local)
Oct 16 02:46:04 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=128:713:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_notify_0 )
Oct 16 02:46:04 bravo lrmd: [25097]: info: rsc:drbd1:0:54: notify
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 130: notify drbd1:1_pre_notify_demote_0 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1287157564-7 from alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_monitor_20000 (9) confirmed on alpha (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1287157564-8 from alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_monitor_20000 (6) confirmed on alpha (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation mailAlert_stop_0 (call=52, rc=0, cib-update=848, confirmed=true) ok
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action mailAlert_stop_0 (93) confirmed on bravo (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 94: start mailAlert_start_0 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_notify_0 (call=53, rc=0, cib-update=849, confirmed=true) ok
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_pre_notify_demote_0 (112) confirmed on bravo (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_notify_0 (call=54, rc=0, cib-update=850, confirmed=true) ok
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_pre_notify_demote_0 (128) confirmed on bravo (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_pre_notify_demote_0 (130) confirmed on alpha (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 80 fired and confirmed
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_pre_notify_demote_0 (114) confirmed on alpha (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 47 fired and confirmed
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action mailAlert_start_0 (94) confirmed on alpha (rc=0)
Oct 16 02:46:04 bravo crmd: [25100]: info: te_rsc_command: Initiating action 95: monitor mailAlert_monitor_120000 on alpha
Oct 16 02:46:04 bravo crmd: [25100]: info: match_graph_event: Action mailAlert_monitor_120000 (95) confirmed on alpha (rc=0)
Oct 16 02:46:15 bravo attrd: [25098]: info: attrd_trigger_update: Sending flush op to all hosts for: pingval (100)
Oct 16 02:46:15 bravo attrd: [25098]: info: attrd_perform_update: Sent update 163: pingval=100
Oct 16 02:46:15 bravo crmd: [25100]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=0, tag=transient_attributes, id=bravo, magic=NA, cib=0.955.21) : Transient attribute: update
Oct 16 02:46:15 bravo crmd: [25100]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000
Oct 16 02:46:15 bravo crmd: [25100]: info: update_abort_priority: Abort action done superceeded by restart
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation squareDomU_stop_0 (call=51, rc=0, cib-update=851, confirmed=true) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action squareDomU_stop_0 (14) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: run_graph: ====================================================
Oct 16 02:46:45 bravo crmd: [25100]: notice: run_graph: Transition 713 (Complete=16, Pending=0, Fired=0, Skipped=23, Incomplete=20, Source=/var/lib/pengine/pe-input-3737.bz2): Stopped
Oct 16 02:46:45 bravo crmd: [25100]: info: te_graph_trigger: Transition 713 is now complete
Oct 16 02:46:45 bravo crmd: [25100]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ]
Oct 16 02:46:45 bravo crmd: [25100]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.
Oct 16 02:46:45 bravo crmd: [25100]: info: do_pe_invoke: Query 852: Requesting the current CIB: S_POLICY_ENGINE
Oct 16 02:46:45 bravo crmd: [25100]: info: do_pe_invoke_callback: Invoking the PE: query=852, ref=pe_calc-dc-1287157605-792, seq=10368, quorate=1
Oct 16 02:46:45 bravo pengine: [25099]: notice: unpack_config: On loss of CCM Quorum: Ignore
Oct 16 02:46:45 bravo pengine: [25099]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Oct 16 02:46:45 bravo pengine: [25099]: info: determine_online_status: Node bravo is online
Oct 16 02:46:45 bravo pengine: [25099]: info: determine_online_status: Node alpha is online
Oct 16 02:46:45 bravo pengine: [25099]: notice: native_print: squareDomU (ocf::heartbeat:Xen): Stopped
Oct 16 02:46:45 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareRoot
Oct 16 02:46:45 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:46:45 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:46:45 bravo pengine: [25099]: notice: clone_print: Master/Slave Set: squareTmp
Oct 16 02:46:45 bravo pengine: [25099]: notice: short_print: Masters: [ bravo ]
Oct 16 02:46:45 bravo pengine: [25099]: notice: short_print: Slaves: [ alpha ]
Oct 16 02:46:45 bravo pengine: [25099]: notice: native_print: resMON (ocf::pacemaker:ClusterMon): Started alpha
Oct 16 02:46:45 bravo pengine: [25099]: notice: clone_print: Clone Set: clonePing
Oct 16 02:46:45 bravo pengine: [25099]: notice: short_print: Started: [ bravo alpha ]
Oct 16 02:46:45 bravo pengine: [25099]: notice: native_print: mailAlert (ocf::heartbeat:MailTo): Started alpha
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd0:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd0:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd0:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareRoot: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: Promoting drbd1:1 (Slave alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: master_color: squareTmp: Promoted 1 instances of a possible 1 to master
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (120s) for squareDomU on alpha
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd0:0 on bravo
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd0:1 on alpha
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd0:0 on bravo
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd0:1 on alpha
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareRoot
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd1:0 on bravo
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd1:1 on alpha
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (20s) for drbd1:0 on bravo
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (10s) for drbd1:1 on alpha
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:45 bravo pengine: [25099]: ERROR: create_notification_boundaries: Creating boundaries for squareTmp
Oct 16 02:46:45 bravo pengine: [25099]: notice: RecurringOp: Start recurring monitor (180s) for resMON on bravo
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Start squareDomU (alpha)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Demote drbd0:0 (Master -> Slave bravo)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Promote drbd0:1 (Slave -> Master alpha)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Demote drbd1:0 (Master -> Slave bravo)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Promote drbd1:1 (Slave -> Master alpha)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Move resource resMON (Started alpha -> bravo)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Leave resource ping:0 (Started bravo)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Leave resource ping:1 (Started alpha)
Oct 16 02:46:45 bravo pengine: [25099]: notice: LogActions: Leave resource mailAlert (Started alpha)
Oct 16 02:46:45 bravo pengine: [25099]: info: process_pe_message: Transition 714: PEngine Input stored in: /var/lib/pengine/pe-input-3738.bz2
Oct 16 02:46:45 bravo crmd: [25100]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Oct 16 02:46:45 bravo crmd: [25100]: WARN: destroy_action: Cancelling timer for action 5 (src=1578)
Oct 16 02:46:45 bravo crmd: [25100]: WARN: destroy_action: Cancelling timer for action 1 (src=1580)
Oct 16 02:46:45 bravo crmd: [25100]: info: unpack_graph: Unpacked transition 714: 54 actions in 54 synapses
Oct 16 02:46:45 bravo crmd: [25100]: info: do_te_invoke: Processing graph 714 (ref=pe_calc-dc-1287157605-792) derived from /var/lib/pengine/pe-input-3738.bz2
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 40 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 73 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 77: stop resMON_stop_0 on alpha
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 107: notify drbd0:0_pre_notify_demote_0 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=107:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_notify_0 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:drbd0:0:55: notify
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 109: notify drbd0:1_pre_notify_demote_0 on alpha
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 123: notify drbd1:0_pre_notify_demote_0 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=123:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_notify_0 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:drbd1:0:56: notify
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 125: notify drbd1:1_pre_notify_demote_0 on alpha
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action resMON_stop_0 (77) confirmed on alpha (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 78: start resMON_start_0 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=78:714:0:a3273222-947d-4891-b5fa-138e2789787a op=resMON_start_0 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:resMON:57: start
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 5 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_notify_0 (call=55, rc=0, cib-update=853, confirmed=true) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_pre_notify_demote_0 (107) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_notify_0 (call=56, rc=0, cib-update=854, confirmed=true) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_pre_notify_demote_0 (123) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_pre_notify_demote_0 (125) confirmed on alpha (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 74 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_pre_notify_demote_0 (109) confirmed on alpha (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 41 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 38 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 13: demote drbd0:0_demote_0 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=13:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_demote_0 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:drbd0:0:58: demote
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation resMON_start_0 (call=57, rc=0, cib-update=855, confirmed=true) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action resMON_start_0 (78) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 79: monitor resMON_monitor_180000 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=79:714:0:a3273222-947d-4891-b5fa-138e2789787a op=resMON_monitor_180000 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:resMON:59: monitor
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation resMON_monitor_180000 (call=59, rc=0, cib-update=856, confirmed=false) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action resMON_monitor_180000 (79) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo lrmd: [25097]: info: RA output: (drbd0:0:demote:stdout)
Oct 16 02:46:45 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_demote_0 (call=58, rc=0, cib-update=857, confirmed=true) ok
Oct 16 02:46:45 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_demote_0 (13) confirmed on bravo (rc=0)
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 39 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 42 fired and confirmed
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 108: notify drbd0:0_post_notify_demote_0 on bravo (local)
Oct 16 02:46:45 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=108:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_notify_0 )
Oct 16 02:46:45 bravo lrmd: [25097]: info: rsc:drbd0:0:60: notify
Oct 16 02:46:45 bravo crmd: [25100]: info: te_rsc_command: Initiating action 110: notify drbd0:1_post_notify_demote_0 on alpha
Oct 16 02:46:46 bravo lrmd: [25097]: info: RA output: (drbd0:0:notify:stdout)
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_notify_0 (call=60, rc=0, cib-update=858, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_post_notify_demote_0 (108) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_post_notify_demote_0 (110) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 43 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 71 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 34 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 46: demote drbd1:0_demote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=46:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_demote_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd1:0:61: demote
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 103: notify drbd0:0_pre_notify_promote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=103:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_notify_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd0:0:62: notify
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 105: notify drbd0:1_pre_notify_promote_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_notify_0 (call=62, rc=0, cib-update=859, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_pre_notify_promote_0 (105) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_pre_notify_promote_0 (103) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 35 fired and confirmed
Oct 16 02:46:46 bravo lrmd: [25097]: info: RA output: (drbd1:0:demote:stdout)
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_demote_0 (call=61, rc=0, cib-update=860, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_demote_0 (46) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 72 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 75 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 124: notify drbd1:0_post_notify_demote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=124:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_notify_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd1:0:63: notify
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 126: notify drbd1:1_post_notify_demote_0 on alpha
Oct 16 02:46:46 bravo lrmd: [25097]: info: RA output: (drbd1:0:notify:stdout)
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_notify_0 (call=63, rc=0, cib-update=861, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_post_notify_demote_0 (124) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_post_notify_demote_0 (126) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 76 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 67 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 119: notify drbd1:0_pre_notify_promote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=119:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_notify_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd1:0:64: notify
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 121: notify drbd1:1_pre_notify_promote_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_notify_0 (call=64, rc=0, cib-update=862, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_pre_notify_promote_0 (121) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_pre_notify_promote_0 (119) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 68 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 65 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 51: promote drbd1:1_promote_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_promote_0 (51) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 66 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 69 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 120: notify drbd1:0_post_notify_promote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=120:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_notify_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd1:0:65: notify
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 122: notify drbd1:1_post_notify_promote_0 on alpha
Oct 16 02:46:46 bravo lrmd: [25097]: info: RA output: (drbd1:0:notify:stdout)
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_notify_0 (call=65, rc=0, cib-update=863, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_post_notify_promote_0 (122) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_post_notify_promote_0 (120) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 70 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 32 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 47: monitor drbd1:0_monitor_20000 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=47:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd1:0_monitor_20000 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd1:0:66: monitor
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 52: monitor drbd1:1_monitor_10000 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 18: promote drbd0:1_promote_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd1:0_monitor_20000 (call=66, rc=0, cib-update=864, confirmed=false) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:0_monitor_20000 (47) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_promote_0 (18) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 33 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 36 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 104: notify drbd0:0_post_notify_promote_0 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=104:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_notify_0 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd0:0:67: notify
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 106: notify drbd0:1_post_notify_promote_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd1:1_monitor_10000 (52) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo lrmd: [25097]: info: RA output: (drbd0:0:notify:stdout)
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_notify_0 (call=67, rc=0, cib-update=865, confirmed=true) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_post_notify_promote_0 (104) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_post_notify_promote_0 (106) confirmed on alpha (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: te_pseudo_action: Pseudo action 37 fired and confirmed
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 9: start squareDomU_start_0 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 14: monitor drbd0:0_monitor_20000 on bravo (local)
Oct 16 02:46:46 bravo crmd: [25100]: info: do_lrm_rsc_op: Performing key=14:714:0:a3273222-947d-4891-b5fa-138e2789787a op=drbd0:0_monitor_20000 )
Oct 16 02:46:46 bravo lrmd: [25097]: info: rsc:drbd0:0:68: monitor
Oct 16 02:46:46 bravo crmd: [25100]: info: te_rsc_command: Initiating action 19: monitor drbd0:1_monitor_10000 on alpha
Oct 16 02:46:46 bravo crmd: [25100]: info: process_lrm_event: LRM operation drbd0:0_monitor_20000 (call=68, rc=0, cib-update=866, confirmed=false) ok
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:0_monitor_20000 (14) confirmed on bravo (rc=0)
Oct 16 02:46:46 bravo crmd: [25100]: info: match_graph_event: Action drbd0:1_monitor_10000 (19) confirmed on alpha (rc=0)
Oct 16 02:46:50 bravo crmd: [25100]: info: match_graph_event: Action squareDomU_start_0 (9) confirmed on alpha (rc=0)
Oct 16 02:46:50 bravo crmd: [25100]: info: te_rsc_command: Initiating action 10: monitor squareDomU_monitor_120000 on alpha
Oct 16 02:47:50 bravo crmd: [25100]: info: match_graph_event: Action squareDomU_monitor_120000 (10) confirmed on alpha (rc=0)
Oct 16 02:47:50 bravo crmd: [25100]: info: run_graph: ====================================================
Oct 16 02:47:50 bravo crmd: [25100]: notice: run_graph: Transition 714 (Complete=54, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-input-3738.bz2): Complete
Oct 16 02:47:50 bravo crmd: [25100]: info: te_graph_trigger: Transition 714 is now complete
Oct 16 02:47:50 bravo crmd: [25100]: info: notify_crmd: Transition 714 status: done - <null>
Oct 16 02:47:50 bravo crmd: [25100]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Oct 16 02:47:50 bravo crmd: [25100]: info: do_state_transition: Starting PEngine Recheck Timer
Oct 16 02:53:40 bravo cib: [25096]: info: cib_stats: Processed 126 operations (2222.00us average, 0% utilization) in the last 10min
Oct 16 02:54:39 bravo lrmd: [25097]: WARN: G_SIG_dispatch: Dispatch function for SIGCHLD was delayed 1000 ms (> 100 ms) before being called (GSource: 0x84ebbc0)
Oct 16 02:54:39 bravo lrmd: [25097]: info: G_SIG_dispatch: started at 1894751196 should have started at 1894751096
</SECTION>
More information about the Pacemaker
mailing list