<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"> <head> <meta http-equiv=Content-Type content="text/html; charset=us-ascii"> <meta name=Generator content="Microsoft Word 12 (filtered medium)"> <style>  </style>  </head> <body lang=EN-US link=blue vlink=purple> <div class=WordSection1> Hi,<o:p></o:p> <o:p> </o:p> We have hit a snag during testing of a 3-node cluster, where only nodes 1 and 2 are allowed to run the service.<o:p></o:p> <o:p> </o:p> If we shutdown the node running the service, the service first starts on the surviving node, but is then stopped. This is not an activity we would normally expect to do, but some of the environment monitoring in our servers can trigger this situation - temperature getting too high etc.<o:p></o:p> <o:p> </o:p> What I think happens is the following:<o:p></o:p> <o:p> </o:p> <![if !supportLists]>1. <![endif]>host 1: shutdown calls on rgmanager to stop: this takes several seconds, stopping the service.<o:p></o:p> <![if !supportLists]>2. <![endif]>host 2: rgmanager starts to relocate the service to the surviving node<o:p></o:p> <![if !supportLists]>3. <![endif]>host 1: shutdown calls on cman to stop<o:p></o:p> <![if !supportLists]>4. <![endif]>host 2: while relocating the service, cman enters gather state because host 1 has dropped out. The service is still starting and triggers "Failed changing service status" in log below.<o:p></o:p> <![if !supportLists]>5. <![endif]>host 1: halts<o:p></o:p> <![if !supportLists]>6. <![endif]>host 2: the service completes start up. The cluster reconfiguration completes. <o:p></o:p> <![if !supportLists]>7. <![endif]>host 2: the service is stopped.<o:p></o:p> <o:p> </o:p> Is this a bug in the cluster system, or just an unfortunate sequence of events that the cluster cannot cope with, i.e. node failure while a service is relocating ?<o:p></o:p> <o:p> </o:p> regards,<o:p></o:p> Martin<o:p></o:p> <o:p> </o:p> Here is the log from node 2:<o:p></o:p> <o:p> </o:p> Aug 16 16:58:40 gmhcluster2 clurgmgrd[4132]: <notice> Member 1 shutting down<o:p></o:p> Aug 16 16:58:40 gmhcluster2 openais[4084]: [TOTEM] Retransmit List: 86<o:p></o:p> Aug 16 16:58:46 gmhcluster2 clurgmgrd[4132]: <notice> Starting stopped service service:MASTERVIP<o:p></o:p> Aug 16 16:58:55 gmhcluster2 openais[4084]: [TOTEM] The token was lost in the OPERATIONAL state.<o:p></o:p> Aug 16 16:58:55 gmhcluster2 openais[4084]: [TOTEM] Receive multicast socket recv buffer size (320000 bytes).<o:p></o:p> Aug 16 16:58:55 gmhcluster2 openais[4084]: [TOTEM] Transmit multicast socket send buffer size (262142 bytes).<o:p></o:p> Aug 16 16:58:55 gmhcluster2 openais[4084]: [TOTEM] entering GATHER state from 2.<o:p></o:p> Aug 16 16:59:01 gmhcluster2 clurgmgrd[4132]: <err> #47: Failed changing service status<o:p></o:p> Aug 16 16:59:01 gmhcluster2 clurgmgrd[4132]: <warning> #71: Relocating failed service service:MASTERVIP<o:p></o:p> Aug 16 16:59:01 gmhcluster2 clurgmgrd[4132]: <warning> #70: Failed to relocate service:MASTERVIP; restarting locally<o:p></o:p> Aug 16 16:59:01 gmhcluster2 clurgmgrd[4132]: <notice> Starting stopped service service:MASTERVIP<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] entering GATHER state from 0.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] Creating commit token because I am the rep.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] Saving state aru 90 high seq received 90<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] Storing new sequence id for ring 1e4<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] entering COMMIT state.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] entering RECOVERY state.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] position [0] member 172.30.31.4:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] previous ring seq 480 rep 172.30.31.3<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] aru 90 high delivered 90 received flag 1<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] position [1] member 172.30.31.5:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] previous ring seq 480 rep 172.30.31.3<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] aru 90 high delivered 90 received flag 1<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] Did not need to originate any messages in recovery.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 kernel: dlm: closing connection to node 1<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] Sending initial ORF token<o:p></o:p> Aug 16 16:59:15 gmhcluster2 clurgmgrd: [4132]: <info> Executing /usr/sbin/dc-cluster-resourceagent start<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] CLM CONFIGURATION CHANGE<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] New Configuration:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] r(0) ip(172.30.31.4)<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] r(0) ip(172.30.31.5)<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] Members Left:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] r(0) ip(172.30.31.3)<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] Members Joined:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] CLM CONFIGURATION CHANGE<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] New Configuration:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] r(0) ip(172.30.31.4)<o:p></o:p> Aug 16 16:59:15 gmhcluster2 /usr/sbin/dc-cluster-resourceagent: [2492] INFO - ACTIVESITE in state started<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] r(0) ip(172.30.31.5)<o:p></o:p> Aug 16 16:59:15 gmhcluster2 /usr/sbin/dc-cluster-resourceagent: [2492] INFO - ACTIVESITE service is running - ACTIVESITE in state started<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] Members Left:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 /usr/sbin/dc-cluster-resourceagent: [2492] INFO - Service MASTERVIP: Performing precautionary updates to databases before setting up VIP<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [CLM ] Members Joined:<o:p></o:p> Aug 16 16:59:15 gmhcluster2 /usr/sbin/dc-cluster-resourceagent: [2492] INFO - Service MASTERVIP: running precautionary update [touch /tmp/dc-set-dr-counters] <o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [SYNC ] This node is within the primary component and will provide service.<o:p></o:p> Aug 16 16:59:15 gmhcluster2 /usr/sbin/dc-cluster-resourceagent: [2492] INFO - Service MASTERVIP: running precautionary update [touch /tmp/dc-set-dr-auto-increments]<o:p></o:p> Aug 16 16:59:15 gmhcluster2 openais[4084]: [TOTEM] entering OPERATIONAL state.<o:p></o:p> Aug 16 16:59:16 gmhcluster2 openais[4084]: [CLM ] got nodejoin message 172.30.31.4<o:p></o:p> Aug 16 16:59:16 gmhcluster2 openais[4084]: [CLM ] got nodejoin message 172.30.31.5<o:p></o:p> Aug 16 16:59:16 gmhcluster2 openais[4084]: [CPG ] got joinlist message from node 3<o:p></o:p> Aug 16 16:59:16 gmhcluster2 clurgmgrd: [4132]: <info> Adding IPv4 address 172.30.30.93/24 to bond0<o:p></o:p> Aug 16 16:59:16 gmhcluster2 openais[4084]: [CPG ] got joinlist message from node 2<o:p></o:p> Aug 16 16:59:17 gmhcluster2 clurgmgrd[4132]: <notice> Service service:MASTERVIP started<o:p></o:p> Aug 16 16:59:17 gmhcluster2 clurgmgrd[4132]: <notice> Stopping service service:MASTERVIP<o:p></o:p> Aug 16 16:59:17 gmhcluster2 clurgmgrd: [4132]: <info> Removing IPv4 address 172.30.30.93/24 from bond0<o:p></o:p> Aug 16 16:59:27 gmhcluster2 clurgmgrd: [4132]: <info> Executing /usr/sbin/dc-cluster-resourceagent stop<o:p></o:p> Aug 16 16:59:27 gmhcluster2 clurgmgrd[4132]: <notice> Service service:MASTERVIP is stopped<o:p></o:p> <o:p> </o:p> <o:p> </o:p> <o:p> </o:p> <o:p> </o:p> <o:p> </o:p> </div> </body> </html>