Hi Pacemaker guru's
I have installed pacemaker successfully and I have setup a cluster with the
following configuration:
node tsparxdb01
node tsparxdb02
primitive ClusterIP ocf:heartbeat:IPaddr2 \
params ip="192.168.1.254" cidr_netmask="32" \
op monitor interval="30s" \
meta target-role="Started"
primitive Data ocf:linbit:drbd \
params drbd_resource="data" \
op monitor interval="60s" \
op start interval="0" timeout="240s" \
op stop interval="0" timeout="240s"
primitive DataFS ocf:heartbeat:Filesystem \
params device="/dev/drbd/by-res/data" directory="/data" fstype="ext4" \
op start interval="0" timeout="60s" \
op stop interval="0" timeout="60s"
primitive MySQL lsb:mysql \
op monitor interval="60s" timeout="120s" \
op start interval="20" timeout="120s" \
op stop interval="20s" timeout="120s"
group Server-MySQL DataFS MySQL ClusterIP
ms DataMaster Data \
meta master-max="1" master-node-max="1" clone-max="2" clone-node-max="1"
notify="true"
colocation DataFS_on_DataMaster inf: Server-MySQL DataMaster:Master
order DataFS-after-DataMaster inf: DataMaster:promote Server-MySQL:start
property $id="cib-bootstrap-options" \
dc-version="1.0.8-042548a451fce8400660f6031f4da6f0223dd5dd" \
cluster-infrastructure="openais" \
expected-quorum-votes="2" \
stonith-enabled="false" \
no-quorum-policy="ignore"
rsc_defaults $id="rsc-options" \
resource-stickiness="100"
Everything except the MySQL resource is working correctly (state 1):
============
Last updated: Wed Jan 19 10:15:51 2011
Stack: openais
Current DC: tsparxdb02 - partition with quorum
Version: 1.0.8-042548a451fce8400660f6031f4da6f0223dd5dd
2 Nodes configured, 2 expected votes
2 Resources configured.
============
Online: [ tsparxdb01 tsparxdb02 ]
Master/Slave Set: DataMaster
Masters: [ tsparxdb02 ]
Slaves: [ tsparxdb01 ]
Resource Group: Server-MySQL
DataFS (ocf::heartbeat:Filesystem): Started tsparxdb02
MySQL (lsb:mysql): Stopped
ClusterIP (ocf::heartbeat:IPaddr2): Started tsparxdb02
The MySQL resource keeps trying to start, but after a while I will see this
(state 2):
============
Last updated: Wed Jan 19 10:17:18 2011
Stack: openais
Current DC: tsparxdb02 - partition with quorum
Version: 1.0.8-042548a451fce8400660f6031f4da6f0223dd5dd
2 Nodes configured, 2 expected votes
2 Resources configured.
============
Online: [ tsparxdb01 tsparxdb02 ]
Master/Slave Set: DataMaster
Masters: [ tsparxdb02 ]
Slaves: [ tsparxdb01 ]
Resource Group: Server-MySQL
DataFS (ocf::heartbeat:Filesystem): Started tsparxdb02
MySQL (lsb:mysql): Stopped
ClusterIP (ocf::heartbeat:IPaddr2): Started tsparxdb02
Failed actions:
MySQL_monitor_60000 (node=tsparxdb02, call=62, rc=7, status=complete):
not running
And then it will go back to the previous state 1.
I have tried to use both RA ocf:heartbeat:mysql and lather the lsb:mysql.
My MySQL startup script seems to be LSB compliant since, it gives on all the
start/stop/status commands the correct result 0 or 3.
Anyone any idea what could be wrong. Attached you will find the snippet of
corosync.log that show when the switch between state 1 and state 2 occurs.
Hoping you can help me.
Regards,
Shurbann Martes
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: WARN: action_timer_callback: Timer popped (timeout=120000, abort_level=1000000, complete=false)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: ERROR: print_elem: Aborting transition, action lost: [Action 41]: In-flight (id: MySQL_monitor_60000, loc: tsparxdb02, priority: 0)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: abort_transition_graph: action_timer_callback:482 - Triggered transition abort (complete=0) : Action lost
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: WARN: cib_action_update: rsc_op 41: MySQL_monitor_60000 on tsparxdb02 timed out
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: run_graph: ====================================================
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: notice: run_graph: Transition 29 (Complete=11, Pending=0, Fired=0, Skipped=2, Incomplete=0, Source=/var/lib/pengine/pe-input-1834.bz2): Stopped
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_graph_trigger: Transition 29 is now complete
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ]
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke: Query 230: Requesting the current CIB: S_POLICY_ENGINE
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: process_graph_event: Action MySQL_monitor_60000 arrived after a completed transition
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: abort_transition_graph: process_graph_event:467 - Triggered transition abort (complete=1, tag=lrm_rsc_op, id=MySQL_monitor_60000, magic=2:1;41:29:0:94d8bb73-f8db-45dc-851a-8c00d57b3867, cib=0.361.69) : Inactive graph
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: WARN: update_failcount: Updating failcount for MySQL on tsparxdb02 after failed monitor: rc=1 (update=value++, time=1295446939)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke: Query 231: Requesting the current CIB: S_POLICY_ENGINE
Jan 19 10:22:19 tsparxdb02 attrd: [10188]: info: attrd_local_callback: Expanded fail-count-MySQL=value++ to 17
Jan 19 10:22:19 tsparxdb02 attrd: [10188]: info: attrd_trigger_update: Sending flush op to all hosts for: fail-count-MySQL (17)
Jan 19 10:22:19 tsparxdb02 attrd: [10188]: info: attrd_perform_update: Sent update 126: fail-count-MySQL=17
Jan 19 10:22:19 tsparxdb02 attrd: [10188]: info: attrd_trigger_update: Sending flush op to all hosts for: last-failure-MySQL (1295446939)
Jan 19 10:22:19 tsparxdb02 attrd: [10188]: info: attrd_perform_update: Sent update 128: last-failure-MySQL=1295446939
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke_callback: Invoking the PE: query=231, ref=pe_calc-dc-1295446939-173, seq=252, quorate=1
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=1, tag=transient_attributes, id=tsparxdb02, magic=NA, cib=0.361.70) : Transient attribute: update
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=1, tag=transient_attributes, id=tsparxdb02, magic=NA, cib=0.361.71) : Transient attribute: update
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke: Query 232: Requesting the current CIB: S_POLICY_ENGINE
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke: Query 233: Requesting the current CIB: S_POLICY_ENGINE
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: unpack_config: On loss of CCM Quorum: Ignore
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb02 is online
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: WARN: unpack_rsc_op: Processing failed op MySQL_monitor_60000 on tsparxdb02: unknown error (1)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb01 is online
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: clone_print: Master/Slave Set: DataMaster
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: short_print: Masters: [ tsparxdb02 ]
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: short_print: Slaves: [ tsparxdb01 ]
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: group_print: Resource Group: Server-MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: DataFS (ocf::heartbeat:Filesystem): Started tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: MySQL (lsb:mysql): Started tsparxdb02 FAILED
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: ClusterIP (ocf::heartbeat:IPaddr2): Started tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: get_failcount: MySQL has failed 16 times on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: MySQL can fail 999984 more times on tsparxdb02 before being forced off
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: get_failcount: ClusterIP has failed 2 times on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: ClusterIP can fail 999998 more times on tsparxdb02 before being forced off
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataFS: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (60s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring start (20s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring stop (20s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (30s) for ClusterIP on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:1 (Slave tsparxdb01)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource DataFS (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Recover resource MySQL (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Restart resource ClusterIP (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: handle_response: pe_calc calculation pe_calc-dc-1295446939-173 is obsolete
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_pe_invoke_callback: Invoking the PE: query=233, ref=pe_calc-dc-1295446939-174, seq=252, quorate=1
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: process_pe_message: Transition 30: PEngine Input stored in: /var/lib/pengine/pe-input-1835.bz2
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: unpack_config: On loss of CCM Quorum: Ignore
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb02 is online
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: WARN: unpack_rsc_op: Processing failed op MySQL_monitor_60000 on tsparxdb02: unknown error (1)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb01 is online
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: clone_print: Master/Slave Set: DataMaster
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: short_print: Masters: [ tsparxdb02 ]
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: short_print: Slaves: [ tsparxdb01 ]
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: group_print: Resource Group: Server-MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: DataFS (ocf::heartbeat:Filesystem): Started tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: MySQL (lsb:mysql): Started tsparxdb02 FAILED
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: native_print: ClusterIP (ocf::heartbeat:IPaddr2): Started tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: get_failcount: MySQL has failed 17 times on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: MySQL can fail 999983 more times on tsparxdb02 before being forced off
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: get_failcount: ClusterIP has failed 2 times on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: ClusterIP can fail 999998 more times on tsparxdb02 before being forced off
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataFS: Rolling back scores from MySQL
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (60s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring start (20s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring stop (20s) for MySQL on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (30s) for ClusterIP on tsparxdb02
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:0 (Master tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:1 (Slave tsparxdb01)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource DataFS (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Recover resource MySQL (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: notice: LogActions: Restart resource ClusterIP (Started tsparxdb02)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: unpack_graph: Unpacked transition 31: 13 actions in 13 synapses
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_te_invoke: Processing graph 31 (ref=pe_calc-dc-1295446939-174) derived from /var/lib/pengine/pe-input-1836.bz2
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_pseudo_action: Pseudo action 49 fired and confirmed
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 44: stop ClusterIP_stop_0 on tsparxdb02 (local)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=44:31:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=ClusterIP_stop_0 )
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: rsc:ClusterIP:117: stop
Jan 19 10:22:19 tsparxdb02 pengine: [10189]: info: process_pe_message: Transition 31: PEngine Input stored in: /var/lib/pengine/pe-input-1836.bz2
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: RA output: (ClusterIP:stop:stderr) logger: unknown facility name: none.
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: RA output: (ClusterIP:stop:stderr) logger: unknown facility name: none.
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation ClusterIP_stop_0 (call=117, rc=0, cib-update=234, confirmed=true) ok
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: match_graph_event: Action ClusterIP_stop_0 (44) confirmed on tsparxdb02 (rc=0)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 1: stop MySQL_stop_0 on tsparxdb02 (local)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=1:31:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=MySQL_stop_0 )
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: rsc:MySQL:118: stop
Jan 19 10:22:19 tsparxdb02 lrmd: [25367]: WARN: For LSB init script, no additional parameters are needed.
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:stop:stdout) * MySQL manager or server PID file could not be found!
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_stop_0 (call=118, rc=0, cib-update=235, confirmed=true) ok
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: match_graph_event: Action MySQL_stop_0 (1) confirmed on tsparxdb02 (rc=0)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_pseudo_action: Pseudo action 50 fired and confirmed
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_pseudo_action: Pseudo action 3 fired and confirmed
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_pseudo_action: Pseudo action 47 fired and confirmed
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 40: start MySQL_start_0 on tsparxdb02 (local)
Jan 19 10:22:19 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=40:31:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=MySQL_start_0 )
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: rsc:MySQL:119: start
Jan 19 10:22:19 tsparxdb02 lrmd: [25385]: WARN: For LSB init script, no additional parameters are needed.
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:start:stdout) Starting MySQL
Jan 19 10:22:19 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:start:stdout) .
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation ClusterIP_monitor_30000 (call=73, rc=7, cib-update=236, confirmed=false) not running
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_graph_event: Detected action ClusterIP_monitor_30000 from a different transition: 18 vs. 31
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: abort_transition_graph: process_graph_event:462 - Triggered transition abort (complete=0, tag=lrm_rsc_op, id=ClusterIP_monitor_30000, magic=0:7;1:18:0:94d8bb73-f8db-45dc-851a-8c00d57b3867, cib=0.361.74) : Old event
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: update_abort_priority: Abort action done superceeded by restart
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: WARN: update_failcount: Updating failcount for ClusterIP on tsparxdb02 after failed monitor: rc=7 (update=value++, time=1295446940)
Jan 19 10:22:20 tsparxdb02 attrd: [10188]: info: attrd_local_callback: Expanded fail-count-ClusterIP=value++ to 3
Jan 19 10:22:20 tsparxdb02 attrd: [10188]: info: attrd_trigger_update: Sending flush op to all hosts for: fail-count-ClusterIP (3)
Jan 19 10:22:20 tsparxdb02 attrd: [10188]: info: attrd_perform_update: Sent update 130: fail-count-ClusterIP=3
Jan 19 10:22:20 tsparxdb02 attrd: [10188]: info: attrd_trigger_update: Sending flush op to all hosts for: last-failure-ClusterIP (1295446940)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=0, tag=transient_attributes, id=tsparxdb02, magic=NA, cib=0.361.75) : Transient attribute: update
Jan 19 10:22:20 tsparxdb02 attrd: [10188]: info: attrd_perform_update: Sent update 132: last-failure-ClusterIP=1295446940
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: abort_transition_graph: te_update_diff:146 - Triggered transition abort (complete=0, tag=transient_attributes, id=tsparxdb02, magic=NA, cib=0.361.76) : Transient attribute: update
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:start:stdout) *
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_start_0 (call=119, rc=0, cib-update=237, confirmed=true) ok
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: match_graph_event: Action MySQL_start_0 (40) confirmed on tsparxdb02 (rc=0)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: run_graph: ====================================================
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: notice: run_graph: Transition 31 (Complete=7, Pending=0, Fired=0, Skipped=6, Incomplete=0, Source=/var/lib/pengine/pe-input-1836.bz2): Stopped
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_graph_trigger: Transition 31 is now complete
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd ]
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_state_transition: All 2 cluster nodes are eligible to run resources.
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_pe_invoke: Query 238: Requesting the current CIB: S_POLICY_ENGINE
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_pe_invoke_callback: Invoking the PE: query=238, ref=pe_calc-dc-1295446940-178, seq=252, quorate=1
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: unpack_config: On loss of CCM Quorum: Ignore
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb02 is online
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: WARN: unpack_rsc_op: Processing failed op MySQL_monitor_60000 on tsparxdb02: unknown error (1)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: WARN: unpack_rsc_op: Processing failed op ClusterIP_monitor_30000 on tsparxdb02: not running (7)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: determine_online_status: Node tsparxdb01 is online
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: clone_print: Master/Slave Set: DataMaster
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: short_print: Masters: [ tsparxdb02 ]
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: short_print: Slaves: [ tsparxdb01 ]
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: group_print: Resource Group: Server-MySQL
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: native_print: DataFS (ocf::heartbeat:Filesystem): Started tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: native_print: MySQL (lsb:mysql): Started tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: native_print: ClusterIP (ocf::heartbeat:IPaddr2): Stopped
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: get_failcount: MySQL has failed 17 times on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: MySQL can fail 999983 more times on tsparxdb02 before being forced off
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: get_failcount: ClusterIP has failed 3 times on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: common_apply_stickiness: ClusterIP can fail 999997 more times on tsparxdb02 before being forced off
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from DataFS
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataMaster: Rolling back scores from MySQL
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: master_color: Promoting Data:0 (Master tsparxdb02)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: master_color: DataMaster: Promoted 1 instances of a possible 1 to master
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: native_merge_weights: DataFS: Rolling back scores from MySQL
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (60s) for MySQL on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring start (20s) for MySQL on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring stop (20s) for MySQL on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: RecurringOp: Start recurring monitor (30s) for ClusterIP on tsparxdb02
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:0 (Master tsparxdb02)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource Data:1 (Slave tsparxdb01)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource DataFS (Started tsparxdb02)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: LogActions: Leave resource MySQL (Started tsparxdb02)
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: notice: LogActions: Start ClusterIP (tsparxdb02)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: unpack_graph: Unpacked transition 32: 7 actions in 7 synapses
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_te_invoke: Processing graph 32 (ref=pe_calc-dc-1295446940-178) derived from /var/lib/pengine/pe-input-1837.bz2
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_pseudo_action: Pseudo action 46 fired and confirmed
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 41: monitor MySQL_monitor_60000 on tsparxdb02 (local)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=41:32:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=MySQL_monitor_60000 )
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2873: operation monitor[76] on lsb::mysql::MySQL for client 10190, its parameters: CRM_meta_name=[monitor] crm_feature_set=[3.0.1] CRM_meta_timeout=[120000] CRM_meta_interval=[60000] for rsc is already running.
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2883: postponing all ops on resource MySQL by 1000 ms
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 42: start MySQL_start_20000 on tsparxdb02 (local)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: ERROR: construct_op: Start and Stop actions cannot have an interval: 20000
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=42:32:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=MySQL_start_0 )
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2873: operation monitor[76] on lsb::mysql::MySQL for client 10190, its parameters: CRM_meta_name=[monitor] crm_feature_set=[3.0.1] CRM_meta_timeout=[120000] CRM_meta_interval=[60000] for rsc is already running.
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2877: operations on resource MySQL already delayed
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 43: stop MySQL_stop_20000 on tsparxdb02 (local)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: ERROR: construct_op: Start and Stop actions cannot have an interval: 20000
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: cancel_op: operation monitor[120] on lsb::mysql::MySQL for client 10190, its parameters: CRM_meta_name=[monitor] crm_feature_set=[3.0.1] CRM_meta_timeout=[120000] CRM_meta_interval=[60000] cancelled
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=43:32:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=MySQL_stop_0 )
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2873: operation monitor[76] on lsb::mysql::MySQL for client 10190, its parameters: CRM_meta_name=[monitor] crm_feature_set=[3.0.1] CRM_meta_timeout=[120000] CRM_meta_interval=[60000] for rsc is already running.
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: perform_op:2877: operations on resource MySQL already delayed
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: te_rsc_command: Initiating action 44: start ClusterIP_start_0 on tsparxdb02 (local)
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: do_lrm_rsc_op: Performing key=44:32:0:94d8bb73-f8db-45dc-851a-8c00d57b3867 op=ClusterIP_start_0 )
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: rsc:ClusterIP:123: start
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_monitor_60000 (call=120, status=1, cib-update=0, confirmed=true) Cancelled
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: rsc:MySQL:121: start
Jan 19 10:22:20 tsparxdb02 lrmd: [25603]: WARN: For LSB init script, no additional parameters are needed.
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_monitor_60000 (call=76, rc=0, cib-update=239, confirmed=false) ok
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: process_graph_event: Detected action MySQL_monitor_60000 from a different transition: 20 vs. 32
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: abort_transition_graph: process_graph_event:462 - Triggered transition abort (complete=0, tag=lrm_rsc_op, id=MySQL_monitor_60000, magic=0:0;36:20:0:94d8bb73-f8db-45dc-851a-8c00d57b3867, cib=0.361.78) : Old event
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000
Jan 19 10:22:20 tsparxdb02 crmd: [10190]: info: update_abort_priority: Abort action done superceeded by restart
Jan 19 10:22:20 tsparxdb02 pengine: [10189]: info: process_pe_message: Transition 32: PEngine Input stored in: /var/lib/pengine/pe-input-1837.bz2
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: RA output: (ClusterIP:start:stderr) logger: unknown facility name: none.
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: RA output: (ClusterIP:start:stderr) logger: unknown facility name: none.
Jan 19 10:22:20 tsparxdb02 lrmd: [10187]: info: RA output: (ClusterIP:start:stderr) logger: unknown facility name: none.
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: rsc:MySQL:122: stop
Jan 19 10:22:21 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation ClusterIP_start_0 (call=123, rc=0, cib-update=240, confirmed=true) ok
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:start:stdout) Starting MySQL
*
Jan 19 10:22:21 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_start_0 (call=121, rc=0, cib-update=241, confirmed=true) ok
Jan 19 10:22:21 tsparxdb02 crmd: [10190]: info: match_graph_event: Action ClusterIP_start_0 (44) confirmed on tsparxdb02 (rc=0)
Jan 19 10:22:21 tsparxdb02 lrmd: [25646]: WARN: For LSB init script, no additional parameters are needed.
Jan 19 10:22:21 tsparxdb02 crmd: [10190]: info: match_graph_event: Action MySQL_start_0 (42) confirmed on tsparxdb02 (rc=0)
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:stop:stdout) Shutting down MySQL
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:stop:stdout) .
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: perform_op:2873: operation stop[122] on lsb::mysql::MySQL for client 10190, its parameters: CRM_meta_name=[stop] crm_feature_set=[3.0.1] CRM_meta_timeout=[120000] CRM_meta_interval=[20000] for rsc is already running.
Jan 19 10:22:21 tsparxdb02 lrmd: [10187]: info: perform_op:2883: postponing all ops on resource MySQL by 1000 ms
Jan 19 10:22:22 tsparxdb02 lrmd: [10187]: info: RA output: (MySQL:stop:stdout) *
Jan 19 10:22:22 tsparxdb02 crmd: [10190]: info: process_lrm_event: LRM operation MySQL_stop_0 (call=122, rc=0, cib-update=242, confirmed=true) ok
Jan 19 10:22:22 tsparxdb02 crmd: [10190]: info: match_graph_event: Action MySQL_stop_0 (43) confirmed on tsparxdb02 (rc=0)
_______________________________________________
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
