From 49cfe571957d009057a7e12560871f62673359d2 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Fri, 4 Sep 2026 22:51:22 +0200 Subject: [PATCH 01/12] opencode: persist custody telemetry to a bounded file, and say so when serving Custody logs previously went to the OpenCode pty and were not persisted. Add an on-by-default JSONL file sink with the configured or XDG state path, private permissions, one-generation 5 MiB rotation, and fail-open telemetry degradation. Configuration decisions and the first successful serve per provider are logged with bounded structured fields, while the secret-absence canary proves parser error text cannot enter the file. --- packages/opencode/README.md | 2 +- packages/opencode/src/log.ts | 85 +++++++++++++++++++++-- packages/opencode/src/plugin.ts | 15 ++++ packages/opencode/src/serve.ts | 7 +- packages/opencode/src/tests/log.test.ts | 68 +++++++++++++++++- packages/opencode/src/tests/serve.test.ts | 15 ++++ 6 files changed, 184 insertions(+), 8 deletions(-) diff --git a/packages/opencode/README.md b/packages/opencode/README.md index d6636ca..fcbb2b1 100644 --- a/packages/opencode/README.md +++ b/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. diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index f9c56ef..8a000e0 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -1,3 +1,6 @@ +import { appendFileSync, chmodSync, mkdirSync, renameSync, statSync } from "node:fs"; +import { dirname, join } from "node:path"; + export type LogLevel = "debug" | "info" | "warn" | "error"; export type CustodyLogEntry = { @@ -23,6 +26,12 @@ export type CustodyLogger = { error(entry: Omit): void; }; +const FILE_LIMIT_BYTES = 5 * 1024 * 1024; +const FILE_FIELDS: Array = [ + "level", "provider", "label", "credentialId", "recordVersion", "state", "httpStatus", + "cooldownUntil", "errorClass", "errorCode", +]; + function defaultSink(entry: CustodyLogEntry): void { const out = entry.level === "debug" ? console.debug @@ -32,12 +41,78 @@ function defaultSink(entry: CustodyLogEntry): void { out(JSON.stringify(entry)); } -export function createLogger(sink: LogSink = defaultSink): CustodyLogger { +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 { + const safe: Record = {}; + for (const field of FILE_FIELDS) { + if (entry[field] !== undefined) safe[field] = entry[field]; + } + return { ...safe, ts: new Date().toISOString(), pid: process.pid }; +} + +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; continuing with console logging"); + }; + const rotateIfNeeded = () => { + try { + if (statSync(path).size > FILE_LIMIT_BYTES) renameSync(path, `${path}.1`); + } 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 }); + rotateIfNeeded(); + initialized = true; + } + rotateIfNeeded(); + appendFileSync(path, `${JSON.stringify(fileEntry(entry))}\n`, { mode: 0o600 }); + chmodSync(path, 0o600); + } catch { + fail(); + } + }; +} + +export function createLogger(sink?: LogSink): CustodyLogger { + const fileSink = sink ? undefined : createFileLogSink(); + const output = sink ?? ((entry: CustodyLogEntry) => { + defaultSink(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 }), }; } diff --git a/packages/opencode/src/plugin.ts b/packages/opencode/src/plugin.ts index 8f0ddf7..c2442fd 100644 --- a/packages/opencode/src/plugin.ts +++ b/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(); 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,18 +371,21 @@ 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 = { @@ -388,17 +393,20 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci 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, }), }; diff --git a/packages/opencode/src/serve.ts b/packages/opencode/src/serve.ts index 642e2cc..9adae1a 100644 --- a/packages/opencode/src/serve.ts +++ b/packages/opencode/src/serve.ts @@ -37,6 +37,7 @@ export type CreateServeFetchOptions = { freshness?: FreshnessController; verifyOwnership?: () => Promise; 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 { diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index 6cf71fc..e3304e6 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -1,6 +1,9 @@ import { afterEach, beforeEach, describe, expect, test } from "bun:test"; +import { existsSync, mkdirSync, readFileSync, statSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; -import { createLogger, serializedLogSink } from "../log"; +import { createFileLogSink, createLogger, serializedLogSink } from "../log"; describe("custody logger", () => { const originalDebug = console.debug; @@ -63,4 +66,67 @@ describe("custody logger", () => { { level: "warn", provider: "deepseek", errorCode: "timeout" }, ]); }); + + test("file sink writes metadata and creates private parent and file", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "nested", "custody.jsonl"); + const logger = createLogger(createFileLogSink({ path })); + + logger.info({ provider: "openai", state: "serving" }); + + const line = JSON.parse(readFileSync(path, "utf8")); + expect(line).toMatchObject({ level: "info", provider: "openai", state: "serving" }); + expect(typeof line.ts).toBe("string"); + expect(line.pid).toBe(process.pid); + expect(statSync(root).mode & 0o777).toBe(0o700); + expect(statSync(join(root, "nested")).mode & 0o777).toBe(0o700); + expect(statSync(path).mode & 0o777).toBe(0o600); + }); + + test("file sink honors override and off disable", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const override = join(root, "override.jsonl"); + + createLogger(createFileLogSink({ env: { CLAUSTRUM_CUSTODY_LOG: override } })).info({ provider: "x" }); + createLogger(createFileLogSink({ env: { CLAUSTRUM_CUSTODY_LOG: "off" } })).info({ provider: "x" }); + + expect(existsSync(override)).toBe(true); + expect(existsSync(join(root, "disabled.jsonl"))).toBe(false); + }); + + test("file sink rotates at five MiB", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + mkdirSync(root, { recursive: true }); + writeFileSync(path, "x".repeat(5 * 1024 * 1024 + 1), { mode: 0o600 }); + createLogger(createFileLogSink({ path })).info({ provider: "rotated" }); + + expect(statSync(`${path}.1`).size).toBe(5 * 1024 * 1024 + 1); + expect(JSON.parse(readFileSync(path, "utf8")).provider).toBe("rotated"); + }); + + test("file sink degrades with one console warning when path is unwritable", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + mkdirSync(root, { recursive: true }); + const blocked = join(root, "blocked"); + writeFileSync(blocked, "not a directory"); + const warnings: string[] = []; + const sink = createFileLogSink({ path: join(blocked, "custody.jsonl"), warn: (message) => warnings.push(message) }); + + sink({ level: "info", provider: "x" }); + sink({ level: "info", provider: "y" }); + + expect(warnings).toHaveLength(1); + }); + + test("file sink excludes free-text error messages", () => { + const path = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}.jsonl`); + const handle = `ckh_${"A".repeat(43)}`; + const key = "sk-fake-secret-key"; + createLogger(createFileLogSink({ path })).error({ provider: "openai", errorMessage: `${handle} ${key}` }); + + const contents = readFileSync(path, "utf8"); + expect(contents).not.toContain(handle); + expect(contents).not.toContain(key); + }); }); diff --git a/packages/opencode/src/tests/serve.test.ts b/packages/opencode/src/tests/serve.test.ts index a450821..ed4e75b 100644 --- a/packages/opencode/src/tests/serve.test.ts +++ b/packages/opencode/src/tests/serve.test.ts @@ -74,6 +74,7 @@ function serve(input: { now?: () => number; readAuthEntry?: () => Promise | unknown; accounts?: Account[]; + onServed?: (account: Account, recordVersion: number) => void; }) { return createServeFetch({ provider: PROVIDER, @@ -82,6 +83,7 @@ function serve(input: { readAuthEntry: input.readAuthEntry ?? (() => tombstoneFor("api", PROVIDER)), upstreamFetch: input.upstream ?? (async () => new Response("upstream", { status: 200 })), now: input.now, + onServed: input.onServed, }); } @@ -103,6 +105,19 @@ afterEach(async () => { }); describe("OpenCode custody serve fetch", () => { + test("reports a successful serve through the bounded callback", async () => { + const served: Array<{ label: string; recordVersion: number }> = []; + const fetch = serve({ onServed: (account, recordVersion) => served.push({ label: account.label, recordVersion }) }); + + await fetch("https://upstream.example/v1/chat"); + await fetch("https://upstream.example/v1/chat"); + + expect(served).toEqual([ + { label: "main", recordVersion: 7 }, + { label: "main", recordVersion: 7 }, + ]); + }); + test("substitutes every sentinel occurrence in every header value", async () => { const requests: Request[] = []; const fetch = serve({ upstream: createUpstream([200], requests) }); From ea693235389fe5474fedd207e7a8bd244a221616 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sat, 5 Sep 2026 07:20:12 +0200 Subject: [PATCH 02/12] opencode: keep happy-path telemetry off the console MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The file sink landed alongside a console sink that still carried every level, and the new info lines were the plugin's first happy-path output ever — so they surfaced straight into the OpenCode TUI (three "serving" lines per boot). The console was quiet before by accident, not design. Console now carries warn/error only; info/debug are file-only. If the file is unavailable the one-shot warning says so and those levels are dropped rather than redirected to the screen. Pinned by inverting the test that had documented the old routing; mutation (info back to console.log) is RED. --- packages/opencode/src/log.ts | 16 +++++++--------- packages/opencode/src/tests/log.test.ts | 25 ++++++++++++++----------- 2 files changed, 21 insertions(+), 20 deletions(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 8a000e0..8330e97 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -32,13 +32,11 @@ const FILE_FIELDS: Array = [ "cooldownUntil", "errorClass", "errorCode", ]; -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)); +// 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 = { @@ -76,7 +74,7 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { const fail = () => { if (unavailable) return; unavailable = true; - warn("persistent custody log unavailable; continuing with console logging"); + warn("persistent custody log unavailable; info/debug telemetry dropped, faults still reach the console"); }; const rotateIfNeeded = () => { try { @@ -105,7 +103,7 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { export function createLogger(sink?: LogSink): CustodyLogger { const fileSink = sink ? undefined : createFileLogSink(); const output = sink ?? ((entry: CustodyLogEntry) => { - defaultSink(entry); + consoleSink(entry); fileSink?.(entry); }); return { diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index e3304e6..a164ea4 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -34,20 +34,23 @@ describe("custody logger", () => { console.error = originalError; }); - test("the default sink keeps debug on console.debug while routing info to stdout and warnings to stderr", () => { - const logger = createLogger(); - logger.debug({ provider: "deepseek", state: "available" }); - logger.info({ provider: "deepseek", state: "available" }); - logger.warn({ provider: "deepseek", state: "transient", errorCode: "timeout" }); - logger.error({ provider: "deepseek", state: "gone", errorClass: "ClaustrumCredentialError" }); - - expect(debugLines).toHaveLength(1); - expect(logLines).toHaveLength(1); + test("the console sink carries only faults: info and debug never reach stdout or stderr", () => { + // The console is the OpenCode TUI's screen. Happy-path telemetry surfacing + // there is the defect this pins (2026-09-05: three "serving" lines per boot in the TUI). + const real = createLogger(); + real.debug({ provider: "deepseek", state: "available" }); + real.info({ provider: "deepseek", state: "serving" }); + real.warn({ provider: "deepseek", state: "transient", errorCode: "timeout" }); + real.error({ provider: "deepseek", state: "gone", errorClass: "ClaustrumCredentialError" }); + + expect(debugLines).toHaveLength(0); + expect(logLines).toHaveLength(0); expect(errorLines).toHaveLength(2); - expect(debugLines[0]).toContain('"level":"debug"'); - expect(logLines[0]).toContain('"level":"info"'); expect(errorLines[0]).toContain('"level":"warn"'); expect(errorLines[1]).toContain('"level":"error"'); + for (const line of [...debugLines, ...logLines, ...errorLines]) { + expect(line).not.toContain('"state":"serving"'); + } }); test("serializedLogSink still writes every level to its caller-provided stream and never strips", () => { From 1c4d842988d84d671990133b9647b697de0277b5 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sat, 5 Sep 2026 08:50:31 +0200 Subject: [PATCH 03/12] opencode: custody log canary drives the real fault path; allowlist is the only door The secret-absence canary proved the sink drops errorMessage, not that a real SyntaxError on the handle-file path cannot reach an allowlisted field (a caller writing errorClass: String(error) would leak Bun's token-quoting message and every test would stay green). The canary now feeds a malformed handle file through the plugin's own config hook and asserts no handle or key reaches disk; the sink validates field shapes so a caller routing an error message into an allowlisted field cannot leak; mutation on the sink is RED. ts/pid join FILE_FIELDS so nothing is appended after the filter; existing dirs/files/rotations are chmod'd to 0700/0600; the off-switch test asserts the file never appears. --- packages/opencode/src/log.ts | 44 +++++++++++-- packages/opencode/src/tests/log-leak.test.ts | 66 ++++++++++++++++++++ packages/opencode/src/tests/log.test.ts | 50 +++++++++++++-- 3 files changed, 151 insertions(+), 9 deletions(-) create mode 100644 packages/opencode/src/tests/log-leak.test.ts diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 8330e97..9439b59 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -15,6 +15,8 @@ export type CustodyLogEntry = { errorClass?: string; errorCode?: string; errorMessage?: string; + ts?: string; + pid?: number; }; export type LogSink = (entry: CustodyLogEntry) => void; @@ -27,10 +29,19 @@ export type CustodyLogger = { }; const FILE_LIMIT_BYTES = 5 * 1024 * 1024; -const FILE_FIELDS: Array = [ +export const FILE_FIELDS: Array = [ "level", "provider", "label", "credentialId", "recordVersion", "state", "httpStatus", - "cooldownUntil", "errorClass", "errorCode", + "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; +const IDENTIFIER = /^[a-z0-9][a-z0-9._-]{0,63}$/; +const FORBIDDEN_IDENTIFIERS = new Set(["__proto__", "constructor", "prototype"]); +const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; +const ERROR_CLASS = /^[A-Za-z][A-Za-z0-9_]{0,63}$/; +const ERROR_CODE = /^[A-Za-z0-9_.-]{1,64}$/; +const STATES = new Set([ + "available", "transient", "cooldown", "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. @@ -51,11 +62,30 @@ function defaultFilePath(env: NodeJS.ProcessEnv): string { } function fileEntry(entry: CustodyLogEntry): Record { + const withMetadata = { ...entry, ts: new Date().toISOString(), pid: process.pid }; const safe: Record = {}; for (const field of FILE_FIELDS) { - if (entry[field] !== undefined) safe[field] = entry[field]; + if (withMetadata[field] !== undefined) { + const value = withMetadata[field]; + if (typeof value !== "string") { + safe[field] = value; + continue; + } + const valid = field === "provider" || field === "label" + ? IDENTIFIER.test(value) && !FORBIDDEN_IDENTIFIERS.has(value) + : field === "credentialId" + ? CREDENTIAL_ID.test(value) + : field === "state" + ? STATES.has(value) + : field === "errorClass" + ? ERROR_CLASS.test(value) + : field === "errorCode" + ? ERROR_CODE.test(value) + : true; + safe[field] = valid ? value : "invalid_shape"; + } } - return { ...safe, ts: new Date().toISOString(), pid: process.pid }; + return safe; } export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { @@ -78,7 +108,10 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { }; const rotateIfNeeded = () => { try { - if (statSync(path).size > FILE_LIMIT_BYTES) renameSync(path, `${path}.1`); + 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; } @@ -88,6 +121,7 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { try { if (!initialized) { mkdirSync(dirname(path), { recursive: true, mode: 0o700 }); + chmodSync(dirname(path), 0o700); rotateIfNeeded(); initialized = true; } diff --git a/packages/opencode/src/tests/log-leak.test.ts b/packages/opencode/src/tests/log-leak.test.ts new file mode 100644 index 0000000..3665276 --- /dev/null +++ b/packages/opencode/src/tests/log-leak.test.ts @@ -0,0 +1,66 @@ +import { afterEach, describe, expect, test } from "bun:test"; +import { chmodSync, mkdirSync, readFileSync, writeFileSync } from "node:fs"; +import { join } from "node:path"; + +import { createOpencodeClaustrumPlugin } from "../plugin"; + +const savedEnv = new Map(); +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(); +}); + +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 malformed = `{"providers":[{"handle":${handle}}`; + + let message = ""; + try { + JSON.parse(malformed); + } catch (error) { + message = error instanceof Error ? error.message : String(error); + } + + expect(message).toContain(handle); + }); + + 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()}`); + 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}}`, { 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 }; + await hooks.config?.({ provider: {} }); + + const contents = readFileSync(custody, "utf8"); + expect(contents.trim().length).toBeGreaterThan(0); + expect(contents).not.toContain(handle); + expect(contents).not.toContain(key); + }); +}); diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index a164ea4..44d5caa 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -3,7 +3,7 @@ import { existsSync, mkdirSync, readFileSync, statSync, writeFileSync } from "no import { tmpdir } from "node:os"; import { join } from "node:path"; -import { createFileLogSink, createLogger, serializedLogSink } from "../log"; +import { createFileLogSink, createLogger, FILE_FIELDS, serializedLogSink } from "../log"; describe("custody logger", () => { const originalDebug = console.debug; @@ -91,10 +91,32 @@ describe("custody logger", () => { const override = join(root, "override.jsonl"); createLogger(createFileLogSink({ env: { CLAUSTRUM_CUSTODY_LOG: override } })).info({ provider: "x" }); - createLogger(createFileLogSink({ env: { CLAUSTRUM_CUSTODY_LOG: "off" } })).info({ provider: "x" }); + const disabled = join(root, ".local", "state", "cortexkit", "opencode-plugin", "custody.jsonl"); + createLogger(createFileLogSink({ env: { CLAUSTRUM_CUSTODY_LOG: "off", XDG_STATE_HOME: join(root, ".local", "state") } })).info({ provider: "x" }); expect(existsSync(override)).toBe(true); - expect(existsSync(join(root, "disabled.jsonl"))).toBe(false); + expect(existsSync(disabled)).toBe(false); + }); + + test("file sink writes only FILE_FIELDS", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + createLogger(createFileLogSink({ path })).info({ provider: "openai", state: "serving" }); + + const line = JSON.parse(readFileSync(path, "utf8")); + expect(Object.keys(line).every((key) => (FILE_FIELDS as readonly string[]).includes(key))).toBe(true); + }); + + test("file sink tightens existing directory and rotated file modes", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + mkdirSync(root, { recursive: true, mode: 0o755 }); + writeFileSync(path, "x".repeat(5 * 1024 * 1024 + 1), { mode: 0o644 }); + createLogger(createFileLogSink({ path })).info({ provider: "rotated" }); + + expect(statSync(root).mode & 0o777).toBe(0o700); + expect(statSync(path).mode & 0o777).toBe(0o600); + expect(statSync(`${path}.1`).mode & 0o777).toBe(0o600); }); test("file sink rotates at five MiB", () => { @@ -123,7 +145,8 @@ describe("custody logger", () => { }); test("file sink excludes free-text error messages", () => { - const path = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}.jsonl`); + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); const handle = `ckh_${"A".repeat(43)}`; const key = "sk-fake-secret-key"; createLogger(createFileLogSink({ path })).error({ provider: "openai", errorMessage: `${handle} ${key}` }); @@ -132,4 +155,23 @@ describe("custody logger", () => { expect(contents).not.toContain(handle); expect(contents).not.toContain(key); }); + + test("file sink rejects secret-bearing values routed into allowlisted shapes", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + const handle = `ckh_${"A".repeat(43)}`; + const syntaxError = `Unexpected identifier "${handle}"`; + const key = "sk-fake-secret-key"; + createLogger(createFileLogSink({ path })).error({ + provider: "openai", + errorClass: syntaxError, + errorCode: `${key} `, + }); + + const contents = readFileSync(path, "utf8"); + expect(contents).not.toContain(handle); + expect(contents).not.toContain(key); + expect(contents).toContain('"errorClass":"invalid_shape"'); + expect(contents).toContain('"errorCode":"invalid_shape"'); + }); }); From 032d252e2f76fc18e11ab5f25ea1f9a9750ff257 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sat, 5 Sep 2026 08:55:37 +0200 Subject: [PATCH 04/12] opencode: custody log sink admits only numbers and booleans as non-strings; every file field has a named rule An object routed into an allowlisted field serialised whole, message and all, past the string-shape checks. Non-strings are now number|boolean only; level and ts get closed rules; the identifier validator is imported from handles.ts rather than copied a third time. --- packages/opencode/src/handles.ts | 2 +- packages/opencode/src/log.ts | 33 ++++++++++++++----------- packages/opencode/src/tests/log.test.ts | 16 ++++++++++++ 3 files changed, 36 insertions(+), 15 deletions(-) diff --git a/packages/opencode/src/handles.ts b/packages/opencode/src/handles.ts index f2b91ef..8b301b3 100644 --- a/packages/opencode/src/handles.ts +++ b/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); } diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 9439b59..7296099 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -1,6 +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 = { @@ -33,11 +35,11 @@ export const FILE_FIELDS: Array = [ "level", "provider", "label", "credentialId", "recordVersion", "state", "httpStatus", "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; -const IDENTIFIER = /^[a-z0-9][a-z0-9._-]{0,63}$/; -const FORBIDDEN_IDENTIFIERS = new Set(["__proto__", "constructor", "prototype"]); const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; const ERROR_CLASS = /^[A-Za-z][A-Za-z0-9_]{0,63}$/; const ERROR_CODE = /^[A-Za-z0-9_.-]{1,64}$/; +const LEVELS = new Set(["debug", "info", "warn", "error"]); +const ISO_TIMESTAMP = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z$/; const STATES = new Set([ "available", "transient", "cooldown", "other_owner", "orphan", "split", "unmanaged", "refusing", "serving", "served", "gone", @@ -68,20 +70,23 @@ function fileEntry(entry: CustodyLogEntry): Record { if (withMetadata[field] !== undefined) { const value = withMetadata[field]; if (typeof value !== "string") { - safe[field] = value; + safe[field] = (typeof value === "number" && Number.isFinite(value)) || typeof value === "boolean" + ? value + : "invalid_shape"; continue; } - const valid = field === "provider" || field === "label" - ? IDENTIFIER.test(value) && !FORBIDDEN_IDENTIFIERS.has(value) - : field === "credentialId" - ? CREDENTIAL_ID.test(value) - : field === "state" - ? STATES.has(value) - : field === "errorClass" - ? ERROR_CLASS.test(value) - : field === "errorCode" - ? ERROR_CODE.test(value) - : true; + 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); break; + case "errorCode": valid = ERROR_CODE.test(value); break; + case "ts": valid = ISO_TIMESTAMP.test(value); break; + default: valid = false; + } safe[field] = valid ? value : "invalid_shape"; } } diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index 44d5caa..23d9295 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -174,4 +174,20 @@ describe("custody logger", () => { expect(contents).toContain('"errorClass":"invalid_shape"'); expect(contents).toContain('"errorCode":"invalid_shape"'); }); + + test("file sink rejects objects routed into allowlisted fields", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + const handle = `ckh_${"A".repeat(43)}`; + createLogger(createFileLogSink({ path })).error({ + provider: "openai", + errorCode: { message: `Unexpected identifier "${handle}"` }, + errorClass: new Error(handle), + } as any); + + const contents = readFileSync(path, "utf8"); + expect(contents).not.toContain(handle); + expect(contents).not.toContain("message"); + expect(contents).toContain("invalid_shape"); + }); }); From 7efb2073b5ed224f0bb8725e2f6a57f7e7055631 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sat, 5 Sep 2026 23:35:45 +0200 Subject: [PATCH 05/12] opencode: custody log field rules reject secret shapes; STATES derived from producers ERROR_CODE and ERROR_CLASS admitted hyphen/underscore/long-token shapes that real keys and handles satisfy, and the canary forced rejection with a trailing space instead of a real value. Rules now match what the producers emit (PascalCase error names; upper- or lower-snake codes, max 32, one case class); the canary uses realistic key/handle shapes with no dodge. STATES is the exact producer set, pinned by a source scan. Integration arm parses records, asserts keys within FILE_FIELDS, and cleans its temp tree. --- packages/opencode/src/log.ts | 8 +++--- packages/opencode/src/tests/log-leak.test.ts | 23 +++++++++++---- packages/opencode/src/tests/log.test.ts | 30 ++++++++++++++++++-- 3 files changed, 50 insertions(+), 11 deletions(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 7296099..49efd19 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -36,12 +36,12 @@ export const FILE_FIELDS: Array = [ "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; -const ERROR_CLASS = /^[A-Za-z][A-Za-z0-9_]{0,63}$/; -const ERROR_CODE = /^[A-Za-z0-9_.-]{1,64}$/; +const ERROR_CLASS = /^[A-Z][A-Za-z0-9]{0,47}$/; +const ERROR_CODE = /^(?:[A-Z][A-Z0-9_]{1,31}|[a-z][a-z0-9_]{1,31})$/; const LEVELS = new Set(["debug", "info", "warn", "error"]); const ISO_TIMESTAMP = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z$/; -const STATES = new Set([ - "available", "transient", "cooldown", "other_owner", "orphan", "split", "unmanaged", +export const STATES = new Set([ + "available", "transient", "cooldown", "reauth", "other_owner", "orphan", "split", "unmanaged", "refusing", "serving", "served", "gone", ]); diff --git a/packages/opencode/src/tests/log-leak.test.ts b/packages/opencode/src/tests/log-leak.test.ts index 3665276..f86fdf9 100644 --- a/packages/opencode/src/tests/log-leak.test.ts +++ b/packages/opencode/src/tests/log-leak.test.ts @@ -1,10 +1,12 @@ import { afterEach, describe, expect, test } from "bun:test"; -import { chmodSync, mkdirSync, readFileSync, writeFileSync } from "node:fs"; +import { chmodSync, mkdirSync, readFileSync, rmSync, writeFileSync } from "node:fs"; import { join } from "node:path"; import { createOpencodeClaustrumPlugin } from "../plugin"; +import { FILE_FIELDS } from "../log"; const savedEnv = new Map(); +const fixtureRoots = new Set(); const ENV_KEYS = ["CLAUSTRUM_OPENCODE_HANDLES", "CLAUSTRUM_CUSTODY_LOG", "XDG_DATA_HOME"] as const; function useEnv(key: string, value: string | undefined) { @@ -19,12 +21,15 @@ afterEach(() => { 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 malformed = `{"providers":[{"handle":${handle}}`; + const key = "sk-fake-secret-key"; + const malformed = `{"providers":[{"handle":${handle},"key":${key}}]`; let message = ""; try { @@ -34,12 +39,16 @@ describe("custody log secret absence canary", () => { } 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"); @@ -48,7 +57,7 @@ describe("custody log secret absence canary", () => { 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}}`, { mode: 0o600 }); + 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); @@ -58,9 +67,13 @@ describe("custody log secret absence canary", () => { const hooks = await createOpencodeClaustrumPlugin()({} as never) as { config?: (cfg: unknown) => Promise }; await hooks.config?.({ provider: {} }); + 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.trim().length).toBeGreaterThan(0); expect(contents).not.toContain(handle); - expect(contents).not.toContain(key); }); }); diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index 23d9295..95f094f 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -3,7 +3,7 @@ import { existsSync, mkdirSync, readFileSync, statSync, writeFileSync } from "no import { tmpdir } from "node:os"; import { join } from "node:path"; -import { createFileLogSink, createLogger, FILE_FIELDS, serializedLogSink } from "../log"; +import { createFileLogSink, createLogger, FILE_FIELDS, serializedLogSink, STATES } from "../log"; describe("custody logger", () => { const originalDebug = console.debug; @@ -165,7 +165,7 @@ describe("custody logger", () => { createLogger(createFileLogSink({ path })).error({ provider: "openai", errorClass: syntaxError, - errorCode: `${key} `, + errorCode: key, }); const contents = readFileSync(path, "utf8"); @@ -175,6 +175,32 @@ describe("custody logger", () => { expect(contents).toContain('"errorCode":"invalid_shape"'); }); + test("STATES contains every literal state emitted by the producers", () => { + const sourceFiles = ["plugin.ts", "serve.ts", "freshness.ts"]; + const literals = sourceFiles.flatMap((file) => { + const source = readFileSync(join(import.meta.dir, "..", file), "utf8"); + return [...source.matchAll(/state\s*(?::|=)\s*"([^"]+)"/g)].map((match) => match[1]!); + }); + + expect(literals.length).toBeGreaterThanOrEqual(3); + for (const state of literals) expect(STATES.has(state)).toBe(true); + expect(STATES.has("reauth")).toBe(true); + }); + + test("producer error classes and codes retain their real shapes", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + const classes = ["SyntaxError", "HandleFileValidationError", "UpstreamFetchError", "FreshnessTickError", "AbortError"]; + const codes = ["ENOENT", "EACCES", "ERR_INVALID_ARG_TYPE", "not_found", "needs_reauth", "kind_not_gettable", "sentinel_in_request"]; + const logger = createLogger(createFileLogSink({ path })); + for (const errorClass of classes) logger.error({ provider: "openai", errorClass }); + for (const errorCode of codes) logger.error({ provider: "openai", errorCode }); + + const records = readFileSync(path, "utf8").trim().split("\n").map((line) => JSON.parse(line)); + expect(records.slice(0, classes.length).map((record) => record.errorClass)).toEqual(classes); + expect(records.slice(classes.length).map((record) => record.errorCode)).toEqual(codes); + }); + test("file sink rejects objects routed into allowlisted fields", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); From 6386b0ec32e1f8c179891e6cc2fde7d2c743977e Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sun, 6 Sep 2026 08:46:09 +0200 Subject: [PATCH 06/12] opencode: errorClass accepts the wire/snake classes producers emit; field-rule population pinned by source scan MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ERROR_CLASS admitted only Error.name values, so the freshness and ownership paths (credential_warm, transient, auth_required, other_owner) were written as invalid_shape — the rule matched half the producers. Both errorClass and errorCode now accept a PascalCase name or a lower-snake token (max 24; a 32-char hex key no longer fits), and a source scan pins every literal producer plus the wire ErrorClass set against the rules so the population cannot drift again. --- packages/opencode/src/log.ts | 4 +- packages/opencode/src/tests/log-leak.test.ts | 8 ++- packages/opencode/src/tests/log.test.ts | 55 ++++++++++++++++++-- 3 files changed, 59 insertions(+), 8 deletions(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 49efd19..ab806a0 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -36,8 +36,8 @@ export const FILE_FIELDS: Array = [ "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; -const ERROR_CLASS = /^[A-Z][A-Za-z0-9]{0,47}$/; -const ERROR_CODE = /^(?:[A-Z][A-Z0-9_]{1,31}|[a-z][a-z0-9_]{1,31})$/; +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})$/; 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([ diff --git a/packages/opencode/src/tests/log-leak.test.ts b/packages/opencode/src/tests/log-leak.test.ts index f86fdf9..88974d9 100644 --- a/packages/opencode/src/tests/log-leak.test.ts +++ b/packages/opencode/src/tests/log-leak.test.ts @@ -2,8 +2,8 @@ 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"; -import { FILE_FIELDS } from "../log"; const savedEnv = new Map(); const fixtureRoots = new Set(); @@ -67,6 +67,8 @@ describe("custody log secret absence canary", () => { const hooks = await createOpencodeClaustrumPlugin()({} as never) as { config?: (cfg: unknown) => Promise }; 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) { @@ -75,5 +77,9 @@ describe("custody log secret absence canary", () => { } 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"); }); }); diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index 95f094f..9c2392f 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -3,7 +3,15 @@ import { existsSync, mkdirSync, readFileSync, statSync, writeFileSync } from "no import { tmpdir } from "node:os"; import { join } from "node:path"; -import { createFileLogSink, createLogger, FILE_FIELDS, serializedLogSink, STATES } from "../log"; +import { + createFileLogSink, + createLogger, + ERROR_CLASS, + ERROR_CODE, + FILE_FIELDS, + serializedLogSink, + STATES, +} from "../log"; describe("custody logger", () => { const originalDebug = console.debug; @@ -177,21 +185,34 @@ describe("custody logger", () => { test("STATES contains every literal state emitted by the producers", () => { const sourceFiles = ["plugin.ts", "serve.ts", "freshness.ts"]; - const literals = sourceFiles.flatMap((file) => { - const source = readFileSync(join(import.meta.dir, "..", file), "utf8"); + const sources = sourceFiles.map((file) => readFileSync(join(import.meta.dir, "..", file), "utf8")); + const literals = sources.flatMap((source) => { return [...source.matchAll(/state\s*(?::|=)\s*"([^"]+)"/g)].map((match) => match[1]!); }); + const errorClasses = sources.flatMap((source) => [...source.matchAll(/errorClass\s*:\s*"([^"]+)"/g)].map((match) => match[1]!)); + const errorCodes = sources.flatMap((source) => [...source.matchAll(/errorCode\s*:\s*"([^"]+)"/g)].map((match) => match[1]!)); expect(literals.length).toBeGreaterThanOrEqual(3); for (const state of literals) expect(STATES.has(state)).toBe(true); expect(STATES.has("reauth")).toBe(true); + expect(errorClasses.length).toBeGreaterThanOrEqual(2); + for (const errorClass of errorClasses) expect(ERROR_CLASS.test(errorClass)).toBe(true); + expect(errorCodes.length).toBeGreaterThanOrEqual(2); + for (const errorCode of errorCodes) expect(ERROR_CODE.test(errorCode)).toBe(true); + + const customErrors = ["errors.ts", "secret-json.ts"].flatMap((file) => { + const source = readFileSync(join(import.meta.dir, "..", file), "utf8"); + return [...source.matchAll(/export class (\w+Error) extends/g)].map((match) => match[1]!); + }); + const wireErrorClasses = ["transient", "permanent", "auth_required", "context_overflow"]; + for (const errorClass of [...customErrors, ...wireErrorClasses]) expect(ERROR_CLASS.test(errorClass)).toBe(true); }); test("producer error classes and codes retain their real shapes", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); - const classes = ["SyntaxError", "HandleFileValidationError", "UpstreamFetchError", "FreshnessTickError", "AbortError"]; - const codes = ["ENOENT", "EACCES", "ERR_INVALID_ARG_TYPE", "not_found", "needs_reauth", "kind_not_gettable", "sentinel_in_request"]; + const classes = ["SyntaxError", "HandleFileValidationError", "UpstreamFetchError", "FreshnessTickError", "AbortError", "credential_warm", "transient", "permanent", "auth_required", "context_overflow", "other_owner"]; + const codes = ["ENOENT", "EACCES", "ERR_INVALID_ARG_TYPE", "not_found", "needs_reauth", "kind_not_gettable", "sentinel_in_request", "timeout", "transport_error"]; const logger = createLogger(createFileLogSink({ path })); for (const errorClass of classes) logger.error({ provider: "openai", errorClass }); for (const errorCode of codes) logger.error({ provider: "openai", errorCode }); @@ -201,6 +222,30 @@ describe("custody logger", () => { expect(records.slice(classes.length).map((record) => record.errorCode)).toEqual(codes); }); + test("secret-shaped values are rejected by both error rules", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + const handle = `ckh_${"A".repeat(43)}`; + const handlePunctuated = `ckh_${"A".repeat(20)}-${"B".repeat(10)}_${"C".repeat(13)}`; + const rows = [ + "sk-fake-secret-key", + `sk-ant-oat01-${"A".repeat(40)}`, + handle, + handlePunctuated, + "a".repeat(64), + "a".repeat(32), + "a".repeat(32).replace(/a/g, "z"), + ]; + const logger = createLogger(createFileLogSink({ path })); + for (const value of rows) logger.error({ provider: "openai", errorClass: value, errorCode: value }); + + const records = readFileSync(path, "utf8").trim().split("\n").map((line) => JSON.parse(line)); + for (const record of records) { + expect(record.errorClass).toBe("invalid_shape"); + expect(record.errorCode).toBe("invalid_shape"); + } + }); + test("file sink rejects objects routed into allowlisted fields", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); From 750452c600f2b68daa5aec7429005abace861e5a Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sun, 6 Sep 2026 09:07:42 +0200 Subject: [PATCH 07/12] opencode: custody log canary names what it proves; code-shaped residual pinned A short lowercase underscore token (sk_fake_secret) has the same shape as not_found and no rule admitting codes can reject it. The canary now claims realistic credential shapes, and a separate test pins the residual as written-verbatim so a future rule that rejects it also visibly rejects real codes. --- packages/opencode/src/log.ts | 1 + packages/opencode/src/tests/log.test.ts | 19 ++++++++++++++++++- 2 files changed, 19 insertions(+), 1 deletion(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index ab806a0..2ffd66f 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -36,6 +36,7 @@ export const FILE_FIELDS: Array = [ "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; +// Lowercase-snake residuals such as sk_fake_secret share the admitted code shape and cannot be separated from real codes. 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})$/; const LEVELS = new Set(["debug", "info", "warn", "error"]); diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index 9c2392f..d9c4147 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -222,7 +222,7 @@ describe("custody logger", () => { expect(records.slice(classes.length).map((record) => record.errorCode)).toEqual(codes); }); - test("secret-shaped values are rejected by both error rules", () => { + test("realistic credential shapes are rejected by both error rules", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); const handle = `ckh_${"A".repeat(43)}`; @@ -246,6 +246,23 @@ describe("custody logger", () => { } }); + test("a code-shaped token is indistinguishable from a code and is written as-is (declared residual)", () => { + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + const path = join(root, "custody.jsonl"); + const residual = "sk_fake_secret"; + const logger = createLogger(createFileLogSink({ path })); + logger.error({ provider: "openai", errorCode: residual, errorClass: residual }); + logger.error({ provider: "openai", errorCode: "not_found", errorClass: "not_found" }); + + // sk_fake_secret has the same shape as not_found; no provider issues this short token as a + // secret, and rejecting it would also reject real codes, so this guards against over-tightening. + const records = readFileSync(path, "utf8").trim().split("\n").map((line) => JSON.parse(line)); + expect(records[0]?.errorCode).toBe(residual); + expect(records[0]?.errorClass).toBe(residual); + expect(records[1]?.errorCode).toBe("not_found"); + expect(records[1]?.errorClass).toBe("not_found"); + }); + test("file sink rejects objects routed into allowlisted fields", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); From 53d266cb7701846e6bb7a90f842014eb84a3b4fb Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Sun, 6 Sep 2026 09:29:29 +0200 Subject: [PATCH 08/12] opencode: custody log rules reject all-hex bodies; pre-filter spread is process-generated only MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A length bound is not a shape bound: capping the snake arms at 24 moved the hex-token window, and admitting the snake wire classes in errorClass reopened it on a second field. Both rules now reject an all-hex (or all-digit) body outright — no real class or code is hex — which removes the class instead of narrowing it. The pre-filter spread in fileEntry is documented as process-generated values only. --- packages/opencode/src/log.ts | 10 +++++++--- packages/opencode/src/tests/log.test.ts | 9 +++++++++ 2 files changed, 16 insertions(+), 3 deletions(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index 2ffd66f..d267521 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -36,9 +36,12 @@ export const FILE_FIELDS: Array = [ "cooldownUntil", "errorClass", "errorCode", "ts", "pid", ]; const CREDENTIAL_ID = /^[A-Za-z0-9._:-]{1,128}$/; -// Lowercase-snake residuals such as sk_fake_secret share the admitted code shape and cannot be separated from real codes. +// 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([ @@ -65,6 +68,7 @@ function defaultFilePath(env: NodeJS.ProcessEnv): string { } function fileEntry(entry: CustodyLogEntry): Record { + // 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 = {}; for (const field of FILE_FIELDS) { @@ -83,8 +87,8 @@ function fileEntry(entry: CustodyLogEntry): Record { 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); break; - case "errorCode": valid = ERROR_CODE.test(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; } diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index d9c4147..bdb4375 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -9,6 +9,7 @@ import { ERROR_CLASS, ERROR_CODE, FILE_FIELDS, + isAllHexBody, serializedLogSink, STATES, } from "../log"; @@ -206,6 +207,10 @@ describe("custody logger", () => { }); const wireErrorClasses = ["transient", "permanent", "auth_required", "context_overflow"]; for (const errorClass of [...customErrors, ...wireErrorClasses]) expect(ERROR_CLASS.test(errorClass)).toBe(true); + expect(isAllHexBody("deadbeef")).toBe(true); + for (const value of [...errorClasses, ...errorCodes, ...customErrors, ...wireErrorClasses]) { + expect(isAllHexBody(value)).toBe(false); + } }); test("producer error classes and codes retain their real shapes", () => { @@ -235,6 +240,10 @@ describe("custody logger", () => { "a".repeat(64), "a".repeat(32), "a".repeat(32).replace(/a/g, "z"), + "a".repeat(16), + "a".repeat(24), + "A".repeat(24), + "1".repeat(24), ]; const logger = createLogger(createFileLogSink({ path })); for (const value of rows) logger.error({ provider: "openai", errorClass: value, errorCode: value }); From a77e2f7d3d2717f2ba2d03034aa50500619ce999 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Tue, 8 Sep 2026 15:10:50 +0200 Subject: [PATCH 09/12] opencode: name the all-hex false positive beside the rule that causes it An English word made only of hex letters (deadbeef, facade, decade) is rejected by isAllHexBody and lands in the file as invalid_shape while reading as an ordinary value at the call site. No producer emits one today, so the cost is a diagnosis nobody can make from the log alone -- the comment says what the symptom looks like and where it comes from. --- packages/opencode/src/log.ts | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index d267521..aa09eb0 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -39,6 +39,10 @@ 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})$/; +// False positives to expect when diagnosing: an English word made only of hex letters (deadbeef, facade, +// decade) is rejected here and reaches the file as invalid_shape while looking ordinary at the call site. +// No current producer emits one — .name gives JS error names, .code gives errno strings — so a field that +// silently reads invalid_shape is the symptom to check first if a future producer starts emitting one. export function isAllHexBody(value: string): boolean { return /^[0-9a-f]+$/i.test(value); } From 6781f8c4a83ebeb7a82566e08835321847c65bb5 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Fri, 11 Sep 2026 23:11:53 +0200 Subject: [PATCH 10/12] opencode: no plugin log level reaches the console, including faults The console sink kept warn and error on stderr, which is the OpenCode TUI's screen. An operator hit it live: a transient vault timeout printed two JSON lines over a running render. The instruction after the first leak (2026-09-05) was that all plugin logs go to the file. That fix moved info and debug and kept faults on the console, on the reasoning that only faults belong there -- a judgement substituted for the instruction. A fault is exactly when the plugin is loudest, so the carve-out preserved the defect for the case that produces the most output, and the second leak was the first one's exemption. The console sink is deleted. Every level goes to the file. Two related paths closed: - the bundled client's unknown-error-class logger defaults to console.warn, so a wire response carrying an unrecognised class printed even with our own levels silenced; the plugin now passes its file logger at the one construction site - the only remaining console write in the plugin is the once-per-process notice emitted when the log FILE is unwritable -- reporting that logging is broken is not logging, and there is nowhere else to put it The test now asserts all four levels produce zero console output rather than pinning warn and error as expected console lines. Verified by mutation: restoring the carve-out reddens it (Expected length: 0, Received length: 2). Five console.warn calls remain in the built bundle from @cortexkit/subc-client (SubcProvider handler failures). Those are upstream and not reachable through our logging path; flagged separately rather than patched here. --- packages/opencode/src/log.ts | 27 +++++++++++++++---------- packages/opencode/src/plugin.ts | 10 ++++++++- packages/opencode/src/tests/log.test.ts | 17 ++++++++-------- 3 files changed, 33 insertions(+), 21 deletions(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index aa09eb0..a463468 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -53,12 +53,21 @@ export const STATES = new Set([ "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)); -} +// NOTHING ROUTINE GOES TO THE CONSOLE. The console is the OpenCode TUI's screen, and a +// plugin writing there corrupts the operator's terminal -- including mid-render, which is +// how this surfaced twice: first as info-level "serving" lines (2026-09-05), then as +// warn/error JSON printed over the TUI during a transient vault timeout (2026-09-11). +// +// The second one is the instructive one. The first fix kept faults on the console on the +// reasoning that "only faults belong there" -- a judgement substituted for the instruction, +// which was that ALL plugin logs go to the file. A fault is exactly when the plugin is +// noisiest, so the carve-out preserved the defect for the case that produces the most output. +// +// The console sink is gone. Every level goes to the file. The ONE remaining console write in +// this module is the once-per-process notice below, emitted only when the log FILE itself is +// unwritable -- reporting that logging is broken is not logging, and there is nowhere else to +// put it. If that line is ever seen in a terminal, the file sink has failed, which is the only +// condition under which this module may speak. export type FileLogSinkOptions = { path?: string; @@ -149,11 +158,7 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { } export function createLogger(sink?: LogSink): CustodyLogger { - const fileSink = sink ? undefined : createFileLogSink(); - const output = sink ?? ((entry: CustodyLogEntry) => { - consoleSink(entry); - fileSink?.(entry); - }); + const output = sink ?? createFileLogSink(); return { debug: (entry) => output({ level: "debug", ...entry }), info: (entry) => output({ level: "info", ...entry }), diff --git a/packages/opencode/src/plugin.ts b/packages/opencode/src/plugin.ts index c2442fd..5ed1ddd 100644 --- a/packages/opencode/src/plugin.ts +++ b/packages/opencode/src/plugin.ts @@ -245,7 +245,15 @@ export function createOpencodeClaustrumPlugin(dependencies: ConfigHookDependenci const pending = (async () => { const result = await detection(); if (result.status !== "available") throw new Error(`Claustrum connection ${result.status}`); - return clientFactory(); + // The client's default unknown-class logger is `console.warn`, which is the OpenCode + // TUI's screen. Routing it into our file sink keeps the whole plugin -- including the + // vendored client bundled with it -- off the operator's terminal. Without this the + // console ban in log.ts is only two thirds enforced: our own levels are silenced and + // a wire response carrying an unrecognised error class still prints. + return clientFactory({ + logger: (errorClass: string) => + log.warn({ errorClass: typeof errorClass === "string" ? errorClass : "invalid_shape" }), + }); })(); connected = pending; try { diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index bdb4375..f38ba7e 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -43,9 +43,13 @@ describe("custody logger", () => { console.error = originalError; }); - test("the console sink carries only faults: info and debug never reach stdout or stderr", () => { - // The console is the OpenCode TUI's screen. Happy-path telemetry surfacing - // there is the defect this pins (2026-09-05: three "serving" lines per boot in the TUI). + test("NO level reaches the console: warn and error are file-only alongside info and debug", () => { + // The console is the OpenCode TUI's screen, and this pins the whole channel shut. + // Two rounds of the same defect: info-level "serving" lines in the TUI (2026-09-05), + // then warn/error JSON printed over a live render during a transient vault timeout + // (2026-09-11). The first fix exempted faults on the reasoning that only faults belong + // on a console -- but a fault is when the plugin is LOUDEST, so the carve-out kept the + // defect for the noisiest case. There is no level-based exemption now; assert all four. const real = createLogger(); real.debug({ provider: "deepseek", state: "available" }); real.info({ provider: "deepseek", state: "serving" }); @@ -54,12 +58,7 @@ describe("custody logger", () => { expect(debugLines).toHaveLength(0); expect(logLines).toHaveLength(0); - expect(errorLines).toHaveLength(2); - expect(errorLines[0]).toContain('"level":"warn"'); - expect(errorLines[1]).toContain('"level":"error"'); - for (const line of [...debugLines, ...logLines, ...errorLines]) { - expect(line).not.toContain('"state":"serving"'); - } + expect(errorLines).toHaveLength(0); }); test("serializedLogSink still writes every level to its caller-provided stream and never strips", () => { From ef4f90c7aabcad33861fd96ef90f5499bbc433b5 Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Mon, 14 Sep 2026 09:57:26 +0200 Subject: [PATCH 11/12] opencode: the log-unavailable notice must describe the drop it causes Deleting the console sink made the failure notice a lie in the same commit. It read "info/debug telemetry dropped, faults still reach the console" -- accurate while a console sink carried warn and error, false the moment that sink went away. An operator hitting an unwritable log would have gone looking for errors on a channel that no longer carries any. This is the defect class the same branch was fixing in serve.ts an hour earlier: a hardcoded literal describing behaviour it does not read. Nothing failed, because no test asserted anything about the notice at all -- it could have said anything. The notice now names the real state (every level dropped), and a test pins it to BEHAVIOUR rather than to its own wording, in two arms that cannot drift together: the claim must not promise a console carrying faults, and warn/error must produce no console output once the file is unavailable. Verified by mutation: restore the old sentence -> Expected to not contain: "reach the console" re-add a console fallback -> Expected length: 0, Received length: 2 The second mutation reddens the sibling all-levels test instead, which is the coupling working: either half of the claim can be broken alone and something fails. Found by review on the parent commit, not by the suite. --- packages/opencode/src/log.ts | 7 ++++++- packages/opencode/src/tests/log.test.ts | 28 +++++++++++++++++++++++++ 2 files changed, 34 insertions(+), 1 deletion(-) diff --git a/packages/opencode/src/log.ts b/packages/opencode/src/log.ts index a463468..4ef1fe4 100644 --- a/packages/opencode/src/log.ts +++ b/packages/opencode/src/log.ts @@ -127,7 +127,12 @@ export function createFileLogSink(options: FileLogSinkOptions = {}): LogSink { const fail = () => { if (unavailable) return; unavailable = true; - warn("persistent custody log unavailable; info/debug telemetry dropped, faults still reach the console"); + // This notice is the ONLY thing this module prints, so it must describe the state it + // actually leaves behind. It used to end "faults still reach the console", which was true + // while a console sink carried warn/error -- deleting that sink made the sentence a lie in + // the same commit, and an operator reading it would go looking for errors on a channel that + // no longer carries any. Every level is dropped once the file is gone. + warn("persistent custody log unavailable; ALL custody telemetry dropped, including warnings and errors"); }; const rotateIfNeeded = () => { try { diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index f38ba7e..adedc12 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -152,6 +152,34 @@ describe("custody logger", () => { expect(warnings).toHaveLength(1); }); + test("the unavailable notice describes the drop it actually causes, and faults really are gone", () => { + // Pins the NOTICE against the BEHAVIOUR, not against its own wording. The text used to end + // "faults still reach the console" -- true while a console sink existed, false the moment that + // sink was deleted, and nothing failed. Two arms so neither half can drift alone: the claim + // must not promise a console that carries faults, and warn/error must genuinely produce no + // console output once the file is unavailable. Re-adding a console fallback reddens arm 2; + // restoring the old sentence reddens arm 1. + const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); + mkdirSync(root, { recursive: true }); + const blocked = join(root, "blocked"); + writeFileSync(blocked, "not a directory"); + const warnings: string[] = []; + const logger = createLogger(createFileLogSink({ + path: join(blocked, "custody.jsonl"), + warn: (message) => warnings.push(message), + })); + + logger.warn({ provider: "x", state: "transient" }); + logger.error({ provider: "x", errorClass: "ClaustrumCredentialError" }); + + expect(warnings).toHaveLength(1); + expect(warnings[0]).not.toContain("reach the console"); + expect(warnings[0]).toContain("ALL custody telemetry dropped"); + expect(errorLines).toHaveLength(0); + expect(logLines).toHaveLength(0); + expect(debugLines).toHaveLength(0); + }); + test("file sink excludes free-text error messages", () => { const root = join(tmpdir(), `claustrum-log-${crypto.randomUUID()}`); const path = join(root, "custody.jsonl"); From da337acf8dd948b5938b07147215dc2198ca256c Mon Sep 17 00:00:00 2001 From: iceteaSA <171169159+iceteaSA@users.noreply.github.com> Date: Tue, 15 Sep 2026 11:14:07 +0200 Subject: [PATCH 12/12] opencode: capture every console channel, not the ones the module happens to use The console mocks covered debug, log and error. console.warn was never captured, so every "nothing reached the console" assertion in this file silently meant "nothing reached the three channels I mocked". A fallback written via console.warn passed all 16 tests -- including the one whose entire purpose is to deny console output. My own mutation on the parent commit missed it: I re-added a fallback using console.error, which is the one channel that was covered, and concluded from a red run that the comment's general claim ("re-adding a console fallback reddens arm 2") held. A mutation proves coverage of the mutation you wrote, never of the class you meant. Picking the covered member of an uncovered class reads exactly like a working guard. Capture and restore console.warn alongside the rest, and assert it empty in both console-silence tests. Verified on both channels this time: console.warn fallback -> Expected length: 0, Received length: 2 (was GREEN) console.error fallback -> same test reddens (unchanged) Found by review. --- packages/opencode/src/tests/log.test.ts | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/packages/opencode/src/tests/log.test.ts b/packages/opencode/src/tests/log.test.ts index adedc12..913a5fe 100644 --- a/packages/opencode/src/tests/log.test.ts +++ b/packages/opencode/src/tests/log.test.ts @@ -15,17 +15,26 @@ import { } from "../log"; describe("custody logger", () => { + // EVERY console channel the module could reach must be captured, not just the ones it uses + // today. Capturing a subset silently narrows every "nothing reached the console" assertion in + // this file to "nothing reached the channels I happened to mock" -- and console.warn was the + // gap: a fallback written via console.warn passed all 16 tests, including the one whose whole + // purpose is to deny console output. Found by review, after a mutation of mine used + // console.error and cleared the only channel that was covered. const originalDebug = console.debug; const originalLog = console.log; const originalError = console.error; + const originalWarn = console.warn; let debugLines: string[]; let logLines: string[]; let errorLines: string[]; + let warnLines: string[]; beforeEach(() => { debugLines = []; logLines = []; errorLines = []; + warnLines = []; console.debug = (...args: unknown[]) => { debugLines.push(args.map(String).join(" ")); }; @@ -35,12 +44,16 @@ describe("custody logger", () => { console.error = (...args: unknown[]) => { errorLines.push(args.map(String).join(" ")); }; + console.warn = (...args: unknown[]) => { + warnLines.push(args.map(String).join(" ")); + }; }); afterEach(() => { console.debug = originalDebug; console.log = originalLog; console.error = originalError; + console.warn = originalWarn; }); test("NO level reaches the console: warn and error are file-only alongside info and debug", () => { @@ -59,6 +72,7 @@ describe("custody logger", () => { expect(debugLines).toHaveLength(0); expect(logLines).toHaveLength(0); expect(errorLines).toHaveLength(0); + expect(warnLines).toHaveLength(0); }); test("serializedLogSink still writes every level to its caller-provided stream and never strips", () => { @@ -178,6 +192,7 @@ describe("custody logger", () => { expect(errorLines).toHaveLength(0); expect(logLines).toHaveLength(0); expect(debugLines).toHaveLength(0); + expect(warnLines).toHaveLength(0); }); test("file sink excludes free-text error messages", () => {