[Linux-HA] Heartbeat doesn't start resources on proper node after
DRBD syncing.
Michael
misha at onet.ru
Wed Oct 3 06:38:54 MDT 2007
Hello, colleagues!
My system is up-to-date Gentoo world, manually installed heartbeat
2.1.2 and unmasked drbd 8.0.6, apache 2.2.6 and mysql 5.0.44 from
portage.
I can't use 0.7.x version of DRBD because it consist bug which i face:
nodes become in WFBitMapS state and freeze. Searching in drbd mailing
list gave me developer post that this problem is fixed in 8 series.
I'm trying to setup HA cluster for web-server with two nodes. To
accomplish this task i'm using drbd to get real-time data replication,
mysql, apache and shared IP address.
According to documentation i created the cluster where i have:
- Master\Slave DRBD resource
- Filesystem which is started on DRBD Master promoted node
- Web group with IP, Apache and mySQL, which is started after
Filesystem and on the same node.
When primary node is falling, second one gets its ip and starts all
resources, when primary system is back it's desired for secondary node
to give all resources back and sync all changes in filesystem with
drbd (this is because primary node is twice more powerful).
When I start heartbeat on both nodes everything is fine, primary one
gets Master status in Master\Slave drbd resource, then, I shutdown
primary node, all resources is setting up on Secondary node (all is
fine).
Then I copy 300mb files to drbd filesystem (i simulate changes in web
environment while primary node is down) and start primary node again,
all resources on Secondary node gets shot down (which i expect).
That is the place where problem happen, drbd need some time to
syncronize filesytem (state become SyncSource), after sync is done (we
have Gb link between the servers, so it's rather fast) i expect my
Primary node take the Master status of drbd resource, but it doesn't
happen, what i see is that Secondary node is still Master and after
timeouts all resources get started on Secondary again.
By the way, if i won't copy large files inside drbd FS all resources
will succesfully migrate to Primary.
Uname of my primary node is "tolstoy", and secondary is "lermontov".
Below is my cib.xml and logs from secondary (lermontov) node after
Primary (tolstoy) is getting online again after shutdown.
Thanks a lot for any kind of help and sorry for my language, i'll
gladly explain anything obscure in my mail.
This is my cib.xml:
<cib admin_epoch="0" have_quorum="false" ignore_dtd="false"
num_peers="0" cib_feature_revision="1.3" generated="false" epoch="240"
num_updates="5" cib-last-w
<configuration>
<crm_config>
<cluster_property_set id="idCluseterPropertySet">
<attributes>
<nvpair id="election_timeout" name="election_timeout" value="10sec"/>
<nvpair id="crmd-integration-timeout"
name="crmd-integration-timeout" value="30sec"/>
</attributes>
</cluster_property_set>
<cluster_property_set id="cib-bootstrap-options">
<attributes>
<nvpair id="cib-bootstrap-options-last-lrm-refresh"
name="last-lrm-refresh" value="1191399415"/>
</attributes>
</cluster_property_set>
</crm_config>
<nodes>
<node id="88704e73-d9eb-43b6-87bb-07a5ff6069d8" uname="tolstoy"
type="normal"/>
<node id="f95e2980-394d-4260-8793-8ea89c33b0ac"
uname="lermontov" type="normal"/>
</nodes>
<resources>
<master_slave id="ms-drbd0">
<meta_attributes id="ma-ms-drbd0">
<attributes>
<nvpair id="ma-ms-drbd0-1" name="clone_max" value="2"/>
<nvpair id="ma-ms-drbd0-2" name="clone_node_max" value="1"/>
<nvpair id="ma-ms-drbd0-3" name="master_max" value="1"/>
<nvpair id="ma-ms-drbd0-4" name="master_node_max" value="1"/>
<nvpair id="ma-ms-drbd0-5" name="notify" value="yes"/>
<nvpair id="ma-ms-drbd0-6" name="globally_unique" value="false"/>
<nvpair id="ma-ms-drbd0-7" name="target_role" value="#default"/>
</attributes>
</meta_attributes>
<primitive id="drbd0" class="ocf" provider="heartbeat" type="drbd">
<operations>
<op id="10" name="monitor" interval="6s" timeout="120s"/>
</operations>
<instance_attributes id="ia-drbd0">
<attributes>
<nvpair id="ia-drbd0-1" name="drbd_resource" value="r0"/>
</attributes>
</instance_attributes>
</primitive>
</master_slave>
<primitive class="ocf" provider="heartbeat" type="Filesystem" id="fs0">
<operations>
<op id="1" name="start" start_delay="60s"/>
</operations>
<instance_attributes id="ia-fs0">
<attributes>
<nvpair id="ia-fs0-2" name="directory" value="/web"/>
<nvpair id="ia-fs0-3" name="device" value="/dev/drbd0"/>
</attributes>
</instance_attributes>
</primitive>
<group id="web_group">
<primitive id="WebServerIP" class="ocf" type="IPaddr"
provider="heartbeat">
<instance_attributes id="ia-webip">
<attributes>
<nvpair id="atr1" name="ip" value="192.168.0.172"/>
</attributes>
</instance_attributes>
</primitive>
<primitive id="WebServerDatabase" class="ocf" type="mysql"
provider="heartbeat">
<operations>
<op id="100" name="start" start_delay="40s"/>
</operations>
<instance_attributes id="ia-webdb">
<attributes>
<nvpair id="mysql_config12" name="config"
value="/etc/mysql/my.cnf"/>
<nvpair id="mysql_config13" name="socket"
value="/var/run/mysqld/mysqld.sock"/>
<nvpair id="mysql_config14" name="pid"
value="/var/run/mysqld/mysqld.pid"/>
<nvpair id="mysql_config15" name="binary"
value="/usr/bin/mysqld_safe"/>
<nvpair id="mysql_config16" name="datadir" value="/web/mysql/"/>
</attributes>
</instance_attributes>
</primitive>
<primitive id="WebServerApache" class="ocf" type="apache"
provider="heartbeat">
<operations>
<op id="101" name="start" start_delay="40s"/>
</operations>
<instance_attributes id="ia-apache">
<attributes>
<nvpair id="nvp1" name="configfile"
value="/etc/apache2/httpd.conf"/>
<nvpair id="nvp2" name="options" value="-DINFO
-DDEFAULT_VHOST -DSTATUS -DPHP5"/>
<nvpair id="nvp3" name="httpd" value="/usr/sbin/apache2"/>
</attributes>
</instance_attributes>
</primitive>
</group>
</resources>
<constraints>
<rsc_location id="loc:drbd1_likes_fred" rsc="ms-drbd0">
<rule id="rule:drbd1_likes_fred" role="master" score="100">
<expression attribute="#uname" operation="eq"
value="tolstoy" id="444"/>
</rule>
</rsc_location>
<rsc_location id="loc:drbd1_likes_fred12" rsc="ms-drbd0">
<rule id="rule:drbd1_likes_fred123" role="master" score="5">
<expression attribute="#uname" operation="eq"
value="lermontov" id="412344"/>
</rule>
</rsc_location>
<rsc_location id="loc:web" rsc="web_group">
<rule id="rule:web-r1" score="1000">
<expression attribute="#uname" operation="eq"
value="tolstoy" id="123123"/>
</rule>
</rsc_location>
<rsc_location id="loc:web12" rsc="web_group">
<rule id="rule:web-r112" score="100">
<expression attribute="#uname" operation="eq"
value="lermontov" id="12312123"/>
</rule>
</rsc_location>
<rsc_order id="drbd0_before_fs0" from="fs0" action="start"
to="ms-drbd0" to_action="promote"/>
<rsc_order id="fs0_before_webgr" from="web_group"
action="start" to="fs0" to_action="start"/>
<rsc_colocation id="fs0_on_drbd0" to="ms-drbd0"
to_role="master" from="fs0" score="infinity"/>
<rsc_colocation id="webgr_on_fs0" to="web_group" from="fs0"
score="infinity"/>
</constraints>
</configuration>
</cib>
These are logs from lermontov after Primary (tolstoy) is back online
after shutdown:
Oct 3 16:17:25 lermontov pengine: [11898]: info:
determine_online_status: Node tolstoy is online
Oct 3 16:17:25 lermontov pengine: [11898]: info:
determine_online_status: Node lermontov is online
Oct 3 16:17:25 lermontov pengine: [11898]: info: clone_print:
Master/Slave Set: ms-drbd0
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
drbd0:0 (heartbeat::ocf:drbd): Stopped
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
drbd0:1 (heartbeat::ocf:drbd): Master lermontov
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
fs0 (heartbeat::ocf:Filesystem): Started lermontov
Oct 3 16:17:25 lermontov pengine: [11898]: info: group_print:
Resource Group: web_group
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
WebServerIP (heartbeat::ocf:IPaddr): Started lermontov
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
WebServerDatabase (heartbeat::ocf:mysql): Started lermontov
Oct 3 16:17:25 lermontov pengine: [11898]: info: native_print:
WebServerApache (heartbeat::ocf:apache): Started lermontov
Oct 3 16:17:25 lermontov pengine: [11898]: info: master_color:
Promoting drbd0:1
Oct 3 16:17:25 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:17:25 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:17:25 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start drbd0:0
Oct 3 16:17:25 lermontov pengine: [11898]: notice: RecurringOp:
tolstoy drbd0:0_monitor_6000
Oct 3 16:17:25 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:17:25 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start drbd0:0
Oct 3 16:17:25 lermontov pengine: [11898]: notice: RecurringOp:
tolstoy drbd0:0_monitor_6000
Oct 3 16:17:25 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:17:25 lermontov pengine: [11898]: WARN: native_color:
Resource fs0 cannot run anywhere
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop fs0
Oct 3 16:17:25 lermontov pengine: [11898]: notice: NoRoleChange: Move
resource WebServerIP (lermontov -> tolstoy)
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop WebServerIP
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerIP
Oct 3 16:17:25 lermontov pengine: [11898]: notice: NoRoleChange: Move
resource WebServerDatabase (lermontov -> tolstoy)
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop WebServerDatabase
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerDatabase
Oct 3 16:17:25 lermontov pengine: [11898]: notice: NoRoleChange: Move
resource WebServerApache (lermontov -> tolstoy)
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop WebServerApache
Oct 3 16:17:25 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerApache
Oct 3 16:17:25 lermontov crmd: [10423]: info: do_state_transition:
State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [
input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=route_message ]
Oct 3 16:17:25 lermontov pengine: [11898]: WARN: process_pe_message:
Transition 1: WARNINGs found during PE processing. PEngine Input
stored in: /home/hacluster/var/lib/heartbeat/pengine/pe-warn-135.bz2
Oct 3 16:17:25 lermontov pengine: [11898]: info: process_pe_message:
Configuration WARNINGs found during PE processing. Please run
"crm_verify -L" to identify issues.
Oct 3 16:17:25 lermontov tengine: [11897]: info: unpack_graph:
Unpacked transition 1: 29 actions in 29 synapses
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 3: drbd0:0_monitor_0 on tolstoy
Oct 3 16:17:25 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 17 fired and confirmed
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 4: fs0_monitor_0 on tolstoy
Oct 3 16:17:25 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 48 fired and confirmed
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 5: WebServerIP_monitor_0 on tolstoy
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 6: WebServerDatabase_monitor_0 on tolstoy
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 7: WebServerApache_monitor_0 on tolstoy
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 44: WebServerApache_stop_0 on lermontov
Oct 3 16:17:25 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 54: drbd0:1_pre_notify_start_0 on lermontov
Oct 3 16:17:25 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerApache_stop_0
key=44:1:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:25 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=drbd0:1_notify_0
key=54:1:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:25 lermontov drbd[12231]: [12246]: DEBUG: r0 notify: pre
for start - counts: active 0 - starting 1 - stopping 0
Oct 3 16:17:25 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation drbd0:1_notify_0 (call=22, rc=0) complete
Oct 3 16:17:25 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:1_pre_notify_start_0 (54) confirmed on lermontov
Oct 3 16:17:25 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 18 fired and confirmed
Oct 3 16:17:26 lermontov apache[12228]: [12289]: INFO: Killing apache PID 12182
Oct 3 16:17:26 lermontov apache[12228]: [12291]: INFO: apache stopped.
Oct 3 16:17:26 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerApache_stop_0 (call=21, rc=0) complete
Oct 3 16:17:26 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerApache_stop_0 (44) confirmed on lermontov
Oct 3 16:17:26 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 42: WebServerDatabase_stop_0 on lermontov
Oct 3 16:17:26 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerDatabase_stop_0
key=42:1:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:27 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerDatabase_monitor_0 (6) confirmed on tolstoy
Oct 3 16:17:27 lermontov tengine: [11897]: info: match_graph_event:
Action fs0_monitor_0 (4) confirmed on tolstoy
Oct 3 16:17:27 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerIP_monitor_0 (5) confirmed on tolstoy
Oct 3 16:17:27 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:0_monitor_0 (3) confirmed on tolstoy
Oct 3 16:17:28 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerApache_monitor_0 (7) confirmed on tolstoy
Oct 3 16:17:28 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 2: probe_complete on tolstoy
Oct 3 16:17:28 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 1 fired and confirmed
Oct 3 16:17:28 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 15 fired and confirmed
Oct 3 16:17:28 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 13: drbd0:0_start_0 on tolstoy
Oct 3 16:17:29 lermontov drbd0: conn( WFConnection -> WFReportParams )
Oct 3 16:17:29 lermontov drbd0: Handshake successful: DRBD Network
Protocol version 86
Oct 3 16:17:29 lermontov drbd0: Peer authenticated using 20 bytes of
'sha1' HMAC
Oct 3 16:17:29 lermontov drbd0: peer( Unknown -> Secondary ) conn(
WFReportParams -> WFBitMapS ) pdsk( DUnknown -> UpToDate )
Oct 3 16:17:29 lermontov drbd0: Writing meta data super block now.
Oct 3 16:17:29 lermontov drbd0: conn( WFBitMapS -> SyncSource ) pdsk(
UpToDate -> Inconsistent )
Oct 3 16:17:29 lermontov drbd0: Began resync as SyncSource (will sync
147484 KB [36871 bits set]).
Oct 3 16:17:29 lermontov drbd0: Writing meta data super block now.
Oct 3 16:17:29 lermontov tengine: [11897]: info: extract_event:
Aborting on transient_attributes changes for
88704e73-d9eb-43b6-87bb-07a5ff6069d8
Oct 3 16:17:29 lermontov tengine: [11897]: info:
update_abort_priority: Abort priority upgraded to 1000000
Oct 3 16:17:29 lermontov tengine: [11897]: info:
update_abort_priority: Abort action 0 superceeded by 2
Oct 3 16:17:29 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:0_start_0 (13) confirmed on tolstoy
Oct 3 16:17:29 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 16 fired and confirmed
Oct 3 16:17:29 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 19 fired and confirmed
Oct 3 16:17:29 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 55: drbd0:1_post_notify_start_0 on lermontov
Oct 3 16:17:29 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 62: drbd0:0_post_notify_start_0 on tolstoy
Oct 3 16:17:29 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=drbd0:1_notify_0
key=55:1:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:29 lermontov drbd[12317]: [12328]: DEBUG: r0 notify: post
for start - counts: active 0 - starting 1 - stopping 0
Oct 3 16:17:29 lermontov drbd[12317]: [12330]: DEBUG: r0: Calling
drbdadm -c /etc/drbd.conf state r0
Oct 3 16:17:29 lermontov drbd[12317]: [12337]: DEBUG: r0: Exit code 0
Oct 3 16:17:29 lermontov drbd[12317]: [12338]: DEBUG: r0: Command
output: Primary/Secondary
Oct 3 16:17:29 lermontov drbd[12317]: [12346]: DEBUG: r0: Calling
drbdadm -c /etc/drbd.conf cstate r0
Oct 3 16:17:29 lermontov drbd[12317]: [12353]: DEBUG: r0: Exit code 0
Oct 3 16:17:29 lermontov drbd[12317]: [12354]: DEBUG: r0: Command
output: SyncSource
Oct 3 16:17:29 lermontov drbd[12317]: [12355]: DEBUG: r0 status:
Primary/Secondary Primary Secondary SyncSource
Oct 3 16:17:29 lermontov drbd[12317]: [12356]: DEBUG: r0: Calling
/home/hacluster/sbin/crm_master -v 100 -l reboot
Oct 3 16:17:29 lermontov crm_master: [12358]: info: Invoked:
/home/hacluster/sbin/crm_master -v 100 -l reboot
Oct 3 16:17:29 lermontov tengine: [11897]: info: extract_event:
Aborting on transient_attributes changes for
f95e2980-394d-4260-8793-8ea89c33b0ac
Oct 3 16:17:29 lermontov tengine: [11897]: info: te_update_diff:
Aborting on transient_attributes deletions
Oct 3 16:17:29 lermontov drbd[12317]: [12359]: DEBUG: r0: Exit code 0
Oct 3 16:17:29 lermontov drbd[12317]: [12360]: DEBUG: r0: Command
output: crm_master[12358]: 2007/10/03_16:17:29 info: Invoked:
/home/hacluster/sbin/crm_master -v 100 -l reboot
Oct 3 16:17:29 lermontov lrmd: [10420]: info: RA output:
(drbd0:1:notify:stdout) crm_master[12358]: 2007/10/03_16:17:29 info:
Invoked: /home/hacluster/sbin/crm_master -v 100 -l reboot
Oct 3 16:17:29 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation drbd0:1_notify_0 (call=24, rc=0) complete
Oct 3 16:17:29 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:1_post_notify_start_0 (55) confirmed on lermontov
Oct 3 16:17:30 lermontov mysql[12292]: [12361]: DEBUG: MySQL is not running
Oct 3 16:17:31 lermontov mysql[12292]: [12363]: INFO: MySQL stopped
Oct 3 16:17:31 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerDatabase_stop_0 (call=23, rc=0) complete
Oct 3 16:17:31 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerDatabase_stop_0 (42) confirmed on lermontov
Oct 3 16:17:31 lermontov tengine: [11897]: info: extract_event:
Aborting on transient_attributes changes for
88704e73-d9eb-43b6-87bb-07a5ff6069d8
Oct 3 16:17:33 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:0_post_notify_start_0 (62) confirmed on tolstoy
Oct 3 16:17:33 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 20 fired and confirmed
Oct 3 16:17:33 lermontov tengine: [11897]: info: run_graph:
====================================================
Oct 3 16:17:33 lermontov tengine: [11897]: notice: run_graph:
Transition 1: (Complete=20, Pending=0, Fired=0, Skipped=9,
Incomplete=0)
Oct 3 16:17:33 lermontov crmd: [10423]: info: do_state_transition:
State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [
input=I_PE_CALC cause=C_IPC_MESSAGE origin=route_message ]
Oct 3 16:17:33 lermontov crmd: [10423]: info: do_state_transition:
All 2 cluster nodes are eligible to run resources.
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'stop' for cluster option 'no-quorum-policy'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'symmetric-cluster'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'false' for cluster option 'stonith-enabled'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'reboot' for cluster option 'stonith-action'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '0' for cluster option
'default-resource-stickiness'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '0' for cluster option
'default-resource-failure-stickiness'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'is-managed-default'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '60s' for cluster option 'cluster-delay'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '20s' for cluster option 'default-action-timeout'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'stop-orphan-resources'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'stop-orphan-actions'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'false' for cluster option 'remove-after-stop'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-error-series-max'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-warn-series-max'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-input-series-max'
Oct 3 16:17:33 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'startup-fencing'
Oct 3 16:17:33 lermontov pengine: [11898]: info:
determine_online_status: Node tolstoy is online
Oct 3 16:17:33 lermontov pengine: [11898]: info:
determine_online_status: Node lermontov is online
Oct 3 16:17:33 lermontov pengine: [11898]: info:
unpack_find_resource: Internally renamed drbd0:0 on lermontov to
drbd0:1
Oct 3 16:17:33 lermontov pengine: [11898]: info: clone_print:
Master/Slave Set: ms-drbd0
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
drbd0:0 (heartbeat::ocf:drbd): Started tolstoy
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
drbd0:1 (heartbeat::ocf:drbd): Master lermontov
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
fs0 (heartbeat::ocf:Filesystem): Started lermontov
Oct 3 16:17:33 lermontov pengine: [11898]: info: group_print:
Resource Group: web_group
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
WebServerIP (heartbeat::ocf:IPaddr): Started lermontov
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
WebServerDatabase (heartbeat::ocf:mysql): Stopped
Oct 3 16:17:33 lermontov pengine: [11898]: info: native_print:
WebServerApache (heartbeat::ocf:apache): Stopped
Oct 3 16:17:33 lermontov pengine: [11898]: info: master_color:
Promoting drbd0:1
Oct 3 16:17:33 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:17:33 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:17:33 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:17:33 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:0 (tolstoy)
Oct 3 16:17:33 lermontov pengine: [11898]: notice: RecurringOp:
tolstoy drbd0:0_monitor_6000
Oct 3 16:17:33 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:17:33 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:17:33 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:0 (tolstoy)
Oct 3 16:17:33 lermontov pengine: [11898]: notice: RecurringOp:
tolstoy drbd0:0_monitor_6000
Oct 3 16:17:33 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:17:33 lermontov pengine: [11898]: WARN: native_color:
Resource fs0 cannot run anywhere
Oct 3 16:17:33 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop fs0
Oct 3 16:17:33 lermontov pengine: [11898]: notice: NoRoleChange: Move
resource WebServerIP (lermontov -> tolstoy)
Oct 3 16:17:33 lermontov pengine: [11898]: notice: StopRsc:
lermontov Stop WebServerIP
Oct 3 16:17:33 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerIP
Oct 3 16:17:33 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerDatabase
Oct 3 16:17:33 lermontov crmd: [10423]: info: do_state_transition:
State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [
input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=route_message ]
Oct 3 16:17:33 lermontov pengine: [11898]: notice: StartRsc:
tolstoy Start WebServerApache
Oct 3 16:17:33 lermontov tengine: [11897]: info: unpack_graph:
Unpacked transition 2: 11 actions in 11 synapses
Oct 3 16:17:33 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 10: drbd0:0_monitor_6000 on tolstoy
Oct 3 16:17:33 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 42 fired and confirmed
Oct 3 16:17:33 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 36: WebServerIP_stop_0 on lermontov
Oct 3 16:17:33 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 48 fired and confirmed
Oct 3 16:17:33 lermontov pengine: [11898]: WARN: process_pe_message:
Transition 2: WARNINGs found during PE processing. PEngine Input
stored in: /home/hacluster/var/lib/heartbeat/pengine/pe-warn-136.bz2
Oct 3 16:17:33 lermontov pengine: [11898]: info: process_pe_message:
Configuration WARNINGs found during PE processing. Please run
"crm_verify -L" to identify issues.
Oct 3 16:17:33 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerIP_stop_0
key=36:2:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output:
(WebServerIP:stop:stdout) In IP Stop
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output:
(WebServerIP:stop:stderr) SIOCDELRT: No such process
Oct 3 16:17:33 lermontov IPaddr[12366]: [12381]: INFO: ifconfig eth0:0 down
Oct 3 16:17:33 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerIP_stop_0 (call=25, rc=0) complete
Oct 3 16:17:33 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerIP_stop_0 (36) confirmed on lermontov
Oct 3 16:17:33 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 43 fired and confirmed
Oct 3 16:17:33 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 35: fs0_stop_0 on lermontov
Oct 3 16:17:33 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 40 fired and confirmed
Oct 3 16:17:33 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 37: WebServerIP_start_0 on tolstoy
Oct 3 16:17:33 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=fs0_stop_0
key=35:2:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:17:33 lermontov Filesystem[12384]: [12413]: INFO: Running
stop for /dev/drbd0 on /web
Oct 3 16:17:33 lermontov Filesystem[12384]: [12423]: INFO: Trying to
unmount /web
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) umount: /web: device is busy umount: /web: device is
busy
Oct 3 16:17:33 lermontov Filesystem[12384]: [12425]: ERROR: Couldn't
unmount /web; trying cleanup with SIGTERM
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) /web:
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stdout) 12124
Oct 3 16:17:33 lermontov lrmd: [10420]: info: RA output: (fs0:stop:stderr) c
Oct 3 16:17:33 lermontov Filesystem[12384]: [12427]: INFO: Some
processes on /web were signalled
Oct 3 16:17:34 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) umount: /web: device is busy umount: /web: device is
busy
Oct 3 16:17:34 lermontov Filesystem[12384]: [12430]: ERROR: Couldn't
unmount /web; trying cleanup with SIGTERM
Oct 3 16:17:34 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) /web:
Oct 3 16:17:34 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stdout) 12124
Oct 3 16:17:34 lermontov lrmd: [10420]: info: RA output: (fs0:stop:stderr) c
Oct 3 16:17:34 lermontov Filesystem[12384]: [12432]: INFO: Some
processes on /web were signalled
Oct 3 16:17:34 lermontov tengine: [11897]: info: match_graph_event:
Action drbd0:0_monitor_6000 (10) confirmed on tolstoy
Oct 3 16:17:34 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerIP_start_0 (37) confirmed on tolstoy
Oct 3 16:17:34 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 38: WebServerDatabase_start_0 on tolstoy
Oct 3 16:17:35 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) umount: /web: device is busy umount: /web: device is
busy
Oct 3 16:17:35 lermontov Filesystem[12384]: [12435]: ERROR: Couldn't
unmount /web; trying cleanup with SIGTERM
Oct 3 16:17:35 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) /web:
Oct 3 16:17:35 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stdout) 12124
Oct 3 16:17:35 lermontov lrmd: [10420]: info: RA output: (fs0:stop:stderr) c
Oct 3 16:17:35 lermontov Filesystem[12384]: [12437]: INFO: Some
processes on /web were signalled
Oct 3 16:17:36 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) umount: /web: device is busy umount: /web: device is
busy
Oct 3 16:17:36 lermontov Filesystem[12384]: [12440]: ERROR: Couldn't
unmount /web; trying cleanup with SIGKILL
Oct 3 16:17:36 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stderr) /web:
Oct 3 16:17:36 lermontov lrmd: [10420]: info: RA output:
(fs0:stop:stdout) 12124
Oct 3 16:17:36 lermontov lrmd: [10420]: info: RA output: (fs0:stop:stderr) c
Oct 3 16:17:36 lermontov Filesystem[12384]: [12442]: INFO: Some
processes on /web were signalled
Oct 3 16:17:41 lermontov drbd0: Resync done (total 12 sec; paused 0
sec; 12288 K/sec)
Oct 3 16:17:41 lermontov drbd0: conn( SyncSource -> Connected ) pdsk(
Inconsistent -> UpToDate )
Oct 3 16:17:41 lermontov drbd0: Writing meta data super block now.
Oct 3 16:17:41 lermontov Filesystem[12384]: [12445]: INFO: unmounted
/web successfully
Oct 3 16:17:41 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation fs0_stop_0 (call=26, rc=0) complete
Oct 3 16:17:41 lermontov tengine: [11897]: info: match_graph_event:
Action fs0_stop_0 (35) confirmed on lermontov
Oct 3 16:18:16 lermontov tengine: [11897]: WARN: status_from_rc:
Action start on tolstoy failed (target: <null> vs. rc: 2): Error
Oct 3 16:18:16 lermontov tengine: [11897]: info:
update_abort_priority: Abort priority upgraded to 1
Oct 3 16:18:16 lermontov tengine: [11897]: info:
update_abort_priority: Abort action 0 superceeded by 2
Oct 3 16:18:16 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerDatabase_start_0 (38) confirmed on tolstoy
Oct 3 16:18:16 lermontov tengine: [11897]: info: run_graph:
====================================================
Oct 3 16:18:16 lermontov tengine: [11897]: notice: run_graph:
Transition 2: (Complete=9, Pending=0, Fired=0, Skipped=2,
Incomplete=0)
Oct 3 16:18:16 lermontov crmd: [10423]: info: do_state_transition:
State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [
input=I_PE_CALC cause=C_IPC_MESSAGE origin=route_message ]
Oct 3 16:18:16 lermontov crmd: [10423]: info: do_state_transition:
All 2 cluster nodes are eligible to run resources.
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'stop' for cluster option 'no-quorum-policy'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'symmetric-cluster'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'false' for cluster option 'stonith-enabled'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'reboot' for cluster option 'stonith-action'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '0' for cluster option
'default-resource-stickiness'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '0' for cluster option
'default-resource-failure-stickiness'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'is-managed-default'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '60s' for cluster option 'cluster-delay'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '20s' for cluster option 'default-action-timeout'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'stop-orphan-resources'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'stop-orphan-actions'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'false' for cluster option 'remove-after-stop'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-error-series-max'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-warn-series-max'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value '-1' for cluster option 'pe-input-series-max'
Oct 3 16:18:16 lermontov pengine: [11898]: notice: cluster_option:
Using default value 'true' for cluster option 'startup-fencing'
Oct 3 16:18:16 lermontov pengine: [11898]: info:
determine_online_status: Node tolstoy is online
Oct 3 16:18:16 lermontov pengine: [11898]: WARN: unpack_rsc_op:
Processing failed op (WebServerDatabase_start_0) on tolstoy
Oct 3 16:18:16 lermontov pengine: [11898]: WARN: unpack_rsc_op:
Handling failed start for WebServerDatabase on tolstoy
Oct 3 16:18:16 lermontov pengine: [11898]: info:
determine_online_status: Node lermontov is online
Oct 3 16:18:16 lermontov pengine: [11898]: info:
unpack_find_resource: Internally renamed drbd0:0 on lermontov to
drbd0:1
Oct 3 16:18:16 lermontov pengine: [11898]: info: clone_print:
Master/Slave Set: ms-drbd0
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
drbd0:0 (heartbeat::ocf:drbd): Started tolstoy
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
drbd0:1 (heartbeat::ocf:drbd): Master lermontov
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
fs0 (heartbeat::ocf:Filesystem): Stopped
Oct 3 16:18:16 lermontov pengine: [11898]: info: group_print:
Resource Group: web_group
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
WebServerIP (heartbeat::ocf:IPaddr): Started tolstoy
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
WebServerDatabase (heartbeat::ocf:mysql): Started tolstoy FAILED
Oct 3 16:18:16 lermontov pengine: [11898]: info: native_print:
WebServerApache (heartbeat::ocf:apache): Stopped
Oct 3 16:18:16 lermontov pengine: [11898]: info: master_color:
Promoting drbd0:1
Oct 3 16:18:16 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:18:16 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:0 (tolstoy)
Oct 3 16:18:16 lermontov pengine: [11898]: notice: DemoteRsc:
lermontov Demote drbd0:1
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:1 (lermontov)
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange:
Leave resource drbd0:0 (tolstoy)
Oct 3 16:18:16 lermontov pengine: [11898]: info: master_color:
Promoted 1 instances of a possible 1 to master
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StartRsc:
lermontov Start fs0
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange: Move
resource WebServerIP (tolstoy -> lermontov)
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StopRsc:
tolstoy Stop WebServerIP
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StartRsc:
lermontov Start WebServerIP
Oct 3 16:18:16 lermontov pengine: [11898]: notice: NoRoleChange:
Recover resource WebServerDatabase (lermontov)
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StopRsc:
tolstoy Stop WebServerDatabase
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StartRsc:
lermontov Start WebServerDatabase
Oct 3 16:18:16 lermontov pengine: [11898]: notice: StartRsc:
lermontov Start WebServerApache
Oct 3 16:18:16 lermontov crmd: [10423]: info: do_state_transition:
State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [
input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=route_message ]
Oct 3 16:18:16 lermontov tengine: [11897]: info: unpack_graph:
Unpacked transition 3: 11 actions in 11 synapses
Oct 3 16:18:16 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 36: fs0_start_0 on lermontov
Oct 3 16:18:16 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 43 fired and confirmed
Oct 3 16:18:16 lermontov pengine: [11898]: info: process_pe_message:
Transition 3: PEngine Input stored in:
/home/hacluster/var/lib/heartbeat/pengine/pe-input-32.bz2
Oct 3 16:18:16 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 48 fired and confirmed
Oct 3 16:18:16 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 1: WebServerDatabase_stop_0 on tolstoy
Oct 3 16:18:16 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=fs0_start_0
key=36:3:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:18:18 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerDatabase_stop_0 (1) confirmed on tolstoy
Oct 3 16:18:18 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 37: WebServerIP_stop_0 on tolstoy
Oct 3 16:18:20 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerIP_stop_0 (37) confirmed on tolstoy
Oct 3 16:18:20 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 44 fired and confirmed
Oct 3 16:19:16 lermontov Filesystem[12451]: [12480]: INFO: Running
start for /dev/drbd0 on /web
Oct 3 16:19:16 lermontov Filesystem[12451]: [12486]: INFO: Starting
filesystem check on /dev/drbd0
Oct 3 16:19:16 lermontov lrmd: [10420]: info: RA output:
(fs0:start:stdout) fsck 1.40.2 (12-Jul-2007)
Oct 3 16:19:16 lermontov lrmd: [10420]: info: RA output:
(fs0:start:stdout) /sbin/fsck.xfs: XFS file system.
Oct 3 16:19:16 lermontov Filesystem "drbd0": Disabling barriers, not
supported by the underlying device
Oct 3 16:19:16 lermontov XFS mounting filesystem drbd0
Oct 3 16:19:16 lermontov Ending clean XFS mount for filesystem: drbd0
Oct 3 16:19:16 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation fs0_start_0 (call=27, rc=0) complete
Oct 3 16:19:16 lermontov crmd: [10423]: info: build_operation_update:
Digest for 0:0;36:3:a7d1bc2c-1d93-4542-bc68-19284a23514f (fs0_start_0)
was 422b283e3954598e187519e0eca9919c
Oct 3 16:19:16 lermontov crmd: [10423]: info: log_data_element:
build_operation_update: digest:source <parameters directory="/web"
device="/dev/drbd0"/>
Oct 3 16:19:16 lermontov tengine: [11897]: info: match_graph_event:
Action fs0_start_0 (36) confirmed on lermontov
Oct 3 16:19:16 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 41 fired and confirmed
Oct 3 16:19:16 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 38: WebServerIP_start_0 on lermontov
Oct 3 16:19:16 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerIP_start_0
key=38:3:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:19:16 lermontov IPaddr[12497]: [12527]: INFO: Using
calculated nic for 192.168.0.172: eth0
Oct 3 16:19:16 lermontov IPaddr[12497]: [12532]: INFO: Using
calculated netmask for 192.168.0.172: 255.255.255.0
Oct 3 16:19:16 lermontov IPaddr[12497]: [12537]: DEBUG: Using
calculated broadcast for 192.168.0.172: 192.168.0.255
Oct 3 16:19:16 lermontov IPaddr[12497]: [12554]: INFO: eval ifconfig
eth0:0 192.168.0.172 netmask 255.255.255.0 broadcast 192.168.0.255
Oct 3 16:19:16 lermontov IPaddr[12497]: [12559]: DEBUG: Sending
Gratuitous Arp for 192.168.0.172 on eth0:0 [eth0]
Oct 3 16:19:16 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerIP_start_0 (call=28, rc=0) complete
Oct 3 16:19:16 lermontov crmd: [10423]: info: build_operation_update:
Digest for 0:0;38:3:a7d1bc2c-1d93-4542-bc68-19284a23514f
(WebServerIP_start_0) was 5e0ac1259a9444e1b2ebd7f54e0efdce
Oct 3 16:19:16 lermontov crmd: [10423]: info: log_data_element:
build_operation_update: digest:source <parameters ip="192.168.0.172"/>
Oct 3 16:19:16 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerIP_start_0 (38) confirmed on lermontov
Oct 3 16:19:16 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 39: WebServerDatabase_start_0 on lermontov
Oct 3 16:19:16 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerDatabase_start_0
key=39:3:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:19:54 lermontov cib: [10419]: info: cib_stats: Processed
1142 operations (140.00us average, 0% utilization) in the last 10min
Oct 3 16:19:56 lermontov mysql[12573]: [12583]: DEBUG: MySQL is not running
Oct 3 16:19:56 lermontov mysql[12573]: [12589]: DEBUG: MySQL is not running
Oct 3 16:20:00 lermontov mysql[12573]: [12648]: INFO: MySQL started
Oct 3 16:20:00 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerDatabase_start_0 (call=29, rc=0) complete
Oct 3 16:20:00 lermontov crmd: [10423]: info: build_operation_update:
Digest for 0:0;39:3:a7d1bc2c-1d93-4542-bc68-19284a23514f
(WebServerDatabase_start_0) was c2c7512c42840a56031efa0e6e60cb2f
Oct 3 16:20:00 lermontov crmd: [10423]: info: log_data_element:
build_operation_update: digest:source <parameters
socket="/var/run/mysqld/mysqld.sock" binary="/usr/bin/mysqld_safe"
pid="/var/run/mysqld/mysqld.pid" config="/etc/mysql/my.cnf"
datadir="/web/mysql/"/>
Oct 3 16:20:00 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerDatabase_start_0 (39) confirmed on lermontov
Oct 3 16:20:00 lermontov tengine: [11897]: info: send_rsc_command:
Initiating action 40: WebServerApache_start_0 on lermontov
Oct 3 16:20:00 lermontov crmd: [10423]: info: do_lrm_rsc_op:
Performing op=WebServerApache_start_0
key=40:3:a7d1bc2c-1d93-4542-bc68-19284a23514f)
Oct 3 16:20:43 lermontov apache[12649]: [12700]: INFO: apache2: Could
not reliably determine the server's fully qualified domain name, using
192.168.0.171 for ServerName [Wed Oct 03 16:20:42 2007] [error] (EAI
2)Name or service not known: Failed to resolve server name for
192.168.0.172 (check DNS) -- or specify an explicit ServerName [Wed
Oct 03 16:20:42 2007] [warn] NameVirtualHost *:80 has no VirtualHosts
Oct 3 16:20:43 lermontov apache[12649]: [12705]: INFO: apache not running
Oct 3 16:20:43 lermontov apache[12649]: [12707]: INFO: waiting for
apache /etc/apache2/httpd.conf to come up
Oct 3 16:20:44 lermontov apache[12649]: [12724]: INFO: 16:20:44
URL:http://192.168.0.172:80/server-status [2695/2695] -> "-" [1]
Oct 3 16:20:44 lermontov crmd: [10423]: info: process_lrm_event: LRM
operation WebServerApache_start_0 (call=30, rc=0) complete
Oct 3 16:20:44 lermontov crmd: [10423]: info: build_operation_update:
Digest for 0:0;40:3:a7d1bc2c-1d93-4542-bc68-19284a23514f
(WebServerApache_start_0) was 05179dc21ab6ff461a7277057d0687a6
Oct 3 16:20:44 lermontov crmd: [10423]: info: log_data_element:
build_operation_update: digest:source <parameters
configfile="/etc/apache2/httpd.conf" options="-DINFO -DDEFAULT_VHOST
-DSTATUS -DPHP5" httpd="/usr/sbin/apache2"/>
Oct 3 16:20:44 lermontov tengine: [11897]: info: match_graph_event:
Action WebServerApache_start_0 (40) confirmed on lermontov
Oct 3 16:20:44 lermontov tengine: [11897]: info: te_pseudo_action:
Pseudo action 42 fired and confirmed
Oct 3 16:20:44 lermontov tengine: [11897]: info: run_graph:
Transition 3: (Complete=11, Pending=0, Fired=0, Skipped=0,
Incomplete=0)
Oct 3 16:20:44 lermontov tengine: [11897]: info: notify_crmd:
Transition 3 status: te_complete - <null>
Oct 3 16:20:44 lermontov crmd: [10423]: info: do_state_transition:
State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS
cause=C_IPC_MESSAGE origin=route_message ]
More information about the Linux-HA
mailing list