🔊 back: output statistics periodically to logs (#762)

tdrive/backend/node/config/custom-environment-variables.json

@@ -21,7 +21,9 @@
       "__name": "DIAG_SKIP_KEYS",
       "__format": "json"
     },
-    "probeSecret": "DIAG_PROBE_SECRET"
+    "probeSecret": "DIAG_PROBE_SECRET",
+    "statsLogPeriodMs": "DIAG_STATS_PRINT_PERIOD_MS",
+    "statsFullStatsLogPeriodMs": "DIAG_FULL_STATS_PRINT_PERIOD_MS"
   },
   "webserver": {
     "host": "TWAKE_DRIVE_HOST",

tdrive/backend/node/config/default.json

@@ -37,7 +37,9 @@
   },
   "diagnostics": {
     "skipKeys": [],
-    "probeSecret": ""
+    "probeSecret": "",
+    "statsLogPeriodMs": 120000,
+    "statsFullStatsLogPeriodMs": 600000
   },
   "tracker": {
     "type": "segment",

tdrive/backend/node/src/core/platform/framework/api/diagnostics.ts

@@ -1,6 +1,8 @@
 import assert from "node:assert";
 import config from "../../../config";
-import { logger } from "../logger";
+import { getLogger } from "../logger";
+
+const logger = getLogger("Diagnostics");
 
 /**
  * Values that can match a set of diagnostic providers.
@@ -44,6 +46,10 @@ interface IDiagnosticsConfig {
   // relied on for security because disabling diagnostics. At worst this
   // provides access to the DB statistics.
   probeSecret?: string;
+  // Period at which to log TDiagnosticTag `stats`. 0 to disable.
+  statsLogPeriodMs: number;
+  // Period at which to log TDiagnosticTag `stats-full`. 0 to disable.
+  statsFullStatsLogPeriodMs: number;
 }
 
 export const getConfig = (): IDiagnosticsConfig => {
@@ -56,7 +62,17 @@ export const getConfig = (): IDiagnosticsConfig => {
         .split(/[,\s]+/g)
         .filter(x => !!x),
     };
-  return configSection;
+
+  const getNumberFromConfig = (value): number => {
+    if (typeof value == "number") return value;
+    if (typeof value == "string") return parseInt(value, 10) ?? 0;
+    return 0;
+  };
+  return {
+    ...configSection,
+    statsLogPeriodMs: getNumberFromConfig(configSection.statsLogPeriodMs),
+    statsFullStatsLogPeriodMs: getNumberFromConfig(configSection.statsFullStatsLogPeriodMs),
+  };
 };
 
 /** Code-wide unique key for each provider */
@@ -125,20 +141,22 @@ const recordDiagnostic = (startMs: number, key: TDiagnosticKey, data?: object, e
     ...(error ? { ok: false, error } : { ...data }),
   });
 
-const runProvider = async provider => {
+const runProvider = async (provider, log) => {
   const startMs = now();
   try {
     const result = await provider.get();
     if (!result.ok)
       logger.error(
-        { provider: provider.key, result },
+        { diagnostic: provider.key, ...result },
         "Got diagnostic provider result with ok=false",
       );
     else if (result.warn)
       logger.warn(
-        { provider: provider.key, result },
+        { diagnostic: provider.key, ...result },
         "Got diagnostic provider result with ok=true but a warning",
       );
+    else if (log)
+      logger.info({ diagnostic: provider.key, ...result }, "Diagnostic provider result");
     return recordDiagnostic(startMs, provider.key, result);
   } catch (err) {
     logger.error({ err, provider: provider.key }, "Failed to read diagnostic provider");
@@ -173,7 +191,7 @@ export default {
       let triggerUpdate: () => void = () => undefined; // The empty function is for the linter. I love you linter <3
       const updateProvider = (timeoutId: number) => async () => {
         forgetPendingTimeout(timeoutId);
-        await runProvider(provider);
+        await runProvider(provider, false);
         triggerUpdate();
       };
       triggerUpdate = () => pendingTimeouts.push(setTimeout(updateProvider, provider.pollPeriodMs));
@@ -213,9 +231,14 @@ export default {
     hasShutdown = true;
   },
 
-  /** Return the values of all providers which include the provided tag */
+  /**
+   * Return the values of all providers which include the provided tag.
+   *
+   * @param log if `true`, print each individual log output even if succesful
+   */
   async get(
     tag: TDiagnosticTag,
+    log: boolean,
   ): Promise<{ ok: boolean } | { [key: TDiagnosticKey]: TDiagnosticResult }> {
     const config = getConfig();
     const result = { ok: true };
@@ -230,7 +253,7 @@ export default {
       immediateDiagnosticProviders.map(async provider => {
         if (!isProviderIncludedInTag(tag, provider, config)) return;
         atLeastOneCheck = true;
-        const providerResult = await runProvider(provider);
+        const providerResult = await runProvider(provider, log);
         if (!providerResult.ok) result.ok = false;
         return (result[provider.key] = providerResult);
       }),

tdrive/backend/node/src/core/platform/services/diagnostics/index.ts

@@ -4,6 +4,10 @@ import DiagnosticsServiceAPI from "./service-provider";
 import DiagnosticsServiceImpl from "./service";
 import WebServerAPI from "../webserver/provider";
 import registerBasicProviders from "./providers";
+import diagnostics, {
+  getConfig as getDiagnosticsGetConfig,
+  TDiagnosticTag,
+} from "../../framework/api/diagnostics";
 
 /**
  * The diagnostics service exposes endpoint that are of use for operational reasons.
@@ -15,6 +19,8 @@ import registerBasicProviders from "./providers";
 export default class DiagnosticsService extends TdriveService<DiagnosticsServiceAPI> {
   name = "diagnostics";
   service: DiagnosticsServiceAPI;
+  private runningIntervalStatsLog?: ReturnType<typeof setInterval>;
+  private runningIntervalStatsFullLog?: ReturnType<typeof setInterval>;
 
   api(): DiagnosticsServiceAPI {
     return this.service;
@@ -30,6 +36,28 @@ export default class DiagnosticsService extends TdriveService<DiagnosticsService
       next();
     });
 
+    const config = getDiagnosticsGetConfig();
+    const printStatsToLog = (tag: TDiagnosticTag) => () => diagnostics.get(tag, true);
+    const startLoggingStats = (tag, periodMs) =>
+      periodMs && periodMs > 0 ? setInterval(printStatsToLog(tag), periodMs) : undefined;
+    this.runningIntervalStatsLog = startLoggingStats("stats", config.statsLogPeriodMs);
+    this.runningIntervalStatsFullLog = startLoggingStats(
+      "stats-full",
+      config.statsFullStatsLogPeriodMs,
+    );
+
+    return this;
+  }
+
+  public async doStop(): Promise<this> {
+    if (this.runningIntervalStatsLog) {
+      clearInterval(this.runningIntervalStatsLog);
+      this.runningIntervalStatsLog = null;
+    }
+    if (this.runningIntervalStatsFullLog) {
+      clearInterval(this.runningIntervalStatsFullLog);
+      this.runningIntervalStatsFullLog = null;
+    }
     return this;
   }
 }

tdrive/backend/node/src/core/platform/services/diagnostics/web/probe-routes.ts

@@ -14,7 +14,7 @@ const routes: FastifyPluginCallback = (fastify: FastifyInstance, _opts, next) =>
         (request.query as { secret: string }).secret !== diagnosticsConfig.probeSecret
       )
         return reply.status(403).send();
-      const results = await diagnostics.get(tag);
+      const results = await diagnostics.get(tag, false);
       if (!results.ok) reply.status(503);
       return reply.send(results);
     });