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.
Parents
  • 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)
Reply
  • 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)
Children
No Data