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

HA - Passive node unstable

Hey,

I've got two UTM v9.307-6 boxes which exist as VMs on two separate Hyper-V servers.

I had been running one in a non-HA configuration for a while, so I'm happy that's stable.

A couple of nights ago I built a new UTM virtual machine and used the HA automatic configuration set it up in a Hot/Standby configuration.

This went okay, and it's synced its config to the new server and placed the slave node in 'READY'.  It's intended that the original VM remain the Primary Master, so I've confirmed that, and also set a Backup Interface.

My problem is that according to the master, the Slave node keeps changing its status to DEAD every half hour or so.  After about a minute of it disappearing, the slave VM returns and the status moves to SYNCING and then back to READY at which point it seems to be working again happily.

What's not fine is that it's doing it every 20 minutes.

When the slave is in READY mode and I intentionally kill connectivity to the Master node, the slave node successfully takes over as expected; and when the preferred master comes back online it successfully transitions control back to the original node.

When the slave node fails there's no impact to the network as such, the master node happily continues serving requests, however, clearly that wouldn't be the case if the master node failed at the same moment the slave node was marked as DEAD.

The Hyper-V server of the slave isn't as powerful as the one which is primary master, however, they're both sitting on average at 
2015:02:13-00:41:10 home-1 ha_daemon[10438]: id="38C1" severity="error" sys="System" sub="ha" seq="M:  959 10.875" name="Node 2 is dead, received no heart beats"

2015:02:13-00:41:11 home-1 ha_mode[782]: daemonized...
2015:02:13-00:41:11 home-1 repctl[797]:  daemonize_check(1958): trying to signal daemon
2015:02:13-00:41:13 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  960 13.207" name="Reading cluster configuration"
2015:02:13-00:41:28 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  961 28.698" name="Monitoring interfaces for link beat: eth1 eth0"
2015:02:13-00:41:28 home-1 ha_daemon[10438]: id="38A3" severity="debug" sys="System" sub="ha" seq="M:  962 28.699" name="Netlink: Found link beat on eth2 again!"
2015:02:13-00:41:34 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  963 34.205" name="Node 2 changed version! 0.000000 -> 9.307006"
2015:02:13-00:41:34 home-1 ha_daemon[10438]: id="38A1" severity="warn" sys="System" sub="ha" seq="M:  964 34.205" name="Lost heartbeat message from node 2! Expected 4474 but got 4499"
2015:02:13-00:41:34 home-1 ha_daemon[10438]: id="38C0" severity="info" sys="System" sub="ha" seq="M:  965 34.205" name="Node 2 is alive"
2015:02:13-00:41:34 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  966 34.205" name="Node 2 changed state: DEAD(2048) -> ACTIVE(0)"
2015:02:13-00:41:34 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  967 34.206" name="Node 2 changed role: DEAD -> SLAVE"
2015:02:13-00:41:34 home-2 ha_daemon[3652]: id="38A0" severity="info" sys="System" sub="ha" seq="S:  242 34.719" name="Node 1 changed version! 0.000000 -> 9.307006"
2015:02:13-00:41:34 home-2 ha_daemon[3652]: id="38A1" severity="warn" sys="System" sub="ha" seq="S:  243 34.720" name="Lost heartbeat message from node 1! Expected 82903 but got 82911"
2015:02:13-00:41:34 home-2 ha_daemon[3652]: id="38C0" severity="info" sys="System" sub="ha" seq="S:  244 34.720" name="Node 1 is alive"
2015:02:13-00:41:34 home-2 ha_daemon[3652]: id="38A0" severity="info" sys="System" sub="ha" seq="S:  245 34.720" name="Node 1 changed state: DEAD(2048) -> ACTIVE(0)"
2015:02:13-00:41:34 home-2 ha_daemon[3652]: id="38A0" severity="info" sys="System" sub="ha" seq="S:  246 34.720" name="Node 1 changed role: DEAD -> MASTER"
2015:02:13-00:41:35 home-2 ha_mode[18691]: daemonized...
2015:02:13-00:41:35 home-2 repctl[18712]:  daemonize_check(1958): trying to signal daemon
2015:02:13-00:41:35 home-2 ha_mode[18702]: daemonized...
2015:02:13-00:41:35 home-2 repctl[18720]:  daemonize_check(1958): trying to signal daemon
2015:02:13-00:41:36 home-1 ha_mode[986]: daemonized...
2015:02:13-00:41:36 home-1 repctl[1002]:  daemonize_check(1958): trying to signal daemon
2015:02:13-00:41:37 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  968 37.867" name="Reading cluster configuration"
2015:02:13-00:41:43 home-2 ha_daemon[3652]: id="38A0" severity="info" sys="System" sub="ha" seq="S:  247 43.469" name="Monitoring interfaces for link beat: eth1 eth0"
2015:02:13-00:41:53 home-1 ha_daemon[10438]: id="38A0" severity="info" sys="System" sub="ha" seq="M:  969 53.422" name="Monitoring interfaces for link beat: eth1 eth0"[/code]


This thread was automatically locked due to age.
Parents
  • Alan, you're new here, so you wouldn't know that one of the unwritten rules is "one topic per thread."  Accordingly, please edit the last message and transfer your new question to a new thread in the forum that covers Reporting.

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Alan, you're new here, so you wouldn't know that one of the unwritten rules is "one topic per thread." 


    Yeah, fair enough. I actually started typing up the post in a new thread but decided that it probably wasn't a coincidence with the HA issues so ended up throwing it here.

    Anyway, going back to the HA issue. After the the dead_time counter things are looking a bit better; I'm no longer getting the 'HA Node is now Master' / 'HA Node is now Slave' emails every 20 minutes.

    However, I've started to get some new weird email notifications instead.

    Example 1:
    The High Availability System is active and fully functional.

    You are receiving this message due to one of the following cases:
    * The HA System has been successfully initiated for the first time.
    * All HA nodes have returned into Active state again
      - after they had been Unlinked or
      - after they had been Dead and a reboot was forced or
      - after an Up2Date process has been successfully finished.

    --
    HA Status          : HA MASTER (node id: 1)
    System Uptime      : 1 day 1 hour 37 minutes
    System Load        : 1.31


    System Version     : Sophos UTM 9.307-6

    Please refer to the manual for detailed instructions.
    Example 2:
    HA selfcheck: Please see attached logfile
    --
    HA Status          : HA SLAVE (node id: 2)
    System Uptime      : 1 day 4 hours 18 minutes
    System Load        : 2.11


    System Version     : Sophos UTM 9.307-6

    Please refer to the manual for detailed instructions.
    The attached file to that second email reads "[FONT="Courier New"]HA SELFMON WARN: Restarting repctl for SLAVE[/FONT]"

    EDIT: hmmm, to make things more interesting, I just checked out the HA log and found this:
    2015:02:15-19:59:32 home-2 ha_mode[18691]: parse at repctl.pl line 156.
    
    2015:02:15-19:59:32 home-2 ha_mode[18691]: HA SELFMON WARN: Restarting repctl for SLAVE
    2015:02:15-20:54:32 home-2 ha_mode[24721]: 2015-02-15 20:54:32 [24737] [e] [db_connect(2648)] error while connecting to database: could not connect to server: Connection refused
    2015:02:15-20:54:32 home-2 ha_mode[24721]: Is the server running on host "198.19.250.1" and accepting
    2015:02:15-20:54:32 home-2 ha_mode[24721]: TCP/IP connections on port 5432?
    2015:02:15-20:54:32 home-2 ha_mode[24721]: 2015-02-15 20:54:32 [24737] [e] [master_connection(2552)] could not connect to server: Connection refused
    2015:02:15-20:54:32 home-2 ha_mode[24721]: Is the server running on host "198.19.250.1" and accepting
    2015:02:15-20:54:32 home-2 ha_mode[24721]: TCP/IP connections on port 5432?
    2015:02:15-20:54:32 home-2 ha_mode[24721]: parse at repctl.pl line 156.
    2015:02:15-20:54:32 home-2 ha_mode[24721]: HA SELFMON WARN: Restarting repctl for SLAVE
    Maybe the issues are related, is there maybe a problem with the daemon?
Reply
  • Alan, you're new here, so you wouldn't know that one of the unwritten rules is "one topic per thread." 


    Yeah, fair enough. I actually started typing up the post in a new thread but decided that it probably wasn't a coincidence with the HA issues so ended up throwing it here.

    Anyway, going back to the HA issue. After the the dead_time counter things are looking a bit better; I'm no longer getting the 'HA Node is now Master' / 'HA Node is now Slave' emails every 20 minutes.

    However, I've started to get some new weird email notifications instead.

    Example 1:
    The High Availability System is active and fully functional.

    You are receiving this message due to one of the following cases:
    * The HA System has been successfully initiated for the first time.
    * All HA nodes have returned into Active state again
      - after they had been Unlinked or
      - after they had been Dead and a reboot was forced or
      - after an Up2Date process has been successfully finished.

    --
    HA Status          : HA MASTER (node id: 1)
    System Uptime      : 1 day 1 hour 37 minutes
    System Load        : 1.31


    System Version     : Sophos UTM 9.307-6

    Please refer to the manual for detailed instructions.
    Example 2:
    HA selfcheck: Please see attached logfile
    --
    HA Status          : HA SLAVE (node id: 2)
    System Uptime      : 1 day 4 hours 18 minutes
    System Load        : 2.11


    System Version     : Sophos UTM 9.307-6

    Please refer to the manual for detailed instructions.
    The attached file to that second email reads "[FONT="Courier New"]HA SELFMON WARN: Restarting repctl for SLAVE[/FONT]"

    EDIT: hmmm, to make things more interesting, I just checked out the HA log and found this:
    2015:02:15-19:59:32 home-2 ha_mode[18691]: parse at repctl.pl line 156.
    
    2015:02:15-19:59:32 home-2 ha_mode[18691]: HA SELFMON WARN: Restarting repctl for SLAVE
    2015:02:15-20:54:32 home-2 ha_mode[24721]: 2015-02-15 20:54:32 [24737] [e] [db_connect(2648)] error while connecting to database: could not connect to server: Connection refused
    2015:02:15-20:54:32 home-2 ha_mode[24721]: Is the server running on host "198.19.250.1" and accepting
    2015:02:15-20:54:32 home-2 ha_mode[24721]: TCP/IP connections on port 5432?
    2015:02:15-20:54:32 home-2 ha_mode[24721]: 2015-02-15 20:54:32 [24737] [e] [master_connection(2552)] could not connect to server: Connection refused
    2015:02:15-20:54:32 home-2 ha_mode[24721]: Is the server running on host "198.19.250.1" and accepting
    2015:02:15-20:54:32 home-2 ha_mode[24721]: TCP/IP connections on port 5432?
    2015:02:15-20:54:32 home-2 ha_mode[24721]: parse at repctl.pl line 156.
    2015:02:15-20:54:32 home-2 ha_mode[24721]: HA SELFMON WARN: Restarting repctl for SLAVE
    Maybe the issues are related, is there maybe a problem with the daemon?
Children
No Data