feat(observability): add DispatchLogger seam — ADR-0174 SDK retirement Phase 1.3 (#177) (#223)

* test(#177): add DispatchEvent factory failing tests

Red tests for makeDispatchEvent shape, traceId UUID v4, uniqueness,
parentTraceId-always-undefined (P1.3), args redaction toggle, ISO 8601
timestamp, and all result variant passthrough.

* feat(#177): introduce DispatchEvent factory

makeDispatchEvent produces an immutable event record per dispatch:
- traceId: crypto.randomUUID() (UUID v4)
- parentTraceId: always undefined (P1.4 wires composer)
- command, result, timestamp (ISO 8601)
- args only included when includeArgs === true (default: omitted)

* test(#177): add arg redaction policy failing tests

Red tests for shouldIncludeArgs (GSD_AUDIT_ARGS env gating) and
redactEvent (strips args from frozen events, preserves all other
fields, returns a new object, never mutates the source).

* feat(#177): introduce arg redaction policy

shouldIncludeArgs(): only GSD_AUDIT_ARGS==='1' opts in; all other
values (unset, '', '0', 'true') default to omitting args.

redactEvent(event): returns a shallow copy of the event, dropping the
args field unless opted in. Never mutates the (frozen) source event.

* test(#177): add DispatchLogger interface failing tests

Red tests covering:
- no-op logger: silent on all events, never throws
- default logger: silent on ok, one flattened JSON line to stderr on error
- default logger: audit file creation + append-only + redaction + config gate
- GSD_AUDIT env var and config.audit.enabled config gate
- GSD_AUDIT_ARGS opt-in for args inclusion
All tests use real fs under os.tmpdir() — no mocked appendFileSync.

* feat(#177): introduce DispatchLogger with default and no-op implementations

createNoOpLogger(): silent on all events — Hub default when no logger injected.
createDefaultLogger({ cwd, config }):
  - Silent on ok result
  - Flattened JSON line to stderr on error: { kind, traceId, ...typedPayload }
  - Append-only audit at .planning/.gsd-trace.jsonl when GSD_AUDIT=1 or config.audit.enabled
  - Args redacted by default; GSD_AUDIT_ARGS=1 opts in
  - Logger errors caught internally; never break dispatch callers

* test(#177): add Hub+logger integration failing tests

Red tests verifying:
- onEvent called exactly once per dispatch (ok, error, handler-throw, unknown)
- DispatchEvent shape: traceId uniqueness, command, result.kind, parentTraceId
- Logger errors contained (dispatch still returns Result, warn line to stderr)
- Hub defaults to no-op when no logger injected
- End-to-end with createDefaultLogger: silent on success, stderr on error, audit file

* feat(#177): wire DispatchLogger into CommandRoutingHub

Add optional logger param to createHub({ ..., logger }).
Defaults to createNoOpLogger() — silent, no behaviour change for callers
that don't inject a logger.

After every dispatch (success and error):
- Normalises HubResult { ok } to DispatchEvent { kind: 'ok'|error-kind }
- Calls makeDispatchEvent({ command, args, result }) to mint the event
- Calls logger.onEvent(event) exactly once
- Wraps in try/catch: logger errors emit { level:'warn', source:'DispatchLogger' }
  to stderr but never propagate to dispatch callers

* chore(#177): gitignore .planning/.gsd-trace.jsonl audit file

The audit trail is local-only, append-only, and must never be committed.
Slotted under the existing "Local scratch + Claude-test artifacts" block.

* docs(#177): document GSD_AUDIT, GSD_AUDIT_ARGS, config.audit.enabled

New ## Observability section at end of CONFIGURATION.md covering:
- Default silent/stderr behaviour overview
- Stderr error JSON format
- Audit file opt-in (env var and config key)
- Args redaction policy and GSD_AUDIT_ARGS opt-in

Also slots GSD_AUDIT and GSD_AUDIT_ARGS into the existing
## Environment Variables table (alphabetical order).

* chore(#177): add changeset for observability seam

type: Added — new DispatchLogger seam with default silent/stderr/audit behaviour.
This commit is contained in:
Tom Boucher
2026-05-24 15:22:36 -04:00
committed by GitHub
parent 4bc3653578
commit 2d14eb8873
11 changed files with 1368 additions and 10 deletions

View File

@@ -0,0 +1,155 @@
'use strict';
/**
* Tests for DispatchEvent shape factory (issue #177).
*
* Each test exercises the real module code path and asserts on
* observable behaviour (return values). No mocks, no vacuous truths.
*/
const { describe, test, beforeEach, afterEach } = require('node:test');
const assert = require('node:assert/strict');
const {
makeDispatchEvent,
} = require('../../get-shit-done/bin/lib/observability/event.cjs');
describe('makeDispatchEvent — shape', () => {
test('returns an object with required top-level fields', () => {
const event = makeDispatchEvent({
command: 'plan',
args: ['--tdd'],
result: { kind: 'ok', data: null },
});
assert.ok(typeof event.traceId === 'string', 'traceId must be a string');
assert.ok(typeof event.command === 'string', 'command must be a string');
assert.ok(typeof event.timestamp === 'string', 'timestamp must be a string');
assert.ok('result' in event, 'result must be present');
});
test('traceId is a UUID v4 (format check)', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'ok', data: null },
});
// UUID v4: xxxxxxxx-xxxx-4xxx-yxxx-xxxxxxxxxxxx
const uuidV4Re = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
assert.match(event.traceId, uuidV4Re, `traceId '${event.traceId}' is not a valid UUID v4`);
});
test('each call produces a unique traceId', () => {
const a = makeDispatchEvent({ command: 'plan', result: { kind: 'ok', data: null } });
const b = makeDispatchEvent({ command: 'plan', result: { kind: 'ok', data: null } });
assert.notEqual(a.traceId, b.traceId, 'consecutive calls must produce different traceIds');
});
test('parentTraceId is always undefined in P1.3', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'ok', data: null },
parentTraceId: 'should-be-ignored',
});
// P1.3: parentTraceId field exists but is always undefined
assert.strictEqual(event.parentTraceId, undefined, 'parentTraceId must be undefined in P1.3');
});
test('command is set from input', () => {
const event = makeDispatchEvent({
command: 'discuss',
result: { kind: 'ok', data: null },
});
assert.equal(event.command, 'discuss');
});
test('timestamp is a valid ISO 8601 string', () => {
const before = Date.now();
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'ok', data: null },
});
const after = Date.now();
const parsed = Date.parse(event.timestamp);
assert.ok(!isNaN(parsed), `timestamp '${event.timestamp}' must parse as a date`);
assert.ok(parsed >= before, 'timestamp must not be in the past');
assert.ok(parsed <= after + 5, 'timestamp must not be in the future');
});
test('result field is passed through', () => {
const result = { kind: 'UnknownCommand', command: 'bogus' };
const event = makeDispatchEvent({ command: 'bogus', result });
assert.deepStrictEqual(event.result, result);
});
});
describe('makeDispatchEvent — args field', () => {
test('args is omitted when not provided', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'ok', data: null },
});
assert.ok(!('args' in event), 'args must not be present when not supplied');
});
test('args is omitted when provided (default redaction)', () => {
// The event factory itself does NOT decide to include args — that is the
// redaction layer's job. makeDispatchEvent simply stores args as supplied.
// By default (no includeArgs), args should NOT appear in the returned event.
const event = makeDispatchEvent({
command: 'plan',
args: ['--foo', 'bar'],
result: { kind: 'ok', data: null },
includeArgs: false,
});
assert.ok(!('args' in event), 'args must be absent when includeArgs is false');
});
test('args is included when includeArgs is true', () => {
const event = makeDispatchEvent({
command: 'plan',
args: ['--foo', 'bar'],
result: { kind: 'ok', data: null },
includeArgs: true,
});
assert.ok('args' in event, 'args must be present when includeArgs is true');
assert.deepStrictEqual(event.args, ['--foo', 'bar']);
});
});
describe('makeDispatchEvent — result variants', () => {
test('ok result shape', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'ok', data: 42 },
});
assert.equal(event.result.kind, 'ok');
assert.equal(event.result.data, 42);
});
test('UnknownCommand result shape', () => {
const event = makeDispatchEvent({
command: 'bogus',
result: { kind: 'UnknownCommand', command: 'bogus' },
});
assert.equal(event.result.kind, 'UnknownCommand');
assert.equal(event.result.command, 'bogus');
});
test('InvalidArgs result shape', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'InvalidArgs', arg: '--bad', reason: 'not recognised' },
});
assert.equal(event.result.kind, 'InvalidArgs');
assert.equal(event.result.arg, '--bad');
});
test('HandlerFailure result shape', () => {
const event = makeDispatchEvent({
command: 'plan',
result: { kind: 'HandlerFailure', message: 'boom' },
});
assert.equal(event.result.kind, 'HandlerFailure');
assert.equal(event.result.message, 'boom');
});
});

View File

@@ -0,0 +1,305 @@
'use strict';
/**
* Integration tests for the Hub + DispatchLogger seam (issue #177).
*
* These tests verify that:
* 1. The Hub calls logger.onEvent exactly once per dispatch.
* 2. The event passed to the logger has the correct shape.
* 3. Logger errors do NOT propagate to the dispatch caller.
* 4. The no-op logger is used when no logger is injected.
* 5. A custom logger (injected via constructor) receives correct events.
*
* Real Hub code is used — no mocks of the Hub itself.
* Logger is a real tracking stub (records calls, no fs writes needed here).
*/
const { describe, test, beforeEach, afterEach } = require('node:test');
const assert = require('node:assert/strict');
const fs = require('fs');
const path = require('path');
const os = require('os');
const {
createHub,
ERROR_KINDS,
} = require('../../get-shit-done/bin/lib/command-routing-hub.cjs');
const {
createDefaultLogger,
createNoOpLogger,
} = require('../../get-shit-done/bin/lib/observability/logger.cjs');
// ─── helpers ─────────────────────────────────────────────────────────────────
/** Creates a logger stub that records every onEvent call. */
function makeTrackingLogger() {
const calls = [];
return {
onEvent(event) {
calls.push(event);
},
calls,
};
}
function makeTmpDir() {
return fs.mkdtempSync(path.join(os.tmpdir(), 'gsd-hub-logger-test-'));
}
/** Capture all stderr writes during fn() */
function captureStderr(fn) {
const chunks = [];
const originalWrite = process.stderr.write.bind(process.stderr);
process.stderr.write = (chunk, ...rest) => {
chunks.push(typeof chunk === 'string' ? chunk : chunk.toString('utf8'));
return originalWrite(chunk, ...rest);
};
try {
fn();
} finally {
process.stderr.write = originalWrite;
}
return chunks.join('');
}
function makeHub(logger) {
const registry = {
plan: {
'': () => ({ ok: true, data: 'done' }),
},
discuss: {
'': () => ({ ok: false, kind: 'HandlerRefusal', reason: 'not now' }),
},
broken: {
'': () => { throw new Error('handler exploded'); },
},
};
const manifest = {
plan: [''],
discuss: [''],
broken: [''],
};
return createHub({ cjsRegistry: registry, manifest, logger });
}
// ─── Hub calls logger.onEvent once per dispatch ───────────────────────────────
describe('Hub + logger — onEvent called per dispatch', () => {
test('onEvent called exactly once on successful dispatch', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
assert.equal(tracking.calls.length, 1, 'onEvent must be called exactly once');
});
test('onEvent called exactly once on error dispatch', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'discuss', subcommand: '' });
assert.equal(tracking.calls.length, 1, 'onEvent must be called exactly once on error');
});
test('onEvent called exactly once when handler throws', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'broken', subcommand: '' });
assert.equal(tracking.calls.length, 1, 'onEvent must be called even when handler throws');
});
test('onEvent called once for unknown command', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'nonexistent', subcommand: '' });
assert.equal(tracking.calls.length, 1);
});
test('multiple dispatches produce multiple onEvent calls (one per dispatch)', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
hub.dispatch({ family: 'discuss', subcommand: '' });
hub.dispatch({ family: 'plan', subcommand: '' });
assert.equal(tracking.calls.length, 3);
});
});
// ─── Event shape passed to logger ────────────────────────────────────────────
describe('Hub + logger — event shape', () => {
test('event has traceId, command, result, timestamp on success', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
const event = tracking.calls[0];
assert.ok(typeof event.traceId === 'string', 'traceId must be a string');
assert.ok(typeof event.command === 'string', 'command must be a string');
assert.ok(typeof event.timestamp === 'string', 'timestamp must be a string');
assert.ok('result' in event, 'result must be present');
});
test('event.result.kind is "ok" for successful dispatch', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
assert.equal(tracking.calls[0].result.kind, 'ok');
});
test('event.result.kind is the error kind for failed dispatch', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'discuss', subcommand: '' });
assert.equal(tracking.calls[0].result.kind, 'HandlerRefusal');
});
test('event.result.kind is HandlerFailure when handler throws', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'broken', subcommand: '' });
assert.equal(tracking.calls[0].result.kind, 'HandlerFailure');
});
test('event.command includes the family', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
assert.ok(tracking.calls[0].command.includes('plan'), 'command must reference the family');
});
test('each dispatch has a unique traceId', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
hub.dispatch({ family: 'plan', subcommand: '' });
assert.notEqual(
tracking.calls[0].traceId,
tracking.calls[1].traceId,
'consecutive dispatches must produce unique traceIds'
);
});
test('event.parentTraceId is undefined in P1.3', () => {
const tracking = makeTrackingLogger();
const hub = makeHub(tracking);
hub.dispatch({ family: 'plan', subcommand: '' });
assert.strictEqual(tracking.calls[0].parentTraceId, undefined,
'parentTraceId must be undefined in P1.3');
});
});
// ─── Logger errors do not break dispatch ────────────────────────────────────
describe('Hub + logger — logger errors are contained', () => {
test('dispatch still returns Result even if logger.onEvent throws', () => {
const throwingLogger = {
onEvent() { throw new Error('logger exploded'); },
};
const hub = makeHub(throwingLogger);
let result;
// Must not throw
assert.doesNotThrow(() => {
result = hub.dispatch({ family: 'plan', subcommand: '' });
});
assert.ok(result.ok === true, 'dispatch must still return ok result despite logger failure');
});
test('logger failure emits a warn line to stderr, not an uncaught exception', () => {
const throwingLogger = {
onEvent() { throw new Error('logger is broken'); },
};
const hub = makeHub(throwingLogger);
const stderrOutput = captureStderr(() => {
hub.dispatch({ family: 'plan', subcommand: '' });
});
// There should be some warning output
assert.ok(stderrOutput.length > 0, 'a warning must be emitted to stderr when logger fails');
// It should be parseable JSON with level:warn
const parsed = JSON.parse(stderrOutput.trim().split('\n')[0]);
assert.equal(parsed.level, 'warn', 'logger failure warning must have level:warn');
assert.equal(parsed.source, 'DispatchLogger');
});
});
// ─── No logger injected — defaults to no-op ──────────────────────────────────
describe('Hub — default no-op when no logger injected', () => {
test('Hub works without a logger param (no throw)', () => {
const hub = createHub({
cjsRegistry: { plan: { '': () => ({ ok: true, data: null }) } },
manifest: { plan: [''] },
});
let result;
assert.doesNotThrow(() => {
result = hub.dispatch({ family: 'plan', subcommand: '' });
});
assert.ok(result.ok);
});
test('no stderr output for success when no logger injected', () => {
const hub = createHub({
cjsRegistry: { plan: { '': () => ({ ok: true, data: null }) } },
manifest: { plan: [''] },
});
const stderrOutput = captureStderr(() => {
hub.dispatch({ family: 'plan', subcommand: '' });
});
assert.equal(stderrOutput, '', 'no-op default must not produce any stderr');
});
});
// ─── End-to-end: createDefaultLogger with real Hub ──────────────────────────
describe('Hub + createDefaultLogger — end-to-end', () => {
let tmpDir;
let savedAudit;
let savedAuditArgs;
beforeEach(() => {
tmpDir = makeTmpDir();
savedAudit = process.env.GSD_AUDIT;
savedAuditArgs = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (savedAudit === undefined) delete process.env.GSD_AUDIT; else process.env.GSD_AUDIT = savedAudit;
if (savedAuditArgs === undefined) delete process.env.GSD_AUDIT_ARGS; else process.env.GSD_AUDIT_ARGS = savedAuditArgs;
fs.rmSync(tmpDir, { recursive: true, force: true });
});
test('silent on success with default logger', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const hub = makeHub(logger);
const stderrOutput = captureStderr(() => hub.dispatch({ family: 'plan', subcommand: '' }));
assert.equal(stderrOutput, '', 'must be silent on success');
});
test('stderr line on error with default logger', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const hub = makeHub(logger);
const stderrOutput = captureStderr(() => hub.dispatch({ family: 'discuss', subcommand: '' }));
assert.ok(stderrOutput.trim().length > 0, 'must emit to stderr on error');
const parsed = JSON.parse(stderrOutput.trim());
assert.equal(parsed.kind, 'HandlerRefusal');
});
test('audit file written when GSD_AUDIT=1', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
const hub = makeHub(logger);
hub.dispatch({ family: 'plan', subcommand: '' });
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
assert.ok(fs.existsSync(auditPath), 'audit file must exist after dispatch with GSD_AUDIT=1');
const line = fs.readFileSync(auditPath, 'utf8').trim();
const parsed = JSON.parse(line);
assert.ok(typeof parsed.traceId === 'string');
assert.equal(parsed.result.kind, 'ok');
});
});

View File

@@ -0,0 +1,339 @@
'use strict';
/**
* Tests for DispatchLogger interface + default implementation (issue #177).
*
* All tests use real fs and real stderr capture (no mocks).
* Env vars are restored in afterEach.
* Temp dirs are created under os.tmpdir() and cleaned up in afterEach.
*/
const { describe, test, beforeEach, afterEach } = require('node:test');
const assert = require('node:assert/strict');
const fs = require('fs');
const path = require('path');
const os = require('os');
const {
createDefaultLogger,
createNoOpLogger,
} = require('../../get-shit-done/bin/lib/observability/logger.cjs');
// ─── helpers ─────────────────────────────────────────────────────────────────
function makeTmpDir() {
return fs.mkdtempSync(path.join(os.tmpdir(), 'gsd-logger-test-'));
}
function captureStderr(fn) {
const chunks = [];
const originalWrite = process.stderr.write.bind(process.stderr);
process.stderr.write = (chunk, ...rest) => {
chunks.push(typeof chunk === 'string' ? chunk : chunk.toString('utf8'));
return originalWrite(chunk, ...rest);
};
try {
fn();
} finally {
process.stderr.write = originalWrite;
}
return chunks.join('');
}
function makeOkEvent(overrides = {}) {
return Object.assign({
traceId: 'test-trace-id',
parentTraceId: undefined,
command: 'plan',
result: { kind: 'ok', data: null },
timestamp: '2026-01-01T00:00:00.000Z',
}, overrides);
}
function makeErrEvent(kindPayload, overrides = {}) {
return Object.assign({
traceId: 'test-trace-id',
parentTraceId: undefined,
command: 'plan',
result: kindPayload,
timestamp: '2026-01-01T00:00:00.000Z',
}, overrides);
}
// ─── createNoOpLogger ────────────────────────────────────────────────────────
describe('createNoOpLogger', () => {
test('returns an object with onEvent', () => {
const logger = createNoOpLogger();
assert.ok(typeof logger.onEvent === 'function', 'onEvent must be a function');
});
test('onEvent does not throw on ok result', () => {
const logger = createNoOpLogger();
assert.doesNotThrow(() => logger.onEvent(makeOkEvent()));
});
test('onEvent does not throw on error result', () => {
const logger = createNoOpLogger();
assert.doesNotThrow(() =>
logger.onEvent(makeErrEvent({ kind: 'UnknownCommand', command: 'bogus' }))
);
});
test('onEvent does not write to stderr', () => {
const logger = createNoOpLogger();
const output = captureStderr(() => logger.onEvent(makeOkEvent()));
assert.equal(output, '', 'no-op logger must not write to stderr');
});
});
// ─── createDefaultLogger — silent on success ─────────────────────────────────
describe('createDefaultLogger — silent on success', () => {
let tmpDir;
let savedAudit;
let savedAuditArgs;
beforeEach(() => {
tmpDir = makeTmpDir();
savedAudit = process.env.GSD_AUDIT;
savedAuditArgs = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (savedAudit === undefined) delete process.env.GSD_AUDIT; else process.env.GSD_AUDIT = savedAudit;
if (savedAuditArgs === undefined) delete process.env.GSD_AUDIT_ARGS; else process.env.GSD_AUDIT_ARGS = savedAuditArgs;
fs.rmSync(tmpDir, { recursive: true, force: true });
});
test('no stderr output on ok result', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const stderrOutput = captureStderr(() => logger.onEvent(makeOkEvent()));
assert.equal(stderrOutput, '', 'must not write to stderr on ok result');
});
test('no audit file created on ok result (no GSD_AUDIT)', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
logger.onEvent(makeOkEvent());
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
assert.ok(!fs.existsSync(auditPath), 'audit file must not be created without GSD_AUDIT=1');
});
});
// ─── createDefaultLogger — stderr on error ──────────────────────────────────
describe('createDefaultLogger — stderr on error', () => {
let tmpDir;
let savedAudit;
let savedAuditArgs;
beforeEach(() => {
tmpDir = makeTmpDir();
savedAudit = process.env.GSD_AUDIT;
savedAuditArgs = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (savedAudit === undefined) delete process.env.GSD_AUDIT; else process.env.GSD_AUDIT = savedAudit;
if (savedAuditArgs === undefined) delete process.env.GSD_AUDIT_ARGS; else process.env.GSD_AUDIT_ARGS = savedAuditArgs;
fs.rmSync(tmpDir, { recursive: true, force: true });
});
test('emits exactly one JSON line to stderr on error', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = makeErrEvent({ kind: 'UnknownCommand', command: 'bogus' });
const stderrOutput = captureStderr(() => logger.onEvent(errEvent));
// Must be exactly one non-empty line
const lines = stderrOutput.split('\n').filter(l => l.trim().length > 0);
assert.equal(lines.length, 1, `expected 1 line, got ${lines.length}: ${stderrOutput}`);
});
test('stderr line is valid JSON', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = makeErrEvent({ kind: 'HandlerFailure', message: 'boom' });
let stderrOutput = '';
stderrOutput = captureStderr(() => logger.onEvent(errEvent));
const line = stderrOutput.trim();
let parsed;
assert.doesNotThrow(() => { parsed = JSON.parse(line); }, `stderr line must be valid JSON, got: ${line}`);
assert.ok(parsed !== null && typeof parsed === 'object');
});
test('stderr JSON contains kind field matching result kind', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = makeErrEvent({ kind: 'HandlerRefusal', reason: 'refused' });
const stderrOutput = captureStderr(() => logger.onEvent(errEvent));
const parsed = JSON.parse(stderrOutput.trim());
assert.equal(parsed.kind, 'HandlerRefusal');
});
test('stderr JSON contains traceId from the event', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = makeErrEvent({ kind: 'UnknownCommand', command: 'bogus' });
errEvent.traceId = 'specific-trace-id-123';
const stderrOutput = captureStderr(() => logger.onEvent(errEvent));
const parsed = JSON.parse(stderrOutput.trim());
assert.equal(parsed.traceId, 'specific-trace-id-123');
});
test('stderr JSON does not contain args by default (redaction)', () => {
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = makeErrEvent({ kind: 'InvalidArgs', arg: '--bad', reason: 'oops' });
errEvent.args = ['--bad', 'value'];
const stderrOutput = captureStderr(() => logger.onEvent(errEvent));
const parsed = JSON.parse(stderrOutput.trim());
assert.ok(!('args' in parsed), 'args must be redacted from stderr output by default');
});
test('stderr JSON includes args when GSD_AUDIT_ARGS=1', () => {
process.env.GSD_AUDIT_ARGS = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
const errEvent = Object.assign(
makeErrEvent({ kind: 'InvalidArgs', arg: '--bad', reason: 'oops' }),
{ args: ['--bad', 'value'] }
);
const stderrOutput = captureStderr(() => logger.onEvent(errEvent));
const parsed = JSON.parse(stderrOutput.trim());
assert.ok('args' in parsed, 'args must appear in stderr when GSD_AUDIT_ARGS=1');
assert.deepStrictEqual(parsed.args, ['--bad', 'value']);
});
test('no stderr output on ok result even when GSD_AUDIT=1', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
const stderrOutput = captureStderr(() => logger.onEvent(makeOkEvent()));
assert.equal(stderrOutput, '', 'ok result must never produce stderr output');
});
});
// ─── createDefaultLogger — audit file ───────────────────────────────────────
describe('createDefaultLogger — audit file', () => {
let tmpDir;
let savedAudit;
let savedAuditArgs;
beforeEach(() => {
tmpDir = makeTmpDir();
savedAudit = process.env.GSD_AUDIT;
savedAuditArgs = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (savedAudit === undefined) delete process.env.GSD_AUDIT; else process.env.GSD_AUDIT = savedAudit;
if (savedAuditArgs === undefined) delete process.env.GSD_AUDIT_ARGS; else process.env.GSD_AUDIT_ARGS = savedAuditArgs;
fs.rmSync(tmpDir, { recursive: true, force: true });
});
test('creates .planning/.gsd-trace.jsonl when GSD_AUDIT=1 (ok result)', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
logger.onEvent(makeOkEvent());
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
assert.ok(fs.existsSync(auditPath), 'audit file must be created when GSD_AUDIT=1');
});
test('creates .planning/ directory if absent', () => {
process.env.GSD_AUDIT = '1';
// tmpDir has no .planning/ subdirectory
assert.ok(!fs.existsSync(path.join(tmpDir, '.planning')));
const logger = createDefaultLogger({ cwd: tmpDir });
logger.onEvent(makeOkEvent());
assert.ok(fs.existsSync(path.join(tmpDir, '.planning')));
});
test('audit file contains one valid JSON line per event', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
logger.onEvent(makeOkEvent({ traceId: 'a1' }));
logger.onEvent(makeOkEvent({ traceId: 'a2' }));
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
const content = fs.readFileSync(auditPath, 'utf8');
const lines = content.split('\n').filter(l => l.trim().length > 0);
assert.equal(lines.length, 2, `expected 2 lines, got ${lines.length}`);
const parsed0 = JSON.parse(lines[0]);
const parsed1 = JSON.parse(lines[1]);
assert.equal(parsed0.traceId, 'a1');
assert.equal(parsed1.traceId, 'a2');
});
test('audit file is append-only (second run adds to existing content)', () => {
process.env.GSD_AUDIT = '1';
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
const logger1 = createDefaultLogger({ cwd: tmpDir });
logger1.onEvent(makeOkEvent({ traceId: 'first' }));
const logger2 = createDefaultLogger({ cwd: tmpDir });
logger2.onEvent(makeOkEvent({ traceId: 'second' }));
const content = fs.readFileSync(auditPath, 'utf8');
const lines = content.split('\n').filter(l => l.trim().length > 0);
assert.equal(lines.length, 2, 'both events must appear (append-only)');
assert.equal(JSON.parse(lines[0]).traceId, 'first');
assert.equal(JSON.parse(lines[1]).traceId, 'second');
});
test('audit file contains both ok and error events', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
logger.onEvent(makeOkEvent({ traceId: 'ok-event' }));
logger.onEvent(makeErrEvent({ kind: 'HandlerFailure', message: 'boom' }, { traceId: 'err-event' }));
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
const content = fs.readFileSync(auditPath, 'utf8');
const lines = content.split('\n').filter(l => l.trim().length > 0);
assert.equal(lines.length, 2);
const traceIds = lines.map(l => JSON.parse(l).traceId);
assert.ok(traceIds.includes('ok-event'), 'ok event must be in audit file');
assert.ok(traceIds.includes('err-event'), 'error event must be in audit file');
});
test('audit file does NOT contain args by default', () => {
process.env.GSD_AUDIT = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
const event = Object.assign(makeOkEvent(), { args: ['secret-arg'] });
logger.onEvent(event);
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
const content = fs.readFileSync(auditPath, 'utf8');
const parsed = JSON.parse(content.trim());
assert.ok(!('args' in parsed), 'args must be redacted from audit file by default');
});
test('audit file DOES contain args when GSD_AUDIT_ARGS=1', () => {
process.env.GSD_AUDIT = '1';
process.env.GSD_AUDIT_ARGS = '1';
const logger = createDefaultLogger({ cwd: tmpDir });
const event = Object.assign(makeOkEvent(), { args: ['visible-arg'] });
logger.onEvent(event);
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
const content = fs.readFileSync(auditPath, 'utf8');
const parsed = JSON.parse(content.trim());
assert.ok('args' in parsed, 'args must appear in audit file when GSD_AUDIT_ARGS=1');
assert.deepStrictEqual(parsed.args, ['visible-arg']);
});
test('config.audit.enabled === true triggers audit file (without GSD_AUDIT env)', () => {
// GSD_AUDIT is not set, but config says enabled
const logger = createDefaultLogger({ cwd: tmpDir, config: { audit: { enabled: true } } });
logger.onEvent(makeOkEvent({ traceId: 'config-triggered' }));
const auditPath = path.join(tmpDir, '.planning', '.gsd-trace.jsonl');
assert.ok(fs.existsSync(auditPath), 'audit file must be created when config.audit.enabled=true');
const parsed = JSON.parse(fs.readFileSync(auditPath, 'utf8').trim());
assert.equal(parsed.traceId, 'config-triggered');
});
});

View File

@@ -0,0 +1,150 @@
'use strict';
/**
* Tests for arg redaction policy (issue #177).
*
* Redaction decides whether args appear in emitted events based on
* the GSD_AUDIT_ARGS env var. Tests use real env manipulation and
* restore state in afterEach. No mocks.
*/
const { describe, test, beforeEach, afterEach } = require('node:test');
const assert = require('node:assert/strict');
const {
shouldIncludeArgs,
redactEvent,
} = require('../../get-shit-done/bin/lib/observability/redaction.cjs');
describe('shouldIncludeArgs', () => {
let originalEnv;
beforeEach(() => {
originalEnv = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (originalEnv === undefined) {
delete process.env.GSD_AUDIT_ARGS;
} else {
process.env.GSD_AUDIT_ARGS = originalEnv;
}
});
test('returns false when GSD_AUDIT_ARGS is not set', () => {
assert.strictEqual(shouldIncludeArgs(), false);
});
test('returns false when GSD_AUDIT_ARGS is empty string', () => {
process.env.GSD_AUDIT_ARGS = '';
assert.strictEqual(shouldIncludeArgs(), false);
});
test('returns false when GSD_AUDIT_ARGS is "0"', () => {
process.env.GSD_AUDIT_ARGS = '0';
assert.strictEqual(shouldIncludeArgs(), false);
});
test('returns true when GSD_AUDIT_ARGS is "1"', () => {
process.env.GSD_AUDIT_ARGS = '1';
assert.strictEqual(shouldIncludeArgs(), true);
});
test('returns false for any other non-1 value', () => {
process.env.GSD_AUDIT_ARGS = 'yes';
assert.strictEqual(shouldIncludeArgs(), false);
process.env.GSD_AUDIT_ARGS = 'true';
assert.strictEqual(shouldIncludeArgs(), false);
});
});
describe('redactEvent', () => {
let originalEnv;
beforeEach(() => {
originalEnv = process.env.GSD_AUDIT_ARGS;
delete process.env.GSD_AUDIT_ARGS;
});
afterEach(() => {
if (originalEnv === undefined) {
delete process.env.GSD_AUDIT_ARGS;
} else {
process.env.GSD_AUDIT_ARGS = originalEnv;
}
});
test('strips args from event when GSD_AUDIT_ARGS is not set', () => {
const event = Object.freeze({
traceId: 'abc',
command: 'plan',
args: ['--foo', 'bar'],
result: { kind: 'ok', data: null },
timestamp: new Date().toISOString(),
});
const redacted = redactEvent(event);
assert.ok(!('args' in redacted), 'args must be absent after redaction');
assert.equal(redacted.command, 'plan');
assert.equal(redacted.traceId, 'abc');
});
test('preserves all other fields after redaction', () => {
const event = Object.freeze({
traceId: 'xyz',
parentTraceId: undefined,
command: 'discuss',
args: ['--mode', 'fast'],
result: { kind: 'HandlerRefusal', reason: 'nope' },
timestamp: '2026-01-01T00:00:00.000Z',
});
const redacted = redactEvent(event);
assert.equal(redacted.traceId, 'xyz');
assert.equal(redacted.command, 'discuss');
assert.equal(redacted.timestamp, '2026-01-01T00:00:00.000Z');
assert.deepStrictEqual(redacted.result, { kind: 'HandlerRefusal', reason: 'nope' });
});
test('includes args when GSD_AUDIT_ARGS=1', () => {
process.env.GSD_AUDIT_ARGS = '1';
const event = Object.freeze({
traceId: 'abc',
command: 'plan',
args: ['--foo', 'bar'],
result: { kind: 'ok', data: null },
timestamp: new Date().toISOString(),
});
const redacted = redactEvent(event);
assert.ok('args' in redacted, 'args must be present when GSD_AUDIT_ARGS=1');
assert.deepStrictEqual(redacted.args, ['--foo', 'bar']);
});
test('event without args field stays without args after redaction', () => {
const event = Object.freeze({
traceId: 'abc',
command: 'plan',
result: { kind: 'ok', data: null },
timestamp: new Date().toISOString(),
});
const redacted = redactEvent(event);
assert.ok(!('args' in redacted), 'args should not appear if original event had none');
});
test('returns a new object, not a mutation of the original frozen event', () => {
const event = Object.freeze({
traceId: 'abc',
command: 'plan',
args: ['secret'],
result: { kind: 'ok', data: null },
timestamp: new Date().toISOString(),
});
const redacted = redactEvent(event);
// Original must still have args
assert.ok('args' in event);
// Redacted must not have args
assert.ok(!('args' in redacted));
// They must be different object references
assert.ok(redacted !== event);
});
});