diff --git a/.changeset/vivid-ibex-bark.md b/.changeset/vivid-ibex-bark.md new file mode 100644 index 000000000..66d2eb602 --- /dev/null +++ b/.changeset/vivid-ibex-bark.md @@ -0,0 +1,5 @@ +--- +type: Fixed +pr: 2621 +--- +**`GSD_AUDIT=1` now actually produces an audit trail** — the reference dispatch logger is wired onto the live command seam, so opting in yields the documented structured stderr line and the `.planning/.gsd-trace.jsonl` audit trail. Previously the seam built its dispatch hub without a logger, so it fell back to a no-op and the opt-in signal was inert with no indication why. With observability off, dispatch output is byte-for-byte unchanged. (#2620) diff --git a/src/cjs-command-router-adapter.cts b/src/cjs-command-router-adapter.cts index ddaed40c9..8af843ac9 100644 --- a/src/cjs-command-router-adapter.cts +++ b/src/cjs-command-router-adapter.cts @@ -13,6 +13,17 @@ // eslint-disable-next-line @typescript-eslint/no-require-imports import commandRoutingHub = require('./command-routing-hub.cjs'); const { createHub, ERROR_KINDS } = commandRoutingHub; +// #2620 (ADR-0174 §6): the Hub defaults to a no-op logger and the live CLI +// dispatch path never injected the reference DispatchLogger, so GSD_AUDIT and +// config.audit.enabled were inert. Inject the reference logger ONLY when +// observability is opt-in enabled; when off, inject nothing so the Hub stays +// byte-for-byte silent (preserving the default dispatch output contract, incl. +// --json-errors). Enabling stderr-on-error unconditionally by default is a +// separate, blast-radius-bearing change (it adds a second stderr line to the +// --json-errors envelope) — deferred as its own follow-up. +// eslint-disable-next-line @typescript-eslint/no-require-imports +import observabilityLogger = require('./observability/logger.cjs'); +const { createDefaultLogger, isAuditEnabled } = observabilityLogger; // Phase 2 (#1646): import ERROR_REASON so the UnknownCommand translation can // pass `sdk_unknown_command` as the second arg to error(), preserving the // JSON-error envelope contract that capability routers' tests assert on. @@ -134,6 +145,10 @@ function routeHubCommandFamily({ const hub = createHub({ cjsRegistry: { [family]: registryHandlers }, manifest: { [family]: available }, + // #2620: wire the reference logger onto the live dispatch path (ADR-0174 §6), + // but only when observability is opt-in enabled — otherwise leave it unset + // so the Hub falls back to the no-op logger and stays byte-for-byte silent. + logger: isAuditEnabled() ? createDefaultLogger({ cwd }) : undefined, }); const result = hub.dispatch({ diff --git a/src/observability/logger.cts b/src/observability/logger.cts index 9bc9007b7..0d1ebd07d 100644 --- a/src/observability/logger.cts +++ b/src/observability/logger.cts @@ -42,9 +42,14 @@ function _safeStringify(value: unknown): string { } /** - * Determine whether the audit file should be written to. + * Determine whether observability is opt-in enabled — via the GSD_AUDIT env var + * or config.audit.enabled. Exported (#2620) so the live dispatch seam can decide + * whether to inject the reference logger at all: when observability is off we + * inject nothing (the Hub stays byte-for-byte silent, preserving the default + * dispatch output contract, incl. --json-errors); when on, the caller injects + * createDefaultLogger and gets the stderr-on-error line + opt-in file audit. */ -function _isAuditEnabled(config: { audit?: { enabled?: boolean } } | undefined): boolean { +function _isAuditEnabled(config?: { audit?: { enabled?: boolean } }): boolean { if (process.env['GSD_AUDIT'] === '1') return true; if (config && config.audit && config.audit.enabled === true) return true; return false; @@ -163,4 +168,4 @@ function createDefaultLogger({ cwd = process.cwd(), config }: DefaultLoggerOptio }; } -export = { createDefaultLogger, createNoOpLogger }; +export = { createDefaultLogger, createNoOpLogger, isAuditEnabled: _isAuditEnabled }; diff --git a/src/phase-command-router.cts b/src/phase-command-router.cts index 3d4e0822f..9ffecddf1 100644 --- a/src/phase-command-router.cts +++ b/src/phase-command-router.cts @@ -21,6 +21,12 @@ import { PHASE_SUBCOMMANDS } from './command-aliases.cjs'; // eslint-disable-next-line @typescript-eslint/no-require-imports import commandRoutingHub = require('./command-routing-hub.cjs'); const { createHub, ERROR_KINDS, makeInvalidArgs } = commandRoutingHub; +// #2620 (ADR-0174 §6): inject the reference DispatchLogger on the live phase +// dispatch path, but only when observability is opt-in enabled; otherwise the +// Hub stays byte-for-byte silent via its no-op fallback. +// eslint-disable-next-line @typescript-eslint/no-require-imports +import observabilityLogger = require('./observability/logger.cjs'); +const { createDefaultLogger, isAuditEnabled } = observabilityLogger; // ─── Types ──────────────────────────────────────────────────────────────────── @@ -246,7 +252,10 @@ function routePhaseCommand({ phase, args, cwd, raw, error }: RoutePhaseCommandOp // ── Construct hub ────────────────────────────────────────────────────────── // #175: Hub is CJS-only — no mode param, no sdkLoader. - const hub = createHub({ cjsRegistry, manifest }); + // #2620: wire the reference logger (ADR-0174 §6) only when observability is + // opt-in enabled; otherwise leave it unset so the Hub stays byte-for-byte + // silent via its no-op fallback. + const hub = createHub({ cjsRegistry, manifest, logger: isAuditEnabled() ? createDefaultLogger({ cwd }) : undefined }); // ── Dispatch ──────────────────────────────────────────────────────────────── const result = hub.dispatch({ diff --git a/tests/cjs-command-router-adapter.test.cjs b/tests/cjs-command-router-adapter.test.cjs index be92d0564..7fb069806 100644 --- a/tests/cjs-command-router-adapter.test.cjs +++ b/tests/cjs-command-router-adapter.test.cjs @@ -629,3 +629,56 @@ describe('bug #3631 — SDK family routers forward --raw to output()', () => { }); }); } + +// ──────────────────────────────────────────────────────────────────────── +// Regression for #2620 — the live adapter must inject a real DispatchLogger +// (ADR-0174 §6: "DispatchLogger is injected; the Hub emits DispatchEvent on +// every dispatch path"). Before the fix, routeHubCommandFamily built the Hub +// with no logger, so it fell back to createNoOpLogger and GSD_AUDIT was inert. +// ──────────────────────────────────────────────────────────────────────── +{ + const { describe, test } = require('node:test'); + const assert = require('node:assert/strict'); + const fs = require('node:fs'); + const path = require('node:path'); + const { routeHubCommandFamily } = require('../gsd-core/bin/lib/cjs-command-router-adapter.cjs'); + const { createTempDir, cleanup } = require('./helpers.cjs'); + + describe('cjs-command-router-adapter — observability logger wiring (#2620)', () => { + test('a dispatch through the live adapter writes the opt-in audit trail when GSD_AUDIT=1', (t) => { + const tmp = createTempDir('gsd-obs-wire-'); + const prev = process.env.GSD_AUDIT; + t.after(() => { + if (prev === undefined) delete process.env.GSD_AUDIT; + else process.env.GSD_AUDIT = prev; + cleanup(tmp); + }); + process.env.GSD_AUDIT = '1'; + + routeHubCommandFamily({ + family: 'unit', + args: ['unit', 'ok'], + subcommands: ['ok'], + handlers: { ok: () => {} }, + unknownMessage: (subcommand, available) => `Unknown ${subcommand}. Available: ${available.join(', ')}`, + error: () => {}, + cwd: tmp, + raw: false, + }); + + const auditPath = path.join(tmp, '.planning', '.gsd-trace.jsonl'); + assert.ok( + fs.existsSync(auditPath), + 'GSD_AUDIT=1 must produce .planning/.gsd-trace.jsonl — the adapter must build the Hub with a real DispatchLogger (ADR-0174 §6), not createNoOpLogger' + ); + const lines = fs.readFileSync(auditPath, 'utf8').trim().split(/\r?\n/).filter(Boolean); + assert.ok(lines.length > 0, 'at least one dispatch event must be recorded'); + assert.equal(lines.length, 1, 'exactly one dispatch event must be recorded'); + const event = JSON.parse(lines[0]); + assert.equal(event.result.kind, 'ok', 'a successful dispatch is recorded with result.kind === "ok"'); + assert.ok(typeof event.command === 'string' && event.command.length > 0, 'event carries the dispatched command'); + assert.ok(typeof event.traceId === 'string' && event.traceId.length > 0, 'event carries a traceId'); + assert.ok(typeof event.timestamp === 'string' && event.timestamp.length > 0, 'event carries an ISO timestamp'); + }); + }); +} diff --git a/tests/phase-command-router.test.cjs b/tests/phase-command-router.test.cjs index 674f99ef0..b04536634 100644 --- a/tests/phase-command-router.test.cjs +++ b/tests/phase-command-router.test.cjs @@ -564,3 +564,79 @@ describe('bug-1437 — phase.list-plans is wired in gsd-tools', () => { }); }); } + +// ─── 6. Observability logger wiring (#2620) ────────────────────────────────── +// +// The fix wires the reference DispatchLogger at BOTH live createHub() seams. +// The sibling seam (cjs-command-router-adapter) is covered in its own file; +// this pins the phase seam so a later refactor that drops the isAuditEnabled() +// gate or the injection here cannot reintroduce the #2620 defect silently. +{ + const fs = require('node:fs'); + const path = require('node:path'); + const { createTempDir, cleanup } = require('./helpers.cjs'); + + describe('phase-command-router — observability logger wiring (#2620)', () => { + test('a dispatch through the phase seam writes the opt-in audit trail when GSD_AUDIT=1', (t) => { + const tmp = createTempDir('gsd-obs-phase-'); + const prevAudit = process.env.GSD_AUDIT; + t.after(() => { + if (prevAudit === undefined) delete process.env.GSD_AUDIT; + else process.env.GSD_AUDIT = prevAudit; + cleanup(tmp); + }); + process.env.GSD_AUDIT = '1'; + + const phase = makePhase({ cmdPhaseNextDecimal: () => {} }); + routePhaseCommand({ + phase, + args: ['phase', 'next-decimal', '5'], + cwd: tmp, + raw: false, + error: (m) => { throw new Error(m); }, + }); + + const auditPath = path.join(tmp, '.planning', '.gsd-trace.jsonl'); + assert.ok( + fs.existsSync(auditPath), + 'GSD_AUDIT=1 must produce .planning/.gsd-trace.jsonl — the phase router must build the Hub with a real DispatchLogger (ADR-0174 §6), not createNoOpLogger' + ); + + const lines = fs.readFileSync(auditPath, 'utf8').trim().split(/\r?\n/).filter(Boolean); + assert.ok(lines.length > 0, 'at least one dispatch event must be recorded'); + assert.equal(lines.length, 1, 'exactly one dispatch event must be recorded'); + + const event = JSON.parse(lines[0]); + assert.equal(event.result.kind, 'ok', 'a successful dispatch is recorded with result.kind === "ok"'); + assert.ok(typeof event.command === 'string' && event.command.length > 0, 'event carries the dispatched command'); + assert.ok(typeof event.traceId === 'string' && event.traceId.length > 0, 'event carries a traceId'); + assert.ok(typeof event.timestamp === 'string' && event.timestamp.length > 0, 'event carries an ISO timestamp'); + }); + + test('no audit trail is written when GSD_AUDIT is unset (Hub stays silent via the no-op fallback)', (t) => { + const tmp = createTempDir('gsd-obs-phase-off-'); + const prevAudit = process.env.GSD_AUDIT; + t.after(() => { + if (prevAudit === undefined) delete process.env.GSD_AUDIT; + else process.env.GSD_AUDIT = prevAudit; + cleanup(tmp); + }); + delete process.env.GSD_AUDIT; + + const phase = makePhase({ cmdPhaseNextDecimal: () => {} }); + routePhaseCommand({ + phase, + args: ['phase', 'next-decimal', '5'], + cwd: tmp, + raw: false, + error: (m) => { throw new Error(m); }, + }); + + assert.equal( + fs.existsSync(path.join(tmp, '.planning', '.gsd-trace.jsonl')), + false, + 'without the opt-in signal the seam must leave no audit artifact' + ); + }); + }); +}