Sorry, my last attempts to grep for heartbeat from syslog failed to pick up the ResourceManager stuff. Apparently Filesystem is returning a code of 2 rather than 0 for some reason that I can't identify since it works perfectly when I run it manually:
Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27577]: debug: Starting /etc/ha.d/resource.d/drbddisk data start Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27581]: debug: /etc/ha.d/resource.d/drbddisk data start done. RC=0 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27614]: debug: Starting /etc/ha.d/resource.d/indhlc-fsck /dev/drbd0 jfs start Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27622]: debug: /etc/ha.d/resource.d/indhlc-fsck /dev/drbd0 jfs start done. RC=0 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27700]: debug: Starting /etc/ha.d/resource.d/Filesystem /dev/dbrd0 /mnt/data jfs start Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27751]: debug: /etc/ha.d/resource.d/Filesystem /dev/dbrd0 /mnt/data jfs start done. RC=2 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27770]: debug: Starting /etc/ha.d/resource.d/IPaddr2 10.233.93.42/24/eth0 stop Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27830]: debug: /etc/ha.d/resource.d/IPaddr2 10.233.93.42/24/eth0 stop done. RC=0 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27845]: debug: Starting /etc/ha.d/resource.d/Filesystem /dev/dbrd0 /mnt/data jfs stop Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27898]: debug: /etc/ha.d/resource.d/Filesystem /dev/dbrd0 /mnt/data jfs stop done. RC=0 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27913]: debug: Starting /etc/ha.d/resource.d/indhlc-fsck /dev/drbd0 jfs stop Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27920]: debug: /etc/ha.d/resource.d/indhlc-fsck /dev/drbd0 jfs stop done. RC=0 Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27935]: debug: Starting /etc/ha.d/resource.d/drbddisk data stop Aug 27 03:57:27 indhlcvms1 ResourceManager[27537]: [27939]: debug: /etc/ha.d/resource.d/drbddisk data stop done. RC=0 On Fri, Aug 27, 2010 at 3:49 AM, Casey Allen Shobe <[email protected]> wrote: > Hi all, > > I'm running heartbeat as it comes from Debian packages on Debian Lenny. > > I already have one cluster happily working. In that cluster, I'm using the > /etc/ha.d/resource.d/Filesystem script along with others. > > On a new cluster I'm trying to get going, well it just never becomes master > on either node. I have no idea why. When I run through every command in my > haresources by hand, they all work, including the Filesystem resource line. > > However I've found through trial and error that when I take out the > Filesystem line from haresources, it magically starts working, well that is, > except that my filesystem never gets mounted - but the other resources > successfully load as it becomes DRBD primary and gets the IP address, which > never happens if I put the Filesystem line in... I really can't see > anything that's wrong and have been hunting for hours now. > > Here is my haresources on a working cluster node - the Filesystem line is > EXACTLY THE SAME: > > indhlcwww1 drbddisk::data \ > indhlc-fsck::/dev/drbd0::jfs \ > Filesystem::/dev/drbd0::/mnt/data::jfs \ > > > Filesystem::/dev/shm::/mnt/data/share/nagios/var/spool/checkresults::tmpfs::uid=200,gid=200,mode=0755 > \ > IPaddr2::10.233.93.49/24/eth0 \ > indhlc-nginx \ > indhlc-service::mojomojo-fcgi \ > indhlc-service::c-fcgi \ > indhlc-service::php-fcgi \ > indhlc-service::nagios \ > indhlc-service::karma-fcgi \ > indhlc-service::karmabeta-fcgi \ > indhlc-service::rsyncd > > This is the haresources on a new node that is not working: > > indhlcvms1 drbddisk::data \ > indhlc-fsck::/dev/drbd0::jfs \ > Filesystem::/dev/dbrd0::/mnt/data::jfs \ > IPaddr2::10.233.93.42/24/eth0 > > However this haresources strangely works: > > indhlcvms1 drbddisk::data \ > indhlc-fsck::/dev/drbd0::jfs \ > IPaddr2::10.233.93.42/24/eth0 > > Here is the log when I the Filesystem line is present: > > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: WARN: node indhlcvms2: is > dead > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Comm_now_up(): > updating status to active > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Local status now set > to: 'active' > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: Sending local > starting msg: resourcestate = 0 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 0, other_is_stable: 0, takeover_in_progress: 0, > going_standby: 0, standby running(ms): 0, resourcestate: 0 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: CreateInitialFilter: > ask_resources > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: CreateInitialFilter: > hb_takeover > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: CreateInitialFilter: > ip-request > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: CreateInitialFilter: > ip-request-resp > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: CreateInitialFilter: > status > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: WARN: No STONITH device > configured. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: WARN: Shared disks are not > protected. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Resources being > acquired from indhlcvms2. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: > StartNextRemoteRscReq() - calling hook > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: notify_world: > invoking harc: OLD status: active > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: Process [status] > started pid 23230 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: Starting notify > process [status] > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: takeover_from_node: > other now stable > Aug 27 03:38:12 indhlcvms1 heartbeat: [23230]: debug: notify_world: setting > SIGCHLD Handler to SIG_DFL > Aug 27 03:38:12 indhlcvms1 heartbeat: [23230]: debug: notify_world: Running > harc status > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: Process > [req_our_resources] started pid 23231 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: debug: > req_our_resources(/usr/share/heartbeat/ResourceManager listkeys indhlcvms1) > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: debug: req_our_resources(): > running [/usr/share/heartbeat/req_resource drbddisk::data] > Aug 27 03:38:12 indhlcvms1 req_resource[23250]: [23302]: debug: in > /usr/share/heartbeat/req_resource drbddisk::data > Aug 27 03:38:12 indhlcvms1 mach_down[23261]: [23303]: info: > /usr/share/heartbeat/mach_down: nice_failback: foreign resources acquired > Aug 27 03:38:12 indhlcvms1 heartbeat: [23214]: WARN: ha_msg_add_nv_depth: > line doesn't contain '=' > Aug 27 03:38:12 indhlcvms1 heartbeat: [23214]: info: >>> > Aug 27 03:38:12 indhlcvms1 heartbeat: [23214]: ERROR: NV failure > (msgfromsteam): [>>>#012] > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: info: 1 local resources from > [/usr/share/heartbeat/ResourceManager listkeys indhlcvms1] > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: info: Local Resource > acquisition completed. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: debug: Sending hold > resources msg: all, stable=1 # req_our_resources() > Aug 27 03:38:12 indhlcvms1 heartbeat: [23231]: info: FIFO message [type > resource] written rc=79 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: AnnounceTakeover(local > 0, foreign 1, reason 'T_RESOURCES' (0)) > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: AnnounceTakeover(local > 1, foreign 1, reason 'T_RESOURCES(us)' (0)) > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Initial resource > acquisition complete (T_RESOURCES(us)) > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: STATE 1 => 3 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 2, other_is_stable: 1, takeover_in_progress: 1, > going_standby: 0, standby running(ms): 0, resourcestate: 3 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Managed > req_our_resources process 23231 exited with return code 0. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: RscMgmtProc > 'req_our_resources' exited code 0 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: AnnounceTakeover(local > 1, foreign 1, reason 'req_our_resources' (1)) > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: > StartNextRemoteRscReq(): child count 1 > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: info: Managed status process > 23230 exited with return code 0. > Aug 27 03:38:12 indhlcvms1 heartbeat: [23209]: debug: RscMgmtProc 'status' > exited code 0 > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: info: Local Resource > acquisition completed. (none) > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: info: local resource > transition completed. > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: debug: Sending hold > resources msg: all, stable=1 # <none> > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: info: AnnounceTakeover(local > 1, foreign 1, reason 'T_RESOURCES(us)' (1)) > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 0, other_is_stable: 1, takeover_in_progress: 1, > going_standby: 0, standby running(ms): 0, resourcestate: 4 > Aug 27 03:38:22 indhlcvms1 heartbeat: [23209]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 0, other_is_stable: 1, takeover_in_progress: 1, > going_standby: 0, standby running(ms): 0, resourcestate: 4 > > ...and here is log output when it succeeds by taking out the Filesystem > line: > > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: WARN: node indhlcvms2: is > dead > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Comm_now_up(): > updating status to active > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Local status now set > to: 'active' > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Sending local > starting msg: resourcestate = 0 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 0, other_is_stable: 0, takeover_in_progress: 0, > going_standby: 0, standby running(ms): 0, resourcestate: 0 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: CreateInitialFilter: > ask_resources > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: CreateInitialFilter: > hb_takeover > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: CreateInitialFilter: > ip-request > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: CreateInitialFilter: > ip-request-resp > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: CreateInitialFilter: > status > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: WARN: No STONITH device > configured. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: WARN: Shared disks are not > protected. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Resources being > acquired from indhlcvms2. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: > StartNextRemoteRscReq() - calling hook > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: notify_world: > invoking harc: OLD status: active > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Process [status] > started pid 22460 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Starting notify > process [status] > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: takeover_from_node: > other now stable > Aug 27 03:36:50 indhlcvms1 heartbeat: [22460]: debug: notify_world: setting > SIGCHLD Handler to SIG_DFL > Aug 27 03:36:50 indhlcvms1 heartbeat: [22460]: debug: notify_world: Running > harc status > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Process > [req_our_resources] started pid 22461 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: debug: > req_our_resources(/usr/share/heartbeat/ResourceManager listkeys indhlcvms1) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: debug: req_our_resources(): > running [/usr/share/heartbeat/req_resource drbddisk::data] > Aug 27 03:36:50 indhlcvms1 mach_down[22488]: [22529]: info: > /usr/share/heartbeat/mach_down: nice_failback: foreign resources acquired > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 0, foreign 1, reason 'T_RESOURCES' (0)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 1, foreign 1, reason 'T_RESOURCES(us)' (0)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Initial resource > acquisition complete (T_RESOURCES(us)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: mach_down takeover > complete. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: process_resources(3): > other now stable > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 1, foreign 1, reason 'mach_down' (1)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: STATE 1 => 3 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 2, other_is_stable: 1, takeover_in_progress: 0, > going_standby: 0, standby running(ms): 0, resourcestate: 3 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Managed status process > 22460 exited with return code 0. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: RscMgmtProc 'status' > exited code 0 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: > StartNextRemoteRscReq(): child count 1 > Aug 27 03:36:50 indhlcvms1 req_resource[22485]: [22537]: debug: in > /usr/share/heartbeat/req_resource drbddisk::data > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: info: 1 local resources from > [/usr/share/heartbeat/ResourceManager listkeys indhlcvms1] > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: info: Local Resource > acquisition completed. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: debug: Sending hold > resources msg: all, stable=1 # req_our_resources() > Aug 27 03:36:50 indhlcvms1 heartbeat: [22461]: info: FIFO message [type > resource] written rc=79 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: > StartNextRemoteRscReq(): child count 1 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 1, foreign 1, reason 'T_RESOURCES(us)' (1)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: hb_rsc_isstable: > ResourceMgmt_child_count: 1, other_is_stable: 1, takeover_in_progress: 0, > going_standby: 0, standby running(ms): 0, resourcestate: 3 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: Managed > req_our_resources process 22461 exited with return code 0. > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: RscMgmtProc > 'req_our_resources' exited code 0 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 1, foreign 1, reason 'req_our_resources' (1)) > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: > StartNextRemoteRscReq() - calling hook > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: notify_world: > invoking harc: OLD status: active > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Process > [ip-request-resp] started pid 22542 > Aug 27 03:36:50 indhlcvms1 heartbeat: [22417]: debug: Starting notify > process [ip-request-resp] > Aug 27 03:36:50 indhlcvms1 heartbeat: [22542]: debug: notify_world: setting > SIGCHLD Handler to SIG_DFL > Aug 27 03:36:50 indhlcvms1 heartbeat: [22542]: debug: notify_world: Running > harc ip-request-resp > Aug 27 03:36:51 indhlcvms1 IPaddr2[22754]: [22793]: INFO: > /usr/lib/heartbeat/send_arp -i 200 -r 5 -p > /var/run/heartbeat/rsctmp/send_arp/send_arp-10.233.93.42 eth0 10.233.93.42 > auto not_used not_used > Aug 27 03:36:51 indhlcvms1 heartbeat: [22417]: info: Managed > ip-request-resp process 22542 exited with return code 0. > Aug 27 03:36:51 indhlcvms1 heartbeat: [22417]: debug: RscMgmtProc > 'ip-request-resp' exited code 0 > Aug 27 03:36:51 indhlcvms1 heartbeat: [22417]: info: AnnounceTakeover(local > 1, foreign 1, reason 'ip-request-resp' (1)) > > Same node, just walking through the resources manually with heartbeat > stopped: > > # /etc/ha.d/resource.d/drbddisk data start > > # /etc/ha.d/resource.d/indhlc-fsck /dev/drbd0 jfs start > /sbin/fsck.jfs version 1.1.12, 24-Aug-2007 > processing started: 8/27/2010 3.48.13 > Using default parameter: -p > The current device is: /dev/drbd0 > Block size in bytes: 4096 > Filesystem size in blocks: 26213591 > **Phase 0 - Replay Journal Log > Filesystem is clean. > > # /etc/ha.d/resource.d/Filesystem /dev/drbd0 /mnt/data jfs start > 2010/08/27_03:48:26 INFO: Running start for /dev/drbd0 on /mnt/data > 2010/08/27_03:48:26 INFO: Success > INFO: Success > > # /etc/ha.d/resource.d/IPaddr2 10.233.93.42/24/eth0 start > 2010/08/27_03:48:41 INFO: ip -f inet addr add 10.233.93.42/24 brd > 10.233.93.255 dev eth0 > 2010/08/27_03:48:41 INFO: ip link set eth0 up > 2010/08/27_03:48:41 INFO: /usr/lib/heartbeat/send_arp -i 200 -r 5 -p > /var/run/heartbeat/rsctmp/send_arp/send_arp-10.233.93.42 eth0 10.233.93.42 > auto not_used not_used > 2010/08/27_03:48:41 INFO: Success > INFO: Success > > Thanks in advance for any help, > -- > Casey Allen Shobe > [email protected] > -- Casey Allen Shobe [email protected] _______________________________________________ Linux-HA mailing list [email protected] http://lists.linux-ha.org/mailman/listinfo/linux-ha See also: http://linux-ha.org/ReportingProblems
