0.1.14: the provider loop says a consumer it keeps failing on the bus, and its recovery (hq ADR 0224, issue 272)

No provider on runProvisioner passed announce, and the loop had no standing per
consumer, so the object store, the SQL and document stores, the mail server and
the others failed their consumers in their journals alone. The loop now keeps the
Go copy's standing (failing after five minutes, again every fifteen, recovered on
success, when unasked or retired, and on the first success since start) and says
it through the SDK's emit unless given another announce.

src/provisioner/index.ts

@@ -10,10 +10,20 @@
 // does not hand one back — the consumer already receives its copy through the mesh's own channel.
 // This is why the old $MESH_SEAL_KEY, the symmetric seal, and the *.grant.json / *.credential files
 // are gone: they described a second, contradictory credential path the mesh does not have.
+//
+// **A provider that keeps failing a consumer says so on the bus (novox/hq ADR 0224).** A consumer
+// whose create, check or secret has failed without one success in between for `failingAfterMs` is
+// announced as `provisioner.failing` — naming the consumer, its machine and the class of error — and
+// again every `sayAgainEveryMs` while it lasts; the first success after that is
+// `provisioner.recovered`, as is a consumer the mesh stopped asking for, and the first success for
+// each consumer since this process started. The controller keeps the newest per provider and consumer
+// and `status` names it. Until novox/hq issue 272 only the Go copy of this loop (postgres, keycloak)
+// said it; every provider on this one failed its consumers in its journal alone.
 
 import { readFile } from "node:fs/promises";
 
 import type { ToolDefinition } from "../contracts/index.js";
+import { emit } from "../events/index.js";
 import { registerModuleTools } from "../tools/index.js";
 
 /** One consumer's resource to bring into being — everything the mesh derived and delivered. */
@@ -86,6 +96,9 @@ export interface Adapter {
   /** Optional: every consumer the backend holds ACTIVE that the mesh made, read at start, so one the
    *  mesh stopped asking for while this process was down is still retired (by the same rules). */
   held?(): Promise<string[]>;
+  /** Optional: the class of one of the adapter's own errors (novox/hq ADR 0224), when its code knows
+   *  better than the error's words; "" or undefined falls back to `classOf` of the text. */
+  classify?(err: unknown): string | undefined;
 }
 
 /** One retired consumer, as `provisioner_retirement` answers it. */
@@ -139,6 +152,21 @@ export type Provisioner = (() => void) & {
 /** The one event a provider says about retirement (novox/hq ADR 0230). */
 export const RETIREMENT_EVENT = "provisioner.retirement";
 
+/** The events a provider's standing toward one consumer is announced as (novox/hq ADR 0224). The
+ *  controller derives the permission to emit them for every module that receives contributions. */
+export const FAILING_EVENT = "provisioner.failing";
+export const RECOVERED_EVENT = "provisioner.recovered";
+
+/** The classes a failing consumer is announced with: what a person reading `status` needs to know
+ *  before reading the journal (novox/hq ADR 0224). An adapter may say better (`classify`). */
+export const CLASS_CREDENTIALS = "credentials-rejected";
+export const CLASS_UNREACHABLE = "unreachable";
+export const CLASS_SECRET = "secret-unreadable";
+export const CLASS_REFUSED = "refused";
+
+/** How long a consumer fails without one success before it is announced failing (ADR 0224). */
+export const FAILING_AFTER_MS = 5 * 60_000;
+
 export interface ProvisionerOptions {
   /** The contributions file the mesh writes for this resource (the module's `receives` path).
    *  Defaults to $MESH_RECEIVES. */
@@ -165,10 +193,16 @@ export interface ProvisionerOptions {
   /** Nor a set larger than this share of the consumers held, where more than one is held. Defaults
    *  to 0.5. */
   retireFraction?: number;
-  /** How often a waiting retirement is said again, in ms. Defaults to 15 minutes. */
+  /** How often a waiting retirement, and a consumer still failing, is said again, in ms. Defaults to
+   *  15 minutes. */
   sayAgainEveryMs?: number;
-  /** Publishes one of the provider's events (`provisioner.retirement`); usually the SDK's `emit`.
-   *  Without it the provider's retirement is said in its journal only. */
+  /** How long, in ms, a consumer fails without one success before it is announced
+   *  `provisioner.failing` (novox/hq ADR 0224). Defaults to FAILING_AFTER_MS, five minutes. */
+  failingAfterMs?: number;
+  /** Publishes one of the provider's events (`provisioner.failing`, `provisioner.recovered`,
+   *  `provisioner.retirement`). Defaults to the SDK's `emit`, so every provider says them on the bus
+   *  without asking (novox/hq issue 272); a failed publish is said in the journal and never fails
+   *  the act it reports. */
   announce?: (event: string, body: Record<string, unknown>) => Promise<void> | void;
   /** The machine this provider runs on, said in each event. Defaults to $MESH_NODE. */
   node?: string;
@@ -227,6 +261,8 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
   const retireAtOnce = opts.retireAtOnce ?? 3;
   const retireFraction = opts.retireFraction ?? 0.5;
   const sayAgainEveryMs = opts.sayAgainEveryMs ?? 15 * 60_000;
+  const failingAfterMs = opts.failingAfterMs ?? FAILING_AFTER_MS;
+  const announce = opts.announce ?? ((event: string, body: Record<string, unknown>) => emit(event, body));
   const node = opts.node ?? process.env.MESH_NODE ?? "";
   const say = (line: string): void => console.error(`[provisioner:${resource}] ${line}`);
   // Retirement (novox/hq ADR 0230). The unasked set last seen and in how many consecutive readable
@@ -245,6 +281,13 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
   // itself. Each repeat doubles the wait before asking again, so such a bug costs one re-apply an
   // hour rather than one a minute, and it is said loudly rather than quietly repeated.
   const lost = new Map<string, { times: number; nextAt: number }>();
+  // Each consumer's unbroken run of failures — since when, how often, the last error, and when it was
+  // last announced (0: not yet) — and every consumer that has succeeded since this process started
+  // (novox/hq ADR 0224).
+  const trouble = new Map<string, {
+    node?: string; since: number; attempts: number; cls: string; text: string; saidAt: number;
+  }>();
+  const cleared = new Set<string>();
 
   // login (`as`) -> what was last applied: the hash that says whether it changed, and the
   // derivation to hand back on withdrawal, which by then is no longer in the file.
@@ -311,6 +354,7 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
               `file and who this process runs as (novox/hq issue 225)`,
           );
         }
+        await failed(g.as, g.node, CLASS_SECRET, `secret not readable (${g.secret}): ${err}`);
         continue;
       }
       waiting.delete(g.as);
@@ -328,11 +372,15 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
         try {
           if (await withTimeout(adapter.holds!(p), holdsTimeoutMs)) {
             lost.delete(g.as);
+            await succeeded(g.as);
             continue;
           }
         } catch (err) {
-          // Unable to ask is not evidence of loss. Kept as applied, asked again next time.
-          console.error(`[provisioner:${resource}] ${g.as}: could not check the backend, will ask again: ${scrub(err, password)}`);
+          // Unable to ask is not evidence of loss. Kept as applied, asked again next time — but a
+          // check that keeps failing is a consumer failed all the same (ADR 0224, issue 179).
+          const text = scrub(err, password);
+          console.error(`[provisioner:${resource}] ${g.as}: could not check the backend, will ask again: ${text}`);
+          await failed(g.as, g.node, classed(err, text), text);
           // A backend that did not answer in time will not answer for the next consumer either, and
           // each would cost a timeout, so the rest of this pass is not asked. Any other failure may
           // be this consumer's alone, and the others are still asked.
@@ -356,6 +404,7 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
           await adapter.reenable({ as: g.as, derived: was.derived ?? p.derived });
         }
         await adapter.create(p);
+        await succeeded(g.as);
         applied.set(g.as, { hash: h, derived: p.derived, node: g.node });
         if (retired.has(g.as)) {
           // Asked for again: the ordinary create re-enabled it and cleared its mark (ADR 0230).
@@ -376,7 +425,9 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
           }
         }
       } catch (err) {
-        console.error(`[provisioner:${resource}] ${g.as}: create failed, will retry: ${scrub(err, password)}`);
+        const text = scrub(err, password);
+        console.error(`[provisioner:${resource}] ${g.as}: create failed, will retry: ${text}`);
+        await failed(g.as, g.node, classed(err, text), text);
         // A failed create is not a disagreement: asked again at the next check, the count unchanged.
         if (reapplying !== undefined) lost.set(g.as, { times: reapplying - 1, nextAt: 0 });
       }
@@ -386,6 +437,12 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
     // `stablePasses` passes, and within the bound, or with a person's word (novox/hq ADR 0230).
     // Only consumers this harness applied, or the backend says the mesh made, are touched.
     const unasked = [...applied.keys()].filter((as) => !wantByAs.has(as)).sort();
+    // A consumer the mesh stopped asking for that this provider holds nothing for is no longer failed
+    // by anyone: said, so the standing the controller keeps for it is cleared rather than left naming a
+    // consumer that is gone. One still held is said recovered when it is retired (ADR 0224, 0230).
+    for (const as of [...trouble.keys()]) {
+      if (!wantByAs.has(as) && !applied.has(as)) await recovered(as, "no longer asked for");
+    }
     const key = unasked.join(",");
     if (pending && pending.consumers.join(",") !== key) {
       say(`the retirement waiting for a person (${pending.consumers.join(", ")}) is no longer what the mesh says; settled, nothing retired`);
@@ -464,6 +521,7 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
         }
         applied.delete(as);
         lost.delete(as);
+        await recovered(as, "retired");
         retired.set(as, { node: was.node, at: at.getTime(), why, derived: was.derived, access: adapter.retire ? "disabled" : "kept" });
         done.push(as);
       } catch (err) {
@@ -485,16 +543,86 @@ export function runProvisioner(resource: string, adapter: Adapter, opts: Provisi
 
   // Said on the bus, never failing the act it reports (the journal still has it).
   async function tell(change: string, body: Record<string, unknown>): Promise<void> {
-    if (!opts.announce) return;
+    await said(RETIREMENT_EVENT, {
+      provider: resource, "provider-node": node, change, bound: bound(applied.size), at: iso(Date.now()), ...body,
+    }, change);
+  }
+
+  async function said(event: string, body: Record<string, unknown>, what = ""): Promise<void> {
     try {
-      await opts.announce(RETIREMENT_EVENT, {
-        provider: resource, "provider-node": node, change, bound: bound(applied.size), at: iso(Date.now()), ...body,
-      });
+      await announce(event, body);
     } catch (err) {
-      say(`could not announce ${RETIREMENT_EVENT} ${change}: ${err}`);
+      say(`could not announce ${event}${what ? ` ${what}` : ""}: ${err}`);
     }
   }
 
+  // An error's class: the adapter's word when it has one, else read from the text (ADR 0224).
+  function classed(err: unknown, text: string): string {
+    try {
+      const own = adapter.classify?.(err);
+      if (own) return own;
+    } catch {
+      // An adapter that cannot class its own error is read by the words.
+    }
+    // A check that did not answer in time is a backend out of reach, whatever its words.
+    if (err instanceof HoldsTimeout) return CLASS_UNREACHABLE;
+    return classOf(text);
+  }
+
+  // One more failure in a consumer's unbroken run, announced once the run has lasted failingAfterMs,
+  // then again every sayAgainEveryMs while it lasts (novox/hq ADR 0224).
+  async function failed(as: string, consumerNode: string | undefined, cls: string, text: string): Promise<void> {
+    const now = Date.now();
+    let s = trouble.get(as);
+    if (!s) {
+      s = { since: now, attempts: 0, cls, text, saidAt: 0 };
+      trouble.set(as, s);
+    }
+    s.node = consumerNode;
+    s.cls = cls;
+    s.text = text;
+    s.attempts++;
+    if (now - s.since < failingAfterMs) return;
+    if (s.saidAt !== 0 && now - s.saidAt < sayAgainEveryMs) return;
+    if (s.saidAt === 0) {
+      say(
+        `${as}: FAILING for ${Math.round((now - s.since) / 1000)}s (${s.attempts} attempts, ${cls}): ${text}. ` +
+          `Announced as ${FAILING_EVENT}; \`status\` names it until it succeeds (novox/hq ADR 0224)`,
+      );
+    }
+    s.saidAt = now;
+    await said(FAILING_EVENT, {
+      provider: resource, "provider-node": node, consumer: as, node: consumerNode ?? "",
+      class: cls, error: clip(text), since: iso(s.since), attempts: s.attempts,
+    });
+  }
+
+  // A success ends a consumer's run of failures; one that was announced is announced recovered. And
+  // the first success for a consumer since this process started is announced too, failing or not: a
+  // provider that announced a failure and was restarted has forgotten it, and without this the
+  // controller would name the consumer failing for ever after it recovered unheard.
+  async function succeeded(as: string): Promise<void> {
+    if (!trouble.has(as) && !cleared.has(as)) {
+      cleared.add(as);
+      await said(RECOVERED_EVENT, { provider: resource, "provider-node": node, consumer: as, why: "first-success" });
+      return;
+    }
+    cleared.add(as);
+    await recovered(as, "");
+  }
+
+  async function recovered(as: string, why: string): Promise<void> {
+    const s = trouble.get(as);
+    if (!s) return;
+    trouble.delete(as);
+    if (s.saidAt === 0) return; // never announced, so there is nothing to take back
+    if (!why) say(`${as}: recovered after ${Math.round((Date.now() - s.since) / 1000)}s and ${s.attempts} failed attempt(s)`);
+    await said(RECOVERED_EVENT, {
+      provider: resource, "provider-node": node, consumer: as, node: s.node ?? "",
+      since: iso(s.since), attempts: s.attempts, ...(why ? { why } : {}),
+    });
+  }
+
   // What the backend holds that the mesh made: active ones become held, so one the mesh stopped asking
   // for while this process was down is still retired, by the same rules; retired ones are known.
   async function seed(): Promise<void> {
@@ -713,6 +841,27 @@ async function readContributions(
   return (doc.given as Contribution[]).filter((g) => g.as && g.secret);
 }
 
+/** An error's class read from its text — the words the backends the mesh runs use (novox/hq ADR
+ *  0224): the same words, in the same order, as the Go copy of this loop reads. */
+export function classOf(text: string): string {
+  const t = text.toLowerCase();
+  const credentials = ["invalid_grant", "invalid user credentials", "password authentication failed",
+    "authentication failed", "unauthorized", " 401"];
+  if (credentials.some((w) => t.includes(w))) return CLASS_CREDENTIALS;
+  const unreachable = ["connection refused", "no such host", "i/o timeout", "deadline exceeded",
+    "connection reset", "network is unreachable", "no route to host", "eof",
+    // Node's own words for the same faults.
+    "econnrefused", "enotfound", "etimedout", "econnreset", "ehostunreach", "enetunreach", "eai_again"];
+  if (unreachable.some((w) => t.includes(w))) return CLASS_UNREACHABLE;
+  return CLASS_REFUSED;
+}
+
+/** An announced error kept to what belongs in a status line. */
+function clip(text: string): string {
+  const most = 300;
+  return text.length <= most ? text : `${text.slice(0, most)}…`;
+}
+
 /** A check that did not answer in time: the backend, not the consumer, is the likely cause. */
 class HoldsTimeout extends Error {}