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="em...@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 <r...@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=[hostmas...@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>
_______________________________________________
Pacemaker mailing list: Pacemaker@oss.clusterlabs.org
http://oss.clusterlabs.org/mailman/listinfo/pacemaker
Project Home: http://www.clusterlabs.org
Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf
Bugs: http://developerbugs.linux-foundation.org/enter_bug.cgi?product=Pacemaker
