Watchdog

Tigase’s Watchdog was implemented to help Tigase close connections that have become stale or inactive. Sometimes the connection is delayed, maybe dropped packets, or a service interruption. After a time, if that connection is re-established, both server and client (or server and server) will continue on as if nothing happened. However, these gaps in connection can last longer, and some installations will rely on the operating system to detect and close stale connections. Some operating systems or environments can take up to 2 hours or more to determine whether a connection is bad and wait for a response from a foreign entity and may not be configured. This can not only slow down performance, but can lead to security issues as well. To solve this problem, we have introduced Watchdog to monitor connections independent of operating system and environments to keep those broken connections from becoming a problem.

Setup

No extra setup is necessary, Watchdog is already included with your build of Tigase (as long as it’s 7.1.0 or newer). Follow the steps in the configuration section.

Watchdog Configuration

To configure watchdog, the following lines need to be present or edited in init.properties file:

--watchdog_timeout=70000
--watchdog_delay=60000
--watchdog_ping_type=xmpp

The three settings are as follows: - --watchdog_timeout=70000 This setting sets the amount of time that watchdog will consider before it determines a connection may be stale. This setting sets the timeout at 70000ms or 70 seconds. - --watchdog_delay=60000 This setting sets how often the watchdog should conduct the check, current setting sets the delay at 60000ms or 60 seconds. - --watchdog_ping_type=whitespace This setting determines the type of ping sent to components when watchdog is testing for activity.

You may, if you choose, to specify individual watchdog settings for specific components by adding them to the component settings, for example if we wanted to change the Client2Server settings to include watchdog, use the following lines in init.properties:

c2s/watchdog_timeout=3000
c2s/watchdog_delay=1500

If any settings are not set, the global or settings will be used. watchdog_delay default is set to 10 min watchdog_ping_type default is set to xmpp

Logic

Watchdog compares it’s own pings, and records the time it takes for a round trip to different components, clustered connections, and if one variable is larger than the other, watchdog will commence closing that stale connection. Here is a breakdown:

  1. A check is performed of a connection(s) on every watchdog_delay interval.
  2. During this check two things occur

    • If the last transfer time exceeds max-inactivity-time a stop service command is given to terminate and broadcast unavailable presence.
    • If the last transfer time is lower than max-inactivity-time but exceeds watchdog_timeout watchdog will try to send a ping (of watchdog_ping_type). This ping may be one of two varieties (set in init.properties)

      • whitespace ping which will yield the time of the last data transfer in any direction.
      • xmpp ping which will yield the time of the last received xmpp stanza.
  3. If the 2nd option is true, the connection will remain open, and another check will begin after the watchdog_delay time has expired.

For example, lets draw this out and get a visual representation

This line represents how often the check is performed. Each - is 10 seconds, so the check is done every 60 seconds (watchdog_delay=60000)

-----+-----+-----+-----+-----+-----+-----+-----+-----+-----+-----+------

     |     |     |     |     |     |     |     |     |     |     |

This line is client activity, here the client has sent a message at 20 seconds and has gone idle.

-+------------------------------------------------------------------

The following line represents the logic, with settings set at: watchdog_timeout=120000 | +c2s/max-inactivity-time[L]=180000 (timeout at 120 seconds and max inactivity timeout at 180 seconds)

 1   2     3     4     5     6
-*---*-----*-----*-----*-----*

1 - 20 seconds - at this point "last transfer" or "last received" time is updated. 2 - 60 seconds - watchdog runs - it check the connection and says "ok, last client transfer was 20s ago - but it’s lower than both inactivity (so don’t disconnect) and timeout (so don’t send ping). 3 - 120 seconds - 2nd check - last transfer was 100s ago - still lower than both values - do nothing. 4 - 180 seconds - 3rd check - last transfer was 160s ago - lower than inactivity but greater than delay - ping it sent. 5 - 240 seconds - 4th check - last transfer was 220s ago - client still has not responded, watchdog compares idle time to max-inactivity-timeout and finds that it is greater, connection is terminated.

It is possible that the connection is broken, and could be detected during the sending of a ping and the connection would be severed at step 4 instead of waiting for step 5. NOTE This MAY cause JVM to throw an exception.

NOTE: Global settings may not be ideal for every setup. Since each component has its own settings for max-inactivity-time you may find it necessary to design custom watchdog settings, or edit the inactivity times to better suit your needs. Below is a short list of components with thier default settings:

bosh/max-inactivity-time[L]=600
c2s/max-inactivity-time[L]=86400
cl-comp/max-inactivity-time[L]=180
s2s/max-inactivity-time[L]=900
ws2s/max-inactivity-time[L]=86400

Again remember, for Watchdog to properly work, the max-inactivity-time MUST be longer than the watchdog_timeout setting

Testing

The tigase.log.0 file can reveal some information about watchdog and how it is working (or how it might be fighting your settings). To do so, enter the following line into your init.properties file:

--debug=server,xmpp.init

This will set debug mode for your log, and enable some more information about what Tigase is doing. These logs are truncated for simplicity. Lets look at the above scenario in terms of the logs:

Stage Two 2015-10-16 08:00:00.000 [Watchdog - c2s] ConnectionManager$Watchdog$1.check() FINEST: Testing service: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368 Socket[addr=/192.168.0.201,port=50368,localport=5222], jid: user@xmpp.domain.org/mobile, sinceLastTransfer: 20,000, maxInactivityTime: 180,000, watchdogTimeout: 120,000, watchdogDelay: 60,000, watchdogPingType: XMPP

Stage Three 2015-10-16 08:01:00.000 [Watchdog - c2s] ConnectionManager$Watchdog$1.check() FINEST: Testing service: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368 Socket[addr=/192.168.0.201,port=50368,localport=5222], jid: user@xmpp.domain.org/mobile, sinceLastTransfer: 100,000, maxInactivityTime: 180,000, watchdogTimeout: 120,000, watchdogDelay: 60,000, watchdogPingType: XMPP

Stage Four 2015-10-16 08:02:00.000 [Watchdog - c2s] ConnectionManager$Watchdog$1.check() FINEST: Testing service: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368 Socket[addr=/192.168.0.201,port=50368,localport=5222], jid: user@xmpp.domain.org/mobile, sinceLastTransfer: 160,000, maxInactivityTime: 180,000, watchdogTimeout: 120,000, watchdogDelay: 60,000, watchdogPingType: XMPP 2015-10-16 08:02:00.697 [Watchdog - c2s] ConnectionManager$Watchdog$1.check() FINEST: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368 Socket[addr=/192.168.0.201,port=50368,localport=5222], jid: user@xmpp.domain.org/mobile, sending XMPP ping from=null, to=null, DATA=<iq from="xmpp.domain.com" id="tigase-ping" to="user@xmpp.domain.com/mobile" type="get"><ping xmlns="urn:xmpp:ping"/></iq>, SIZE=134, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=get

Stage Five 2015-10-16 08:03:00.000 [Watchdog - c2s] ConnectionManager$Watchdog$1.check() FINEST: Testing service: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368 Socket[addr=/192.168.0.201,port=50368,localport=5222], jid: user@xmpp.domain.org/mobile, sinceLastTransfer: 100,000, maxInactivityTime: 180,000, watchdogTimeout: 120,000, watchdogDelay: 60,000, watchdogPingType: XMPP 2015-10-16 08:03:00.248 [pool-20-thread-6] ConnectionManager.serviceStopped() FINER: Connection stopped: c2s@xmpp./domain.com/192.168.0.150_5222_192.168.0.201_50368, type: accept, Socket: TLS: c2s@lenovo-z585/192.168.0.150_5222_192.168.0.201_50368 Socket[unconnected], jid: user@xmpp.domain.com 2015-10-16 08:03:00.248 [pool-20-thread-6] ClientConnectionManager.xmppStreamClosed() FINER: Stream closed: c2s@xmpp.domain.com/192.168.0.150_5222_192.168.0.201_50368