Hi,

I've got an active-passive Heartbeat cluster with Apache, MySQL, ActiveMQ and DRBD.

Today, I wanted to perform hardware-maintenance on the secondary node (node04), so I stopped the heartbeat service before shutting it down.

Then, the primary node (node03) received a shutdown notice from the secondary node (node04).

This logging comes from the primary node: node03

heartbeat[4458]: 2010/03/08_08:52:56 info: Received shutdown notice from 'node04.companydomain.nl'.
heartbeat[4458]: 2010/03/08_08:52:56 info: Resources being acquired from node04.companydomain.nl.
harc[27522]:    2010/03/08_08:52:56 info: Running /etc/ha.d/rc.d/status status
heartbeat[27523]: 2010/03/08_08:52:56 info: Local Resource acquisition completed.
mach_down[27567]:       2010/03/08_08:52:56 info: /usr/share/heartbeat/mach_down: nice_failback: foreign resources acquired
mach_down[27567]:       2010/03/08_08:52:56 info: mach_down takeover complete for node node04.companydomain.nl.
heartbeat[4458]: 2010/03/08_08:52:56 info: mach_down takeover complete.
harc[27620]:    2010/03/08_08:52:56 info: Running /etc/ha.d/rc.d/ip-request-resp ip-request-resp
ip-request-resp[27620]: 2010/03/08_08:52:56 received ip-request-resp drbddisk OK yes
ResourceManager[27645]: 2010/03/08_08:52:56 info: Acquiring resource group: node03.companydomain.nl drbddisk Filesystem::/dev/drbd0::/data::ext3 mysql apache::/etc/httpd/conf/httpd.conf LVSSyncDaemonSwap::master monitor activemq tivoli-cluster MailTo::[email protected]::DRBDFailureDrisAcc MailTo::[email protected]::DRBDFailureDrisAcc 1.2.3.212
ResourceManager[27645]: 2010/03/08_08:52:56 info: Running /etc/ha.d/resource.d/drbddisk  start
Filesystem[27700]:      2010/03/08_08:52:57 INFO:  Running OK
ResourceManager[27645]: 2010/03/08_08:52:57 info: Running /etc/ha.d/resource.d/mysql  start
mysql[27783]:   2010/03/08_08:52:57 Starting MySQL[ OK ]
apache[27853]:  2010/03/08_08:52:57 INFO:  Running OK
ResourceManager[27645]: 2010/03/08_08:52:57 info: Running /etc/ha.d/resource.d/monitor  start
monitor[28160]: 2010/03/08_08:52:58
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/activemq  start
activemq[28210]:        2010/03/08_08:52:58 Starting ActiveMQ Broker... ActiveMQ Broker is already running.
ResourceManager[27645]: 2010/03/08_08:52:58 ERROR: Return code 1 from /etc/ha.d/resource.d/activemq
ResourceManager[27645]: 2010/03/08_08:52:58 CRIT: Giving up resources due to failure of activemq
ResourceManager[27645]: 2010/03/08_08:52:58 info: Releasing resource group: node03.companydomain.nl drbddisk Filesystem::/dev/drbd0::/data::ext3 mysql apache::/etc/httpd/conf/httpd.conf LVSSyncDaemonSwap::master monitor activemq tivoli-cluster MailTo::[email protected]::DRBDFailureDrisAcc MailTo::[email protected]::DRBDFailureDrisAcc 1.2.3.212
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/IPaddr 1.2.3.212 stop
IPaddr[28329]:  2010/03/08_08:52:58 INFO: ifconfig eth0:0 down
IPaddr[28312]:  2010/03/08_08:52:58 INFO:  Success
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/MailTo [email protected] DRBDFailureDrisAcc stop
MailTo[28378]:  2010/03/08_08:52:58 INFO:  Success
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/MailTo [email protected] DRBDFailureDrisAcc stop
MailTo[28433]:  2010/03/08_08:52:58 INFO:  Success
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/tivoli-cluster  stop
ResourceManager[27645]: 2010/03/08_08:52:58 info: Running /etc/ha.d/resource.d/activemq  stop
activemq[28503]:        2010/03/08_08:53:01 Stopping ActiveMQ Broker... Stopped ActiveMQ Broker.
ResourceManager[27645]: 2010/03/08_08:53:01 info: Running /etc/ha.d/resource.d/monitor  stop
monitor[28681]: 2010/03/08_08:53:01
ResourceManager[27645]: 2010/03/08_08:53:01 info: Running /etc/ha.d/resource.d/LVSSyncDaemonSwap master stop
LVSSyncDaemonSwap[28714]:       2010/03/08_08:53:02 info: ipvs_syncmaster down
LVSSyncDaemonSwap[28714]:       2010/03/08_08:53:02 info: ipvs_syncbackup up
LVSSyncDaemonSwap[28714]:       2010/03/08_08:53:02 info: ipvs_syncmaster released
ResourceManager[27645]: 2010/03/08_08:53:02 info: Running /etc/ha.d/resource.d/apache /etc/httpd/conf/httpd.conf stop
apache[28782]:  2010/03/08_08:53:03 INFO: Killing apache PID 18390
apache[28782]:  2010/03/08_08:53:03 INFO: apache stopped.
apache[28771]:  2010/03/08_08:53:03 INFO:  Success
ResourceManager[27645]: 2010/03/08_08:53:03 info: Running /etc/ha.d/resource.d/mysql  stop
mysql[28851]:   2010/03/08_08:53:24 Shutting down MySQL.....................[ OK ]
ResourceManager[27645]: 2010/03/08_08:53:24 info: Running /etc/ha.d/resource.d/Filesystem /dev/drbd0 /data ext3 stop
Filesystem[29010]:      2010/03/08_08:53:25 INFO: Running stop for /dev/drbd0 on /data
Filesystem[29010]:      2010/03/08_08:53:25 INFO: Trying to unmount /data
Filesystem[29010]:      2010/03/08_08:53:25 ERROR: Couldn't unmount /data; trying cleanup with SIGTERM
Filesystem[29010]:      2010/03/08_08:53:25 INFO: Some processes on /data were signalled
Filesystem[29010]:      2010/03/08_08:53:27 INFO: unmounted /data successfully
Filesystem[28999]:      2010/03/08_08:53:27 INFO:  Success
ResourceManager[27645]: 2010/03/08_08:53:27 info: Running /etc/ha.d/resource.d/drbddisk  stop
heartbeat[4458]: 2010/03/08_08:53:29 WARN: node node04.companydomain.nl: is dead
heartbeat[4458]: 2010/03/08_08:53:29 info: Dead node node04.companydomain.nl gave up resources.
heartbeat[4458]: 2010/03/08_08:53:29 info: Link node04.companydomain.nl:eth0 dead.
heartbeat[4458]: 2010/03/08_08:53:29 info: Link node04.companydomain.nl:eth1 dead.
hb_standby[29193]:      2010/03/08_08:53:57 Going standby [foreign].
heartbeat[4458]: 2010/03/08_08:53:57 info: node03.companydomain.nl wants to go standby [foreign]

Soo... What just happened here???

• Heartbeat on node04 stopped and told node03, which was the active node at the time.
• Somehow, node03 decided to start the cluster processes that were already running. (For the processes that are not critical, I always return a 0 from the startupscript so it does not stops the entire cluster when a non-essential part fails.)
• When starting ActiveMQ, it returns status 1 because it is already running.
• This fails the node and shuts everything down. As heartbeat is not running on the secondary node, it cannot failover to there.

When I tried to run ha_takeover to restart the resources, absolutely nothing happened.

Only after I restarted heartbeat on the primary node the resources could be started (after a delay of 2 minutes).

These are my questions:

• Why does heartbeat on the primary node try to start the cluster processes again?
• Why did ha_takeover not work?
• What can I do to prevent this from happening?

Server configuration:

DRBD:

version: 8.3.7 (api:88/proto:86-91)
GIT-hash: ea9e28dbff98e331a62bcbcc63a6135808fe2917 build by [email protected], 2010-01-20 09:14:48
 0: cs:Connected ro:Secondary/Primary ds:UpToDate/UpToDate B r----
    ns:0 nr:6459432 dw:6459432 dr:0 al:0 bm:301 lo:0 pe:0 ua:0 ap:0 ep:1 wo:d oos:0

uname -a

Linux node04 2.6.18-164.11.1.el5 #1 SMP Wed Jan 6 13:26:04 EST 2010 x86_64 x86_64 x86_64 GNU/Linux

haresources

node03.companydomain.nl \
          drbddisk \
          Filesystem::/dev/drbd0::/data::ext3 \
          mysql \
          apache::/etc/httpd/conf/httpd.conf \
          LVSSyncDaemonSwap::master \
          monitor \
          activemq \
          tivoli-cluster \
          MailTo::[email protected]::DRBDFailureDrisAcc \
          MailTo::[email protected]::DRBDFailureDrisAcc \
          1.2.3.212

ha.cf

debugfile /var/log/ha-debug
logfile /var/log/ha-log
keepalive 500ms
deadtime 30
warntime 10
initdead 120
udpport 694
mcast eth0 225.0.0.3 694 1 0
mcast eth1 225.0.0.4 694 1 0
auto_failback off
node    node03.companydomain.nl
node    node04.companydomain.nl

respawn hacluster /usr/lib64/heartbeat/dopd
apiauth dopd gid=haclient uid=hacluster

Thank you very much in advance,

Ger Apeldoorn