(core) Add options to /status health-check endpoints to check DB and Redis liveness.

Summary:
- /status accepts new optional query parameters: db=1, redis=1, and timeout=<ms> (defaults to 10_000).
- These verify that the server can make trivial calls to DB/Redis, and that they return within the timeout.
- New HealthCheck tests simulates DB and Redis problems.
- Added resilience to Redis reconnects (helped by a test case that simulates disconnects)
- When closing Redis-based session store, disconnect from Redis (to avoid hanging tests)

Some associated test reorg:
- Move stripeTools out of test/nbrowser, and remove an unnecessary dependency,
  to avoid starting up browser for gen-server tests.
- Move TcpForwarder to its own file, to use in the new test.

Test Plan: Added a new HealthCheck test that simulates DB and Redis problems.

Reviewers: georgegevoian

Reviewed By: georgegevoian

Differential Revision: https://phab.getgrist.com/D4054

app/gen-server/lib/DocWorkerMap.ts

@@ -190,6 +190,9 @@ export class DocWorkerMap implements IDocWorkerMap {
     this._clients = _clients || [createClient(process.env.REDIS_URL)];
     this._redlock = new Redlock(this._clients);
     this._client = this._clients[0]!;
+    this._client.on('error', (err) => log.warn(`DocWorkerMap: redisClient error`, String(err)));
+    this._client.on('end', () => log.warn(`DocWorkerMap: redisClient connection closed`));
+    this._client.on('reconnecting', () => log.warn(`DocWorkerMap: redisClient reconnecting`));
   }
 
   public async addWorker(info: DocWorkerInfo): Promise<void> {

app/gen-server/lib/TypeORMPatches.ts

@@ -25,6 +25,8 @@ import {
 } from 'typeorm/error/QueryRunnerProviderAlreadyReleasedError';
 import {QueryBuilder} from 'typeorm/query-builder/QueryBuilder';
 
+// Print a warning for transactions that take longer than this.
+const SLOW_TRANSACTION_MS = 5000;
 
 /**********************
  * Patch 1
@@ -103,9 +105,21 @@ export function applyPatch() {
       async function runOrRollback() {
         try {
           await queryRunner.startTransaction();
-          const result = await runInTransaction(queryRunner.manager);
-          await queryRunner.commitTransaction();
-          return result;
+
+          const start = Date.now();
+
+          const timer = setInterval(() => {
+            const timeMs = Date.now() - start;
+            log.warn(`TypeORM transaction slow: [${arg1} ${arg2}]`, {timeMs});
+          }, SLOW_TRANSACTION_MS);
+
+          try {
+            const result = await runInTransaction(queryRunner.manager);
+            await queryRunner.commitTransaction();
+            return result;
+          } finally {
+            clearInterval(timer);
+          }
         } catch (err) {
           log.debug(`TypeORM transaction error [${arg1} ${arg2}] - ${err}`);
           try {

app/server/lib/FlexServer.ts

@@ -53,11 +53,11 @@ import {getAppPathTo, getAppRoot, getUnpackedAppRoot} from 'app/server/lib/place
 import {addPluginEndpoints, limitToPlugins} from 'app/server/lib/PluginEndpoint';
 import {PluginManager} from 'app/server/lib/PluginManager';
 import * as ProcessMonitor from 'app/server/lib/ProcessMonitor';
-import {adaptServerUrl, getOrgUrl, getOriginUrl, getScope, integerParam, isDefaultUser, optStringParam,
-        RequestWithGristInfo, sendOkReply, stringArrayParam, stringParam, TEST_HTTPS_OFFSET,
+import {adaptServerUrl, getOrgUrl, getOriginUrl, getScope, integerParam, isDefaultUser, isParameterOn, optIntegerParam,
+        optStringParam, RequestWithGristInfo, sendOkReply, stringArrayParam, stringParam, TEST_HTTPS_OFFSET,
         trustOrigin} from 'app/server/lib/requestUtils';
 import {ISendAppPageOptions, makeGristConfig, makeMessagePage, makeSendAppPage} from 'app/server/lib/sendAppPage';
-import {getDatabaseUrl, listenPromise} from 'app/server/lib/serverUtils';
+import {getDatabaseUrl, listenPromise, timeoutReached} from 'app/server/lib/serverUtils';
 import {Sessions} from 'app/server/lib/Sessions';
 import * as shutdown from 'app/server/lib/shutdown';
 import {TagChecker} from 'app/server/lib/TagChecker';
@@ -374,6 +374,10 @@ export class FlexServer implements GristServer {
     return this._widgetRepository;
   }
 
+  public hasNotifier(): boolean {
+    return Boolean(this._notifier);
+  }
+
   public getNotifier(): INotifier {
     if (!this._notifier) { throw new Error('no notifier available'); }
     return this._notifier;
@@ -425,13 +429,45 @@ export class FlexServer implements GristServer {
     // Health check endpoint. if called with /hooks, testing hooks are required in order to be
     // considered healthy.  Testing hooks are used only in server started for tests, and
     // /status/hooks allows the tests to wait for them to be ready.
-    this.app.get('/status(/hooks)?', (req, res) => {
-      if (this._healthy && (this._hasTestingHooks || !req.url.endsWith('/hooks'))) {
+    // If db=1 query parameter is included, status will include the status of DB connection.
+    // If redis=1 query parameter is included, status will include the status of the Redis connection.
+    this.app.get('/status(/hooks)?', async (req, res) => {
+      const checks = new Map<string, Promise<boolean>|boolean>();
+      const timeout = optIntegerParam(req.query.timeout, 'timeout') || 10_000;
+
+      // Check that the given promise resolves with no error within our timeout.
+      const asyncCheck = async (promise: Promise<unknown>|undefined) => {
+        if (!promise || await timeoutReached(timeout, promise) === true) {
+          return false;
+        }
+        return promise.then(() => true, () => false);     // Success => true, rejection => false
+      };
+
+      if (req.path.endsWith('/hooks')) {
+        checks.set('hooks', this._hasTestingHooks);
+      }
+      if (isParameterOn(req.query.db)) {
+        checks.set('db', asyncCheck(this._dbManager.connection.query('SELECT 1')));
+      }
+      if (isParameterOn(req.query.redis)) {
+        checks.set('redis', asyncCheck(this._docWorkerMap.getRedisClient()?.pingAsync()));
+      }
+      let extra = '';
+      let ok = true;
+      // If we had any extra check, collect their status to report them.
+      if (checks.size > 0) {
+        const results = await Promise.all(checks.values());
+        ok = ok && results.every(r => r === true);
+        const notes = Array.from(checks.keys(), (key, i) => `${key} ${results[i] ? 'ok' : 'not ok'}`);
+        extra = ` (${notes.join(", ")})`;
+      }
+
+      if (this._healthy && ok) {
         this._healthCheckCounter++;
-        res.status(200).send(`Grist ${this.name} is alive.`);
+        res.status(200).send(`Grist ${this.name} is alive${extra}.`);
       } else {
         this._healthCheckCounter = 0;  // reset counter if we ever go internally unhealthy.
-        res.status(500).send(`Grist ${this.name} is unhealthy.`);
+        res.status(500).send(`Grist ${this.name} is unhealthy${extra}.`);
       }
     });
   }

app/server/lib/gristSessions.ts

@@ -3,6 +3,7 @@ import {parseSubdomain} from 'app/common/gristUrls';
 import {isNumber} from 'app/common/gutil';
 import {RequestWithOrg} from 'app/server/lib/extractOrg';
 import {GristServer} from 'app/server/lib/GristServer';
+import {fromCallback} from 'app/server/lib/serverUtils';
 import {Sessions} from 'app/server/lib/Sessions';
 import {promisifyAll} from 'bluebird';
 import * as express from 'express';
@@ -62,8 +63,9 @@ function createSessionStoreFactory(sessionsDB: string): () => SessionStore {
       });
       return assignIn(store, {
         async close() {
-          // Doesn't actually close, just unrefs stream so node becomes close-able.
-          store.client.unref();
+          // Quit the client, so that it doesn't attempt to reconnect (which matters for some
+          // tests), and so that node becomes close-able.
+          await fromCallback(cb => store.client.quit(cb));
         }});
     };
   } else {

stubs/app/server/declarations.d.ts

@@ -58,6 +58,7 @@ declare module "redis" {
     public watchAsync(key: string): Promise<void>;
     public lrangeAsync(key: string, start: number, end: number): Promise<string[]>;
     public rpushAsync(key: string, ...vals: string[]): Promise<number>;
+    public pingAsync(): Promise<string>;
   }
 
   class Multi {

test/gen-server/apiUtils.ts

@@ -51,9 +51,11 @@ export class TestServer {
     // TypeORM doesn't give us a very clean way to shut down the db connection,
     // and node-sqlite3 has become fussier about this, and in regular tests
     // we substitute sqlite for postgres.
-    for (let i = 0; i < 30; i++) {
-      if (!this.server.getNotifier().testPending) { break; }
-      await delay(100);
+    if (this.server.hasNotifier()) {
+      for (let i = 0; i < 30; i++) {
+        if (!this.server.getNotifier().testPending) { break; }
+        await delay(100);
+      }
     }
     await removeConnection();
   }

test/server/Comm.ts

@@ -2,7 +2,7 @@ import {Events as BackboneEvents} from 'backbone';
 import {promisifyAll} from 'bluebird';
 import {assert} from 'chai';
 import * as http from 'http';
-import {AddressInfo, Server, Socket} from 'net';
+import {AddressInfo} from 'net';
 import * as sinon from 'sinon';
 import WebSocket from 'ws';
 import * as path from 'path';
@@ -16,8 +16,9 @@ import {Client, ClientMethod} from 'app/server/lib/Client';
 import {CommClientConnect} from 'app/common/CommTypes';
 import {delay} from 'app/common/delay';
 import {isLongerThan} from 'app/common/gutil';
-import {connect as connectSock, fromCallback, getAvailablePort, listenPromise} from 'app/server/lib/serverUtils';
+import {fromCallback, listenPromise} from 'app/server/lib/serverUtils';
 import {Sessions} from 'app/server/lib/Sessions';
+import {TcpForwarder} from 'test/server/tcpForwarder';
 import * as testUtils from 'test/server/testUtils';
 import * as session from '@gristlabs/express-session';
 
@@ -494,62 +495,3 @@ function getWSSettings(docWorkerUrl: string): GristWSSettings {
     warn()                      { (log as any).warn(...arguments); },
   };
 }
-
-// We'll test reconnects by making a connection through this TcpForwarder, which we'll use to
-// simulate disconnects.
-export class TcpForwarder {
-  public port: number|null = null;
-  private _connections = new Map<Socket, Socket>();
-  private _server: Server|null = null;
-
-  constructor(private _serverPort: number) {}
-
-  public async pickForwarderPort(): Promise<number> {
-    this.port = await getAvailablePort(5834);
-    return this.port;
-  }
-  public async connect() {
-    await this.disconnect();
-    this._server = new Server((sock) => this._onConnect(sock));
-    await listenPromise(this._server.listen(this.port));
-  }
-  public async disconnectClientSide() {
-    await Promise.all(Array.from(this._connections.keys(), destroySock));
-    if (this._server) {
-      await new Promise((resolve) => this._server!.close(resolve));
-      this._server = null;
-    }
-    this.cleanup();
-  }
-  public async disconnectServerSide() {
-    await Promise.all(Array.from(this._connections.values(), destroySock));
-    this.cleanup();
-  }
-  public async disconnect() {
-    await this.disconnectClientSide();
-    await this.disconnectServerSide();
-  }
-  public cleanup() {
-    const pairs = Array.from(this._connections.entries());
-    for (const [clientSock, serverSock] of pairs) {
-      if (clientSock.destroyed && serverSock.destroyed) {
-        this._connections.delete(clientSock);
-      }
-    }
-  }
-  private async _onConnect(clientSock: Socket) {
-    const serverSock = await connectSock(this._serverPort);
-    clientSock.pipe(serverSock);
-    serverSock.pipe(clientSock);
-    clientSock.on('error', (err) => serverSock.destroy(err));
-    serverSock.on('error', (err) => clientSock.destroy(err));
-    this._connections.set(clientSock, serverSock);
-  }
-}
-
-async function destroySock(sock: Socket): Promise<void> {
-  if (!sock.destroyed) {
-    await new Promise((resolve, reject) =>
-      sock.on('close', resolve).destroy());
-  }
-}

test/server/tcpForwarder.ts

@@ -0,0 +1,61 @@
+import {Server, Socket} from 'net';
+import {connect as connectSock, getAvailablePort, listenPromise} from 'app/server/lib/serverUtils';
+
+// We'll test reconnects by making a connection through this TcpForwarder, which we'll use to
+// simulate disconnects.
+export class TcpForwarder {
+  public port: number|null = null;
+  private _connections = new Map<Socket, Socket>();
+  private _server: Server|null = null;
+
+  constructor(private _serverPort: number, private _serverHost?: string) {}
+
+  public async pickForwarderPort(): Promise<number> {
+    this.port = await getAvailablePort(5834);
+    return this.port;
+  }
+  public async connect() {
+    await this.disconnect();
+    this._server = new Server((sock) => this._onConnect(sock));
+    await listenPromise(this._server.listen(this.port));
+  }
+  public async disconnectClientSide() {
+    await Promise.all(Array.from(this._connections.keys(), destroySock));
+    if (this._server) {
+      await new Promise((resolve) => this._server!.close(resolve));
+      this._server = null;
+    }
+    this.cleanup();
+  }
+  public async disconnectServerSide() {
+    await Promise.all(Array.from(this._connections.values(), destroySock));
+    this.cleanup();
+  }
+  public async disconnect() {
+    await this.disconnectClientSide();
+    await this.disconnectServerSide();
+  }
+  public cleanup() {
+    const pairs = Array.from(this._connections.entries());
+    for (const [clientSock, serverSock] of pairs) {
+      if (clientSock.destroyed && serverSock.destroyed) {
+        this._connections.delete(clientSock);
+      }
+    }
+  }
+  private async _onConnect(clientSock: Socket) {
+    const serverSock = await connectSock(this._serverPort, this._serverHost);
+    clientSock.pipe(serverSock);
+    serverSock.pipe(clientSock);
+    clientSock.on('error', (err) => serverSock.destroy(err));
+    serverSock.on('error', (err) => clientSock.destroy(err));
+    this._connections.set(clientSock, serverSock);
+  }
+}
+
+async function destroySock(sock: Socket): Promise<void> {
+  if (!sock.destroyed) {
+    await new Promise((resolve, reject) =>
+      sock.on('close', resolve).destroy());
+  }
+}