This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Up2date installation on HA killed slave

Hi

After investigating on how to do the Up2Date-installation in an active/passive HA environment I finally felt safe doing it.

15 minutes after clicking "Upgrade to latest version now" I ended up with a DEAD slave. Now it has passed 30 minutes and still the SLAVE is dead.

The log says:

2010:02:17-22:14:35 (none) ha_daemon[3539]: id="38A2" severity="error" sys="System" sub="ha" name="Node 2 died during up2date process!"
2010:02:17-22:14:35 (none) ha_daemon[3539]: id="38C1" severity="info" sys="System" sub="ha" name="Node 2 is dead, received no heart beats!"
2010:02:17-22:14:37 (none) slon_control[3668]: Killing slon reporting [21816]
2010:02:17-22:14:37 (none) slon_control[3668]: Killing slon pop3 [21817]
2010:02:17-22:14:45 (none) ha_daemon[3539]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
2010:02:17-22:14:47 (none) ha_daemon[3539]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
2010:02:17-22:14:56 (none) ha_daemon[3539]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
2010:02:17-22:14:57 (none) slon_control[3668]: Slon reporting exited with value 0!
2010:02:17-22:14:57 (none) slon_control[3668]: Slon pop3 exited with value 0!
2010:02:17-22:14:59 (none) ha_daemon[3539]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!" 


What am I doing wrong?


This thread was automatically locked due to age.
  • Since I cannot access the slave anymore I thoguht I might add a photo of the screen. It seems like the startup scripts have been mangled. It complains about not getting postgresql started, bad password in one startup script, all the services failed on run level 3 etc. etc. etc.

    Whats going on?

    This was going from 7.301 -> 7.503, but I dont know which package failed.
  • do you have a backup file for the slave?  If so might want to do a reload and restore.

    Owner:  Emmanuel Technology Consulting

    http://etc-md.com

    Former Sophos SG(Astaro) advocate/researcher/Silver Partner

    PfSense w/Suricata, ntopng, 

    Other addons to follow

  • I had a similar issue this evening when I applied the 7.503 update, the master pushed the update to the slave, slave got stuck in the up2date cycle, then barfed and halted.  Factory reset was required to bring it back.
    Second time (after the rebuild) it worked fine [:)]
  • I have  the standard backup files from webadmin, but no other than that. Is there special backup file for the slave that I missed?

    With factory reset I take it you have an appliance? We run on Supermicro servers. But do you mean, reinstall the whole server and restore the backup file with the Astaro configuration?

    If so, which version should I install? 7.503? 7.301 (dont have that one...)?
  • Hi Lindin,

    There are no special backup files for the slave - if you're rebuilding a slave, either rebuild it or factory reset it (available on both appliances and software/server version).
    Then perform the basic setup and then attach it to the cluster master via Management/High Availability menu.  If you built the slave with 7.502 after you join it to the cluster it will be upgraded to the same version running on the master.
  • Unbelievable, it happened again...

    Today I was about to go from 7.507 to 7.511

    Exactly the same happened, it got stuck, node 2 is dead. I shows up in the log on and off:

    2011:07:12-19:42:51 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:19 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:43:33 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:36 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:43:38 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:43 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="Access granted to remote node 2!"
    2011:07:12-19:49:19 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"

    I cannot believe how shaky this software is. Anyone else experience this? I really hesitate to update Astaro since it hangs everytime I do it.
  • Here is the log:

    2011:07:12-19:03:18 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="Initiating up2date process on node 2 to version latest"
    2011:07:12-19:03:18 rama-2 ha_daemon[19448]: id="38A0" severity="info" sys="System" sub="ha" name="--- Node is disabled ---"
    2011:07:12-19:03:18 rama-2 ha_daemon[19448]: id="38A0" severity="info" sys="System" sub="ha" name="Starting local up2date process to version latest"
    2011:07:12-19:03:18 rama-2 slon_control[20052]: Exiting...
    2011:07:12-19:03:18 rama-2 slon_control[20052]: Killing slon reporting [31918]
    2011:07:12-19:03:18 rama-2 slon[31920]: [18-1] INFO   remoteListenThread_1: disconnecting from 'dbname=reporting host=198.19.250.1 user=ha_sync password=slony'
    2011:07:12-19:03:20 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="Node 2 changed state: ACTIVE -> UP2DATE"
    2011:07:12-19:03:20 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="Waiting for 1 nodes to finish up2date process before initiating graceful takeover!"
    2011:07:12-19:03:20 rama-1 slon_control[3756]: Exiting...
    2011:07:12-19:03:20 rama-1 slon_control[3756]: Killing slon reporting [9859]
    2011:07:12-19:03:21 rama-2 slon_control[20052]: Killing slon pop3 [31919]
    2011:07:12-19:03:21 rama-2 slon[31922]: [18-1] INFO   remoteListenThread_1: disconnecting from 'dbname=pop3 host=198.19.250.1 user=ha_sync password=slony'
    2011:07:12-19:03:23 rama-1 slon_control[3756]: Killing slon pop3 [9860]
    2011:07:12-19:03:23 rama-1 slon[5056]: [12-1] INFO   remoteListenThread_2: disconnecting from 'dbname=pop3 host=198.19.250.2 user=ha_sync password=slony'
    2011:07:12-19:08:20 rama-1 slon[5029]: [12-1] ERROR  remoteListenThread_2: timeout (300 s) for event selection
    2011:07:12-19:20:16 rama-2 ctsyncd: received SIGTERM, exiting
    2011:07:12-19:20:16 rama-2 ha_daemon[19448]: id="38A0" severity="info" sys="System" sub="ha" name="--- Node is disabled ---"
    2011:07:12-19:20:16 rama-2 ha_daemon[19448]: id="38A0" severity="info" sys="System" sub="ha" name="HA daemon shutting down"
    2011:07:12-19:20:16 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="HA daemon of node 2 is restarting, waiting 900 seconds before declaring node as dead"
    2011:07:12-19:20:41 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:20:42 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:20:48 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:20:50 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:35:16 rama-1 ha_daemon[3537]: id="38A2" severity="error" sys="System" sub="ha" name="Node 2 died during up2date process!"
    2011:07:12-19:35:16 rama-1 ha_daemon[3537]: id="38C1" severity="info" sys="System" sub="ha" name="Node 2 is dead, received no heart beats!"
    2011:07:12-19:35:17 rama-1 slon_control[680]: Dropping privileges to user postgres with user ID 999 and group ID 999
    2011:07:12-19:35:17 rama-1 slon_control[682]: Starting ASG slon control on Node 1
    2011:07:12-19:35:23 rama-1 slon_control[682]: Set mode to MASTER
    2011:07:12-19:35:23 rama-1 slon_control[682]: Slonik error, process exited with value 255
    2011:07:12-19:35:23 rama-1 slon_control[682]: Slonik error, process exited with value 255
    2011:07:12-19:42:48 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:42:51 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:19 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:43:33 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:36 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-19:43:38 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Found link beat on eth5 again!"
    2011:07:12-19:43:43 rama-1 ha_daemon[3537]: id="38A0" severity="info" sys="System" sub="ha" name="Access granted to remote node 2!"
    2011:07:12-19:49:19 rama-1 ha_daemon[3537]: id="38A3" severity="debug" sys="System" sub="ha" name="Netlink: Lost link beat on eth5!"
    2011:07:12-20:18:45 rama-1 ctsyncd: ev_dispatch: callback failed (ev 0x8058ab0)
    2011:07:12-20:19:21 rama-1 ctsyncd: ctsyncd started
    2011:07:12-20:19:21 rama-1 ctsyncd: tuple-cache initialized (hashsize 512)
    2011:07:12-20:19:21 rama-1 ctsyncd: seq-cache initialized (hashsize 64)
    2011:07:12-20:19:21 rama-1 ctsyncd: joined mcast group 224.0.0.82:1999
    2011:07:12-20:19:21 rama-1 ctsyncd: new session 'default' (ip=198.19.250.1 grp=224.0.0.82:1999)
    2011:07:12-20:19:21 rama-1 ctsyncd: now running in INIT mode
    2011:07:12-20:19:21 rama-1 ctsyncd: now running in MASTER mode
    2011:07:12-20:32:24 rama-1 ctsyncd: ev_dispatch: callback failed (ev 0x8058ab0)
    2011:07:12-20:33:01 rama-1 ctsyncd: ctsyncd started
    2011:07:12-20:33:01 rama-1 ctsyncd: tuple-cache initialized (hashsize 512)
    2011:07:12-20:33:01 rama-1 ctsyncd: seq-cache initialized (hashsize 64)
    2011:07:12-20:33:01 rama-1 ctsyncd: joined mcast group 224.0.0.82:1999
    2011:07:12-20:33:01 rama-1 ctsyncd: new session 'default' (ip=198.19.250.1 grp=224.0.0.82:1999)
    2011:07:12-20:33:01 rama-1 ctsyncd: now running in INIT mode
    2011:07:12-20:33:01 rama-1 ctsyncd: now running in MASTER mode
    2011:07:12-20:34:04 rama-1 ctsyncd: ev_dispatch: callback failed (ev 0x8058ab0)
    2011:07:12-20:34:10 rama-1 ctsyncd: ev_dispatch: callback failed (ev 0x8058ab0)
    2011:07:12-20:34:39 rama-1 ctsyncd: ev_dispatch: callback failed (ev 0x8058ab0)
  • That looks the log during an Up2Date.  If you're convinced that it's not working, then you can disconnect the slave and factory reset it before reconnecting it:

    Login as root
    Type cc [enter]
    RAW [enter]
    system_factory_reset [enter] 

    Angelo commented recently on how a normal Up2Date proceeds in HA.

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Thanks for your answer.

    I had to reinstall the cluster the last time it happened, it is doable this time too. But I really would like to know why the slave ends up dead. It has gone 4 hours since I started the Up2date and the slave node is still dead. I am convinced it will not heal.

    I am sure factory reset / reinstallation will help me get back on track but it does not solve the main problem - that is; why does this happen?

    I would like to fix this without doing a factory reset, something is wrong and I guess it is interesting also for Astaro to solve this. 

    I will have to get the HA back on track this week, preferably tomorrow. I have registered a support case and hopefully I will get some clarity regarding this problem that keeps occurring when we update the FW.



    That looks the log during an Up2Date.  If you're convinced that it's not working, then you can disconnect the slave and factory reset it before reconnecting it:

    Login as root
    Type cc [enter]
    RAW [enter]
    system_factory_reset [enter] 

    Angelo commented recently on how a normal Up2Date proceeds in HA.

    Cheers - Bob