Coordinator: heartbeat + lifecycle log lines, request timeouts and log contract

.changeset/coordinator-heartbeat-log-contract.md

@@ -0,0 +1,5 @@
+---
+"@3flabs/guardian-coordinator": patch
+---
+
+Emit a per-poll heartbeat line and `guardian.startup` / `guardian.fatal` lifecycle lines from the coordinator, bound grunt-api calls with a configurable request timeout (`REQUEST_TIMEOUT_MS`), and pin every guaranteed log line in `log-contract.json` so regex-based monitoring can rely on it.

packages/guardian-coordinator/README.md

@@ -41,6 +41,8 @@ Optional env:
 
 - `POLL_INTERVAL_MS` default `5000`
 - `PAGE_SIZE` default `100`
+- `REQUEST_TIMEOUT_MS` default `10000`; per-request timeout for grunt-api calls. A hung
+  request aborts and surfaces as a failed poll instead of freezing the loop.
 - `CHAIN_IDS` comma-separated signing-request filter
 - `FACILITIES` comma-separated signing-request filter (facility, or whitelist book for
   `request_whitelisting`)
@@ -72,6 +74,41 @@ Optional env:
   scan per request contract — need longer than the default.
 - `GUARDIAN_SWAP_PRICE_TOLERANCE_BPS` default `1`
 
+## Lifecycle and heartbeat lines
+
+The CLI emits three JSON lines of its own, shaped alike:
+
+```json
+{"level":"info","event":"guardian.startup","build":"1.2.3","chains":[1]}
+{"level":"info","event":"guardian.heartbeat","ok":true,"fetched":0,"signed":0,"skipped":0,"failed":0,"durationMs":12}
+{"level":"fatal","event":"guardian.fatal","err":"COORDINATOR_BASE_URL is required"}
+```
+
+- `guardian.startup` — stdout, once, after config and signer construction succeed.
+  It means the config parsed and the signer was constructed — not that the signer or
+  RPCs were exercised. The first heartbeat is the first proof of live work.
+- `guardian.heartbeat` — stdout, one per poll cycle, including cycles whose poll
+  failed (`ok: false`); its absence means the loop is dead or wedged. The gap between
+  heartbeats is poll duration + `POLL_INTERVAL_MS`, not just the interval: a busy
+  cycle (many requests × `GUARDIAN_SIGN_TIMEOUT_MS`, plus event scans) legitimately
+  stretches it. Size any absence alert to the worst-case cycle duration, not to the
+  poll interval, or a burst of signing work will page you for nothing.
+- `guardian.fatal` — stderr, right before the process exits with code 1, whether the
+  failure happened at boot (bad config) or later. Carries a `stack` field, appended
+  after `err`, when the thrown value has one.
+
+The serialized shapes are a monitoring contract pinned by tests in
+`tests/coordinator.test.ts`; changing them breaks downstream alerting.
+
+`log-contract.json` at the package root is the machine-readable version of this
+contract: one regex per guaranteed line (the three lines above plus the
+`submitted guardian signature for` / `guardian coordinator poll failed:` /
+`failed guardian signing request` / `skipping malformed guardian signing request:`
+prefixes). Monitoring should build its rules from that file.
+`tests/log-contract.test.ts` verifies it in both directions — every pattern is
+emitted by a real code path, and every emitted line matches a pattern — so
+adding, removing, or rewording a log line without updating the contract fails CI.
+
 For `remote_http`, the coordinator sends:
 
 ```json

packages/guardian-coordinator/log-contract.json

@@ -0,0 +1,12 @@
+{
+  "description": "Log lines the guardian-coordinator guarantees on stdout/stderr. Regex-based monitoring must build its rules from these patterns. tests/log-contract.test.ts verifies both directions: every pattern is emitted by a real code path, and every emitted line matches a pattern. Changing a pattern is a breaking change to downstream alerting.",
+  "patterns": {
+    "startup": "^\\{\"level\":\"info\",\"event\":\"guardian\\.startup\",\"build\":",
+    "heartbeat": "^\\{\"level\":\"info\",\"event\":\"guardian\\.heartbeat\",\"ok\":(true|false),\"fetched\":\\d+,\"signed\":\\d+,\"skipped\":\\d+,\"failed\":\\d+,\"durationMs\":\\d+\\}$",
+    "fatal": "^\\{\"level\":\"fatal\",\"event\":\"guardian\\.fatal\",\"err\":",
+    "submitted": "^submitted guardian signature for ",
+    "poll_failed": "^guardian coordinator poll failed: ",
+    "signing_failed": "^failed guardian signing request ",
+    "malformed_request": "^skipping malformed guardian signing request: "
+  }
+}

packages/guardian-coordinator/package.json

@@ -21,7 +21,8 @@
   "files": [
     "dist",
     "src",
-    "README.md"
+    "README.md",
+    "log-contract.json"
   ],
   "publishConfig": {
     "access": "public",

packages/guardian-coordinator/src/cli.ts

@@ -477,16 +477,39 @@ function nonNegativeInt(value: string | undefined, fallback: number): number {
   return parsed;
 }
 
-async function main(): Promise<void> {
-  await runGuardianCoordinator({
-    ...loadCoordinatorConfig(process.env),
-    guardian: buildGuardianFromEnv(process.env),
+/**
+ * Fork-owned lifecycle lines, shaped like the heartbeat. Their serialized
+ * form is a monitoring contract pinned by tests — do not change casually.
+ */
+export function startupLine(guardian: CoordinatorGuardian): string {
+  return JSON.stringify({
+    level: "info",
+    event: "guardian.startup",
+    build: guardian.metadata.build,
+    chains: guardian.metadata.supportedChains,
+  });
+}
+
+export function fatalLine(error: unknown): string {
+  return JSON.stringify({
+    level: "fatal",
+    event: "guardian.fatal",
+    err: error instanceof Error ? error.message : String(error),
+    // Appended last so the prefix monitoring matches on stays stable.
+    ...(error instanceof Error && error.stack ? { stack: error.stack } : {}),
   });
 }
 
+async function main(): Promise<void> {
+  const config = loadCoordinatorConfig(process.env);
+  const guardian = buildGuardianFromEnv(process.env);
+  console.log(startupLine(guardian));
+  await runGuardianCoordinator({ ...config, guardian });
+}
+
 if (process.argv[1] && import.meta.url === pathToFileURL(process.argv[1]).href) {
   main().catch((error) => {
-    console.error(error instanceof Error ? error.message : String(error));
+    console.error(fatalLine(error));
     process.exitCode = 1;
   });
 }

packages/guardian-coordinator/src/index.ts

@@ -19,6 +19,7 @@ import { z } from "zod";
 
 const DEFAULT_POLL_INTERVAL_MS = 5_000;
 const DEFAULT_PAGE_SIZE = 100;
+const DEFAULT_REQUEST_TIMEOUT_MS = 10_000;
 const TOKEN_ID = "guardian-coordinator";
 const TOKEN_INFO = {
   tokenId: TOKEN_ID,
@@ -52,6 +53,7 @@ export type CoordinatorConnectionConfig = {
   pageSize: number;
   chainIds?: Set<number>;
   facilities?: Set<string>;
+  requestTimeoutMs?: number;
 };
 
 export type GuardianCoordinatorOptions = CoordinatorConnectionConfig & {
@@ -98,28 +100,64 @@ export function loadCoordinatorConfig(
     coordinatorApiKey: required(env, "COORDINATOR_API_KEY"),
     pollIntervalMs: positiveInt(env.POLL_INTERVAL_MS, DEFAULT_POLL_INTERVAL_MS),
     pageSize: positiveInt(env.PAGE_SIZE, DEFAULT_PAGE_SIZE),
+    requestTimeoutMs: positiveInt(env.REQUEST_TIMEOUT_MS, DEFAULT_REQUEST_TIMEOUT_MS),
     chainIds: numberSet(env.CHAIN_IDS),
     facilities: stringSet(env.FACILITIES),
   };
 }
 
+export type PollCycleStats = {
+  fetched: number;
+  signed: number;
+  skipped: number;
+  failed: number;
+};
+
 export async function runGuardianCoordinator(options: GuardianCoordinatorOptions): Promise<void> {
-  const logger = options.logger ?? console;
   for (;;) {
-    try {
-      await runGuardianCoordinatorOnce(options);
-    } catch (error) {
-      logger.error(
-        `guardian coordinator poll failed: ${error instanceof Error ? error.message : String(error)}`,
-      );
-    }
+    await runGuardianCoordinatorCycle(options);
     await sleep(options.pollIntervalMs);
   }
 }
 
+/**
+ * One poll cycle plus its heartbeat line. The heartbeat is emitted even
+ * when the poll throws (`ok: false`): it signals the loop is alive, not
+ * that it succeeded, so a missing-heartbeat alert fires only when the
+ * process is dead or wedged. The serialized shape is a monitoring
+ * contract pinned by a test — do not change it casually.
+ */
+export async function runGuardianCoordinatorCycle(
+  options: GuardianCoordinatorOptions,
+): Promise<PollCycleStats> {
+  const logger = options.logger ?? console;
+  const startedAt = Date.now();
+  const stats: PollCycleStats = { fetched: 0, signed: 0, skipped: 0, failed: 0 };
+  let ok = true;
+  try {
+    await runGuardianCoordinatorOnce(options, stats);
+  } catch (error) {
+    ok = false;
+    logger.error(
+      `guardian coordinator poll failed: ${error instanceof Error ? error.message : String(error)}`,
+    );
+  }
+  logger.log(
+    JSON.stringify({
+      level: "info",
+      event: "guardian.heartbeat",
+      ok,
+      ...stats,
+      durationMs: Date.now() - startedAt,
+    }),
+  );
+  return stats;
+}
+
 export async function runGuardianCoordinatorOnce(
   options: GuardianCoordinatorOptions,
-): Promise<void> {
+  stats: PollCycleStats = { fetched: 0, signed: 0, skipped: 0, failed: 0 },
+): Promise<PollCycleStats> {
   const fetcher = options.fetcher ?? fetch;
   const logger = options.logger ?? console;
 
@@ -133,20 +171,27 @@ export async function runGuardianCoordinatorOnce(
       if (filter.facility !== undefined) url.searchParams.set("facility", filter.facility);
 
       const requests = zSigningRequestPage.parse(
-        await requestJson(fetcher, "GET", url.toString(), {
-          headers: { "x-api-key": options.coordinatorApiKey },
-        }),
+        await requestJson(
+          fetcher,
+          "GET",
+          url.toString(),
+          { headers: { "x-api-key": options.coordinatorApiKey } },
+          options.requestTimeoutMs,
+        ),
       );
+      stats.fetched += requests.items.length;
 
       for (const item of requests.items) {
         const row = zSigningRequest.safeParse(item);
         if (!row.success) {
+          stats.failed++;
           logger.error(`skipping malformed guardian signing request: ${row.error.message}`);
           continue;
         }
         const request = row.data;
 
         if (request.mySubmission !== null) {
+          stats.skipped++;
           continue;
         }
 
@@ -167,6 +212,7 @@ export async function runGuardianCoordinatorOnce(
             (options.chainIds && !options.chainIds.has(parsed.body.chainId)) ||
             (options.facilities && !options.facilities.has(target.address.toLowerCase()))
           ) {
+            stats.skipped++;
             continue;
           }
 
@@ -182,9 +228,12 @@ export async function runGuardianCoordinatorOnce(
               },
               body: JSON.stringify({ chainId: parsed.body.chainId, signature: signed.signature }),
             },
+            options.requestTimeoutMs,
           );
+          stats.signed++;
           logger.log(`submitted guardian signature for ${request.id}`);
         } catch (error) {
+          stats.failed++;
           logger.error(
             `failed guardian signing request ${request.id}: ${
               error instanceof Error ? error.message : String(error)
@@ -196,6 +245,7 @@ export async function runGuardianCoordinatorOnce(
       if (requests.items.length === 0 || page * requests.pageSize >= requests.total) break;
     }
   }
+  return stats;
 }
 
 async function signWithGuardian(
@@ -276,8 +326,13 @@ async function requestJson(
   method: string,
   url: string,
   init: RequestInit = {},
+  timeoutMs: number = DEFAULT_REQUEST_TIMEOUT_MS,
 ): Promise<unknown> {
-  const response = await fetcher(url, { ...init, method });
+  const response = await fetcher(url, {
+    ...init,
+    method,
+    signal: AbortSignal.timeout(timeoutMs),
+  });
   const text = await response.text();
   let body: unknown = null;
   if (text.length > 0) {