opencode: persist custody telemetry to a bounded file, and say so when serving

packages/opencode/README.md

@@ -65,7 +65,7 @@ grep -cE '^\s*(catch|} catch)|^\s*return[; ]|^\s*continue;' packages/opencode/sr
 | closing-wave worktree | 27 | 18 | 13 | 9 |
 | custody review triage | 27 | 18 | 13 | 9 |
 | `a3b3a6c` | 27 | 21 | 13 | 10 |
-| current (this commit) | 32 | 41 | 13 | 14 |
+| current (this commit) | 33 | 41 | 13 | 15 |
 
 A changed count without a matching sweep row is a review failure, not harmless churn.
 

packages/opencode/src/handles.ts

@@ -40,7 +40,7 @@ function handleIsValid(handle: unknown): handle is string {
   return typeof handle === "string" && /^ckh_[A-Za-z0-9_-]{43}$/.test(handle);
 }
 
-function identifierIsValid(value: unknown): value is string {
+export function identifierIsValid(value: unknown): value is string {
   return typeof value === "string" && PROVIDER_ID.test(value) && !FORBIDDEN_IDENTIFIERS.has(value);
 }
 

packages/opencode/src/log.ts

@@ -1,3 +1,8 @@
+import { appendFileSync, chmodSync, mkdirSync, renameSync, statSync } from "node:fs";
+import { dirname, join } from "node:path";
+
+import { identifierIsValid } from "./handles";
+
 export type LogLevel = "debug" | "info" | "warn" | "error";
 
 export type CustodyLogEntry = {
@@ -12,6 +17,8 @@ export type CustodyLogEntry = {
   errorClass?: string;
   errorCode?: string;
   errorMessage?: string;
+  ts?: string;
+  pid?: number;
 };
 
 export type LogSink = (entry: CustodyLogEntry) => void;
@@ -23,21 +30,131 @@ export type CustodyLogger = {
   error(entry: Omit<CustodyLogEntry, "level">): void;
 };
 
-function defaultSink(entry: CustodyLogEntry): void {
-  const out = entry.level === "debug"
-    ? console.debug
-    : entry.level === "warn" || entry.level === "error"
-      ? console.error
-      : console.log;
-  out(JSON.stringify(entry));
+const FILE_LIMIT_BYTES = 5 * 1024 * 1024;
+export const FILE_FIELDS: Array<keyof CustodyLogEntry> = [
+  "level", "provider", "label", "credentialId", "recordVersion", "state", "httpStatus",
+  "cooldownUntil", "errorClass", "errorCode", "ts", "pid",
+];
+const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/;
+// A ≤24-character lowercase-snake residual such as sk_fake_secret shares the admitted code shape and is not all-hex.
+export const ERROR_CLASS = /^(?:[A-Z][A-Za-z0-9]{0,47}|[a-z][a-z0-9_]{1,23})$/;
+export const ERROR_CODE = /^(?:[A-Z][A-Z0-9_]{1,23}|[a-z][a-z0-9_]{1,23})$/;
+export function isAllHexBody(value: string): boolean {
+  return /^[0-9a-f]+$/i.test(value);
+}
+const LEVELS = new Set(["debug", "info", "warn", "error"]);
+const ISO_TIMESTAMP = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z$/;
+export const STATES = new Set([
+  "available", "transient", "cooldown", "reauth", "other_owner", "orphan", "split", "unmanaged",
+  "refusing", "serving", "served", "gone",
+]);
+
+// Console is the OpenCode TUI's stdout: only faults belong there. Happy-path
+// telemetry (info/debug) is file-only, or it becomes noise in the operator's screen.
+function consoleSink(entry: CustodyLogEntry): void {
+  if (entry.level !== "warn" && entry.level !== "error") return;
+  console.error(JSON.stringify(entry));
+}
+
+export type FileLogSinkOptions = {
+  path?: string;
+  env?: NodeJS.ProcessEnv;
+  warn?: (message: string) => void;
+};
+
+function defaultFilePath(env: NodeJS.ProcessEnv): string {
+  const stateHome = env.XDG_STATE_HOME || (env.HOME ? join(env.HOME, ".local", "state") : ".local/state");
+  return join(stateHome, "cortexkit", "opencode-plugin", "custody.jsonl");
+}
+
+function fileEntry(entry: CustodyLogEntry): Record<string, unknown> {
+  // These pre-filter additions are process-generated ts/pid only; caller-influenced values enter through entry and their rules.
+  const withMetadata = { ...entry, ts: new Date().toISOString(), pid: process.pid };
+  const safe: Record<string, unknown> = {};
+  for (const field of FILE_FIELDS) {
+    if (withMetadata[field] !== undefined) {
+      const value = withMetadata[field];
+      if (typeof value !== "string") {
+        safe[field] = (typeof value === "number" && Number.isFinite(value)) || typeof value === "boolean"
+          ? value
+          : "invalid_shape";
+        continue;
+      }
+      let valid: boolean;
+      switch (field) {
+        case "level": valid = LEVELS.has(value); break;
+        case "provider":
+        case "label": valid = identifierIsValid(value); break;
+        case "credentialId": valid = CREDENTIAL_ID.test(value); break;
+        case "state": valid = STATES.has(value); break;
+        case "errorClass": valid = ERROR_CLASS.test(value) && !isAllHexBody(value); break;
+        case "errorCode": valid = ERROR_CODE.test(value) && !isAllHexBody(value); break;
+        case "ts": valid = ISO_TIMESTAMP.test(value); break;
+        default: valid = false;
+      }
+      safe[field] = valid ? value : "invalid_shape";
+    }
+  }
+  return safe;
+}
+
+export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink {
+  const env = options.env ?? process.env;
+  if (options.path === undefined && ["off", "0", "false", "no"].includes(env.CLAUSTRUM_CUSTODY_LOG ?? "")) {
+    return () => {};
+  }
+  const path = options.path ?? env.CLAUSTRUM_CUSTODY_LOG ?? defaultFilePath(env);
+  const warn = options.warn ?? ((message: string) => console.error(JSON.stringify({
+    level: "warn",
+    errorCode: "custody_log_unavailable",
+    errorMessage: message,
+  })));
+  let unavailable = false;
+  let initialized = false;
+  const fail = () => {
+    if (unavailable) return;
+    unavailable = true;
+    warn("persistent custody log unavailable; info/debug telemetry dropped, faults still reach the console");
+  };
+  const rotateIfNeeded = () => {
+    try {
+      if (statSync(path).size > FILE_LIMIT_BYTES) {
+        renameSync(path, `${path}.1`);
+        chmodSync(`${path}.1`, 0o600);
+      }
+    } catch (error) {
+      if ((error as NodeJS.ErrnoException).code !== "ENOENT") throw error;
+    }
+  };
+  return (entry) => {
+    if (unavailable) return;
+    try {
+      if (!initialized) {
+        mkdirSync(dirname(path), { recursive: true, mode: 0o700 });
+        chmodSync(dirname(path), 0o700);
+        rotateIfNeeded();
+        initialized = true;
+      }
+      rotateIfNeeded();
+      appendFileSync(path, `${JSON.stringify(fileEntry(entry))}\n`, { mode: 0o600 });
+      chmodSync(path, 0o600);
+    } catch {
+      fail();
+    }
+  };
 }
 
-export function createLogger(sink: LogSink = defaultSink): CustodyLogger {
+export function createLogger(sink?: LogSink): CustodyLogger {
+  const fileSink = sink ? undefined : createFileLogSink();
+  const output = sink ?? ((entry: CustodyLogEntry) => {
+    consoleSink(entry);
+    fileSink?.(entry);
+  });
   return {
-    debug: (entry) => sink({ level: "debug", ...entry }),
-    info: (entry) => sink({ level: "info", ...entry }),
-    warn: (entry) => sink({ level: "warn", ...entry }),
-    error: (entry) => sink({ level: "error", ...entry }),
+    debug: (entry) => output({ level: "debug", ...entry }),
+    info: (entry) => output({ level: "info", ...entry }),
+    warn: (entry) => output({ level: "warn", ...entry }),
+    error: (entry) => output({ level: "error", ...entry }),
   };
 }
 

packages/opencode/src/plugin.ts

@@ -204,6 +204,7 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci
   const handleReader = dependencies.handleReader ?? readHandleFile;
   const authReader = dependencies.authReader ?? readAuthFile;
   const log = createLogger(dependencies.logSink ?? (dependencies.log ? serializedLogSink(dependencies.log) : undefined));
+  const announcedProviders = new Set<string>();
   if (process.env.CLAUSTRUM_CUSTODY_DISABLE === "1") {
     return async () => ({
       config: async () => {
@@ -359,6 +360,7 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci
           // breaks the contract documented in docs/opencode-custody-design.md.
           if (owner !== undefined && owner !== OUR_PLUGIN_ID) {
             log.debug({ provider, errorClass: "other_owner", errorCode: owner });
+            log.info({ provider, state: "other_owner" });
             continue;
           }
 
@@ -369,36 +371,42 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci
             if (consumesTombstone) {
               const refusal = new CustodyOrphanError(`${sentinelShapeDrift(entry, provider)}; refusing before OpenCode can load it`);
               logError(log, refusal, provider);
+              log.info({ provider, state: "orphan" });
               configureRefusal(provider, refusal);
               continue;
             }
             if (owner === OUR_PLUGIN_ID) {
               if (entry === undefined) {
                 logError(log, new CustodyOrphanError("handle entry has no auth.json counterpart; run ck auth migrate-opencode"), provider);
+                log.info({ provider, state: "orphan" });
                 continue;
               }
               const error = new CustodySplitError(
                 `local credential is real while custody handles remain; run ck auth migrate-opencode --provider ${provider} to re-tombstone, or ck auth migrate-opencode --restore ${provider} to use the local credential`,
               );
               logError(log, error, provider);
+              log.info({ provider, state: "split" });
               const configured = materializeProvider(provider);
               if (!configured) continue;
               configured.options = {
                 ...(configured.options ?? {}),
                 fetch: async () => { throw error; },
               };
             }
+            log.info({ provider, state: "unmanaged" });
             continue;
           }
           if (owner === undefined) {
             const refusal = new CustodyOrphanError("tombstone has no serving handle; run ck auth migrate-opencode");
             logError(log, refusal, provider);
+            log.info({ provider, state: "orphan" });
             configureRefusal(provider, refusal);
             continue;
           }
           if (handle!.shape !== (entry as { type?: unknown }).type) {
             const refusal = new CustodySplitError("custody handle shape disagrees with auth entry; run ck auth migrate-opencode");
             logError(log, refusal, provider);
+            log.info({ provider, state: "split" });
             configureRefusal(provider, refusal);
             continue;
           }
@@ -411,12 +419,14 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci
               `OpenCode native LLM mode bypasses the custody fetch seam; OPENCODE_EXPERIMENTAL_NATIVE_LLM=${observed} must be unset or disabled`,
             );
             logError(log, refusal, provider);
+            log.info({ provider, state: "refusing" });
             configureRefusal(provider, refusal);
             continue;
           }
 
           const configured = materializeProvider(provider);
           if (!configured) continue;
+          log.info({ provider, state: "serving" });
           const freshness = new FreshnessController({
             provider,
             shape: handle!.shape,
@@ -457,6 +467,11 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci
               },
               readAuthEntry: async () => (await readAuth(defaultAuthPath(), authReader))[provider],
               upstreamFetch,
+              onServed: (account, recordVersion) => {
+                if (announcedProviders.has(provider)) return;
+                announcedProviders.add(provider);
+                log.info({ provider, label: account.label, credentialId: account.credential_id, recordVersion, state: "served" });
+              },
               log,
             }),
           };

packages/opencode/src/serve.ts

@@ -37,6 +37,7 @@ export type CreateServeFetchOptions = {
   freshness?: FreshnessController;
   verifyOwnership?: () => Promise<void>;
   log?: CustodyLogger;
+  onServed?: (account: ServeAccount, recordVersion: number) => void;
   // Test seam: replace the production snapshot when the test wants to drive
   // the substitution-failure catch arm with a controlled error (e.g. a
   // canary-message `withMaterial` throw) without a live daemon or a hand-
@@ -247,10 +248,14 @@ export function createServeFetch(options: CreateServeFetchOptions) {
             await discard(response);
             break;
           }
+          options.onServed?.(account, attempt.recordVersion);
           return response;
         }
         const location = response.headers.get("Location");
-        if (!location) return response;
+        if (!location) {
+          options.onServed?.(account, attempt.recordVersion);
+          return response;
+        }
         let fromOrigin: string;
         let next: URL;
         try {

packages/opencode/src/tests/log-leak.test.ts

@@ -0,0 +1,85 @@
+import { afterEach, describe, expect, test } from "bun:test";
+import { chmodSync, mkdirSync, readFileSync, rmSync, writeFileSync } from "node:fs";
+import { join } from "node:path";
+
+import { createFileLogSink, createLogger, FILE_FIELDS } from "../log";
+import { createOpencodeClaustrumPlugin } from "../plugin";
+
+const savedEnv = new Map<string, string | undefined>();
+const fixtureRoots = new Set<string>();
+const ENV_KEYS = ["CLAUSTRUM_OPENCODE_HANDLES", "CLAUSTRUM_CUSTODY_LOG", "XDG_DATA_HOME"] as const;
+
+function useEnv(key: string, value: string | undefined) {
+  if (!savedEnv.has(key)) savedEnv.set(key, process.env[key]);
+  if (value === undefined) delete process.env[key];
+  else process.env[key] = value;
+}
+
+afterEach(() => {
+  for (const [key, value] of savedEnv) {
+    if (value === undefined) delete process.env[key];
+    else process.env[key] = value;
+  }
+  savedEnv.clear();
+  for (const root of fixtureRoots) rmSync(root, { recursive: true, force: true });
+  fixtureRoots.clear();
+});
+
+describe("custody log secret absence canary", () => {
+  test("Bun SyntaxError exposes the adjacent fake handle in the malformed shape", () => {
+    const handle = `ckh_${"A".repeat(43)}`;
+    const key = "sk-fake-secret-key";
+    const malformed = `{"providers":[{"handle":${handle},"key":${key}}]`;
+
+    let message = "";
+    try {
+      JSON.parse(malformed);
+    } catch (error) {
+      message = error instanceof Error ? error.message : String(error);
+    }
+
+    expect(message).toContain(handle);
+    // Bun reports only the first unexpected token; the key is nevertheless present in the
+    // malformed input, so the integration arm exercises a non-vacuous key path separately.
+    expect(message).not.toContain(key);
+  });
+
+  test("real malformed handle file fault path never writes handle or key", async () => {
+    // This integration arm proves the real config-hook path writes a fault without secrets;
+    // handles.ts -> parseSecretJson applies the fixed-message SecretJsonParseError upstream.
+    const root = join("/tmp/opencode", `custody-log-canary-${crypto.randomUUID()}`);
+    fixtureRoots.add(root);
+    const config = join(root, "config");
+    const data = join(root, "data");
+    const handles = join(config, "cortexkit", "opencode-handles.json");
+    const custody = join(root, "custody.jsonl");
+    const handle = `ckh_${"A".repeat(43)}`;
+    const key = "sk-fake-secret-key";
+    mkdirSync(join(config, "cortexkit"), { recursive: true, mode: 0o700 });
+    mkdirSync(join(data, "opencode"), { recursive: true, mode: 0o700 });
+    writeFileSync(handles, `{"providers":[{"handle":${handle},"key":${key}}`, { mode: 0o600 });
+    chmodSync(handles, 0o600);
+    writeFileSync(join(data, "opencode", "auth.json"), JSON.stringify({}), { mode: 0o600 });
+    useEnv("CLAUSTRUM_OPENCODE_HANDLES", handles);
+    useEnv("CLAUSTRUM_CUSTODY_LOG", custody);
+    useEnv("XDG_DATA_HOME", data);
+
+    const hooks = await createOpencodeClaustrumPlugin()({} as never) as { config?: (cfg: unknown) => Promise<void> };
+    await hooks.config?.({ provider: {} });
+
+    createLogger(createFileLogSink({ path: custody })).error({ provider: "openai", errorCode: key, errorClass: handle });
+
+    const records = readFileSync(custody, "utf8").trim().split("\n").map((line) => JSON.parse(line));
+    expect(records.length).toBeGreaterThan(0);
+    for (const record of records) {
+      expect(Object.keys(record).every((key) => (FILE_FIELDS as readonly string[]).includes(key))).toBe(true);
+      expect(record).not.toHaveProperty("errorMessage");
+    }
+    const contents = readFileSync(custody, "utf8");
+    expect(contents).not.toContain(handle);
+    expect(contents).not.toContain(key);
+    const injected = records.at(-1)!;
+    expect(injected.errorCode).toBe("invalid_shape");
+    expect(injected.errorClass).toBe("invalid_shape");
+  });
+});