Report PVs by time since disconnect, and fail the healthcheck only in strict mode

README.md

@@ -64,6 +64,11 @@ The server sends each WebSocket client a ping every **WEBSOCKET_PING_INTERVAL_SE
 A client that stops reading makes writes to it block once the network buffers fill.  When a write blocks for **WEBSOCKET_SEND_TIMEOUT_SECONDS** (default 20, Tomcat's own default), Tomcat closes the session.  This setting applies only on Tomcat.
 
 
+### Healthcheck
+`/healthcheck` returns a JSON array of monitored PVs that haven't been connected for longer than **HEALTHCHECK_GRACE_SECONDS** (default 30), counted from when they disconnected, or from when monitoring began for a PV that never connected.  Each entry has the PV's `name`, its `state` (`DISCONNECTED`, or `CONNECTING` if it never connected), and `disconnected_minutes`.
+
+By default the response is 200 whenever the server is up, which suits load balancers: an IOC being down affects every instance alike.  With `?strict=true` the response is 503 when a PV that was connected has disconnected, which suits monitoring that should alert on that, such as Nagios.  PVs that never connected are listed but don't fail strict mode, since they may simply not exist.
+
 ### Logging
 This app is designed to run on Tomcat so [Tomcat logging configuration](https://tomcat.apache.org/tomcat-9.0-doc/logging.html) applies.  We use the built-in JVM logging library, which Tomcat uses with some slight modifications to support separate classloaders.  In the past we bundled an application [logging.properites](https://github.com/JeffersonLab/epics2web/blob/956894699ef1b303907a04720aeb50260ffa72b1/src/main/resources/logging.properties) inside the epics2web.war file.  We no longer do that because it then appears to require repackaging/rebuilding a new version of the app to modify the logging config as the app bundled config overrides the global Tomcat config at conf/logging.properties.  The recommend logging strategy is to now make configuration in the global Tomcat config so as to make it easy to modify logging levels.  An app specific handler can be created.  The global configuration location is generally set by the Tomcat default start script via JVM system properties.  The system properties should look something like: 
 - `-Djava.util.logging.config.file=/usr/share/tomcat/conf/logging.properties`

build.yaml

@@ -13,6 +13,8 @@ services:
       WEBSOCKET_PING_INTERVAL_SECONDS: 2
       WEBSOCKET_TIMEOUT_SECONDS: 5
       WEBSOCKET_SEND_TIMEOUT_SECONDS: 3
+      # Short, so HealthcheckTest runs in seconds
+      HEALTHCHECK_GRACE_SECONDS: 2
     build:
       context: .
       dockerfile: Dockerfile

src/integration/java/org/jlab/epics2web/HealthcheckTest.java

@@ -0,0 +1,140 @@
+package org.jlab.epics2web;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertNull;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+import static org.junit.Assume.assumeTrue;
+
+import jakarta.json.Json;
+import jakarta.json.JsonArray;
+import jakarta.json.JsonObject;
+import jakarta.json.JsonReader;
+import java.io.StringReader;
+import java.net.URI;
+import java.net.http.HttpClient;
+import java.net.http.HttpRequest;
+import java.net.http.HttpResponse;
+import java.net.http.WebSocket;
+import java.util.UUID;
+import java.util.concurrent.TimeUnit;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.Timeout;
+
+/**
+ * Tests /healthcheck (#28). Needs build.yaml's 2 second HEALTHCHECK_GRACE_SECONDS. The disconnect
+ * test stops and starts the softioc container, so it needs the docker command.
+ */
+public class HealthcheckTest {
+
+  private static final HttpClient HTTP = HttpClient.newHttpClient();
+
+  @Rule public Timeout globalTimeout = Timeout.seconds(90);
+
+  /** A PV that never connects may just not exist, so it's listed but doesn't fail strict mode. */
+  @Test
+  public void neverConnectedPvIsListedWithoutFailingStrictMode() throws Exception {
+    String pv = "epics2web:test:healthcheck:" + UUID.randomUUID();
+    WebSocket socket = monitor(pv);
+    try {
+      JsonObject entry = waitForEntry(pv, true);
+      assertEquals("CONNECTING", entry.getString("state"));
+      assertEquals(200, get("healthcheck").statusCode());
+      assertEquals(200, get("healthcheck?strict=true").statusCode());
+    } finally {
+      socket.abort();
+    }
+    waitForEntry(pv, false);
+  }
+
+  /**
+   * A PV that disconnects is reported once the grace period after the disconnect passes. HELLO
+   * changes every 0.2 s; channel1 hasn't changed since the IOC started, which the old check mistook
+   * for time disconnected.
+   */
+  @Test
+  public void disconnectedPvFailsStrictModeOnly() throws Exception {
+    assumeTrue("docker command not available", docker("ps") == 0);
+
+    WebSocket socket = monitor("channel1");
+    try {
+      // Longer than the grace period, so a check of time since the last value would fail at once
+      Thread.sleep(3_000);
+      assertEquals(0, docker("stop", "-t", "1", "softioc"));
+      long stopped = System.nanoTime();
+
+      // Disconnected by now, but still within the grace period after the disconnect
+      Thread.sleep(1_000);
+      assertNull(entry(get("healthcheck"), "channel1"));
+
+      JsonObject entry = waitForEntry("channel1", true);
+      long reportedAfter = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - stopped);
+      assertEquals("DISCONNECTED", entry.getString("state"));
+      // Measured from the disconnect, seconds ago, not from channel1's last value change
+      double minutes = Double.parseDouble(entry.getString("disconnected_minutes"));
+      assertTrue("Disconnected for " + minutes + " minutes", minutes < 0.5);
+      assertTrue("Reported after only " + reportedAfter + " ms", reportedAfter >= 2_000);
+      assertEquals(200, get("healthcheck").statusCode());
+      assertEquals(503, get("healthcheck?strict=true").statusCode());
+    } finally {
+      docker("start", "softioc");
+      waitForEntry("channel1", false); // Reconnected
+      socket.abort();
+    }
+    assertEquals(200, get("healthcheck?strict=true").statusCode());
+  }
+
+  private static WebSocket monitor(String pv) {
+    WebSocket socket =
+        HTTP.newWebSocketBuilder()
+            .buildAsync(
+                URI.create("ws://localhost:8080/epics2web/monitor"), new WebSocket.Listener() {})
+            .join();
+    socket.sendText("{\"type\": \"monitor\",\"pvs\": [\"" + pv + "\"]}", true).join();
+    return socket;
+  }
+
+  /** Waits for the healthcheck to list, or stop listing, a PV; returns its entry if listed. */
+  private static JsonObject waitForEntry(String pv, boolean listed) throws Exception {
+    long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(30);
+    while (System.nanoTime() < deadline) {
+      JsonObject entry = entry(get("healthcheck"), pv);
+      if ((entry != null) == listed) {
+        return entry;
+      }
+      Thread.sleep(200);
+    }
+    fail(listed ? "Healthcheck never listed " + pv : "Healthcheck still lists " + pv);
+    return null;
+  }
+
+  private static JsonObject entry(HttpResponse<String> response, String pv) {
+    try (JsonReader reader = Json.createReader(new StringReader(response.body()))) {
+      JsonArray entries = reader.readArray();
+      for (int i = 0; i < entries.size(); i++) {
+        if (pv.equals(entries.getJsonObject(i).getString("name"))) {
+          return entries.getJsonObject(i);
+        }
+      }
+      return null;
+    }
+  }
+
+  private static HttpResponse<String> get(String path) throws Exception {
+    return HTTP.send(
+        HttpRequest.newBuilder().uri(URI.create("http://localhost:8080/epics2web/" + path)).build(),
+        HttpResponse.BodyHandlers.ofString());
+  }
+
+  private static int docker(String... args) {
+    String[] command = new String[args.length + 1];
+    command[0] = "docker";
+    System.arraycopy(args, 0, command, 1, args.length);
+    try {
+      return new ProcessBuilder(command).redirectErrorStream(true).start().waitFor();
+    } catch (Exception e) {
+      return -1;
+    }
+  }
+}

src/main/java/org/jlab/epics2web/Application.java

@@ -63,6 +63,10 @@ public class Application implements ServletContextListener {
   public static final long SEND_TIMEOUT_SECONDS =
       getSecondsFromEnv("WEBSOCKET_SEND_TIMEOUT_SECONDS", 20);
 
+  /** How long a PV may be disconnected before the healthcheck reports it. */
+  public static final long HEALTHCHECK_GRACE_SECONDS =
+      getSecondsFromEnv("HEALTHCHECK_GRACE_SECONDS", 30);
+
   private static ScheduledExecutorService timeoutExecutor = null;
   private static ExecutorService callbackExecutor = null;
   private static ExecutorService writerExecutor = null;

src/main/java/org/jlab/epics2web/controller/Healthcheck.java

@@ -45,6 +45,12 @@ public class Healthcheck extends HttpServlet {
   protected void doGet(HttpServletRequest request, HttpServletResponse response)
       throws ServletException, IOException {
 
+    // Strict mode answers 503 when a PV is reported, for monitoring that alerts on PVs. The default
+    // answers 200 whenever the server is up, for load balancers: an IOC being down affects every
+    // instance alike, and restarting the server doesn't bring it back.
+    String strictParam = request.getParameter("strict");
+    boolean strict = strictParam != null && !"false".equalsIgnoreCase(strictParam);
+
     boolean healthy = true;
 
     Map<String, ChannelMonitor> monitorMap = channelManager.getMonitorMap();
@@ -56,23 +62,28 @@ protected void doGet(HttpServletRequest request, HttpServletResponse response)
     for (Map.Entry<String, ChannelMonitor> entry : monitorMap.entrySet()) {
       String pv = entry.getKey();
       ChannelMonitor monitor = entry.getValue();
+      ChannelMonitor.MonitorState state = monitor.getState();
+
+      if (state == ChannelMonitor.MonitorState.CONNECTED) {
+        continue;
+      }
 
-      // If never an update, then we assume PV doesn't exist.  Might miss some cases.  Better than
-      // nothing health check!
-      if (monitor.getLastTimestamp() != null) {
-        Instant lastTimestamp = monitor.getLastTimestamp().toInstant();
-        Duration duration = Duration.between(now, lastTimestamp);
-        long differenceInSeconds = Math.abs(duration.toSeconds());
+      // Time since the PV disconnected, or since monitoring began if it never connected
+      Duration notConnected = Duration.between(monitor.getStateChanged(), now);
 
-        if (monitor.getState() != ChannelMonitor.MonitorState.CONNECTED
-            && (differenceInSeconds > 30)) {
+      if (notConnected.toSeconds() > Application.HEALTHCHECK_GRACE_SECONDS) {
+        // A PV that never connected may just not exist, such as a mistyped name, so it's listed
+        // but doesn't make strict mode fail
+        if (state == ChannelMonitor.MonitorState.DISCONNECTED) {
           healthy = false;
-          JsonObjectBuilder unhealthyChannel = Json.createObjectBuilder();
-          unhealthyChannel.add("name", pv);
-          unhealthyChannel.add(
-              "disconnected_minutes", String.format("%.1f", differenceInSeconds / 60.0));
-          unhealthyChannelArray.add(unhealthyChannel);
         }
+
+        JsonObjectBuilder unhealthyChannel = Json.createObjectBuilder();
+        unhealthyChannel.add("name", pv);
+        unhealthyChannel.add("state", state.name());
+        unhealthyChannel.add(
+            "disconnected_minutes", String.format("%.1f", notConnected.toSeconds() / 60.0));
+        unhealthyChannelArray.add(unhealthyChannel);
       }
     }
 
@@ -82,7 +93,7 @@ protected void doGet(HttpServletRequest request, HttpServletResponse response)
 
     response.setStatus(HttpServletResponse.SC_OK);
 
-    if (!healthy) {
+    if (strict && !healthy) {
       response.setStatus(HttpServletResponse.SC_SERVICE_UNAVAILABLE);
     }
 

src/main/java/org/jlab/epics2web/epics/ChannelMonitor.java

@@ -16,6 +16,7 @@
 import gov.aps.jca.event.MonitorListener;
 import java.io.Closeable;
 import java.io.IOException;
+import java.time.Instant;
 import java.util.Date;
 import java.util.Set;
 import java.util.concurrent.*;
@@ -46,7 +47,11 @@ public class ChannelMonitor implements Closeable {
       new AtomicReference<>(
           MonitorState
               .CONNECTING); // We don't use CAJChannel.getConnectionState() because we want to still
+
   // be "connecting" during enum label fetch
+  /** When the connection state last changed, or when the monitor was created. */
+  private volatile Instant stateChanged = Instant.now();
+
   private final AtomicReference<String[]> enumLabels =
       new AtomicReference<>(
           null); // volatile arrays are unsafe due to individual indicies so use AtomicReference
@@ -179,6 +184,22 @@ public MonitorState getState() {
     return state.get();
   }
 
+  /**
+   * Return when the connection state last changed, or when the monitor was created if it never has.
+   * Unlike getLastTimestamp, this is the time of a disconnect, not of the last value change.
+   *
+   * @return The time
+   */
+  public Instant getStateChanged() {
+    return stateChanged;
+  }
+
+  private void setState(MonitorState newState) {
+    if (state.getAndSet(newState) != newState) {
+      stateChanged = Instant.now();
+    }
+  }
+
   public String getLastValue() {
     return ChannelManager.getDbrValueAsString(lastDbr);
   }
@@ -358,12 +379,12 @@ public void run() {
                 } else {
                   LOGGER.log(Level.FINEST, "Notifying clients of disconnect from channel: {0}", pv);
 
-                  state.set(MonitorState.DISCONNECTED);
+                  setState(MonitorState.DISCONNECTED);
                   notifyPvInfoAll(false);
                 }
               } catch (CAException e) {
                 LOGGER.log(Level.SEVERE, "Unable to monitor channel", e);
-                state.set(MonitorState.DISCONNECTED);
+                setState(MonitorState.DISCONNECTED);
                 notifyPvInfoAll(false);
               }
             }
@@ -399,7 +420,7 @@ private void handleRegularConnectionOrReconnect() throws IllegalStateException,
         }
       }
 
-      state.set(MonitorState.CONNECTED);
+      setState(MonitorState.CONNECTED);
       notifyPvInfoAll(true);
     }
 
@@ -428,7 +449,7 @@ public TimedChannelEnumGetListener() {
                 new Callable<Void>() {
                   @Override
                   public Void call() throws Exception {
-                    state.set(MonitorState.DISCONNECTED);
+                    setState(MonitorState.DISCONNECTED);
 
                     notifyPvInfoAll(false);