Merge pull request #3508 from jeremymcs/fix/audit-log-hardening
fix(gsd): harden audit log persistence and demote probe warnings
This commit is contained in:
commit
2acf5292d0
6 changed files with 179 additions and 29 deletions
|
|
@ -112,9 +112,9 @@ function detectMainBranch(basePath: string): string {
|
|||
encoding: "utf-8",
|
||||
});
|
||||
if (result.trim()) return "main";
|
||||
} catch (err) {
|
||||
// main doesn't exist
|
||||
logWarning("recovery", `main branch not found: ${err instanceof Error ? err.message : String(err)}`);
|
||||
} catch (_) {
|
||||
// Expected — main doesn't exist, try master next
|
||||
void _;
|
||||
}
|
||||
try {
|
||||
const result = execFileSync("git", ["rev-parse", "--verify", "master"], {
|
||||
|
|
@ -123,11 +123,13 @@ function detectMainBranch(basePath: string): string {
|
|||
encoding: "utf-8",
|
||||
});
|
||||
if (result.trim()) return "master";
|
||||
} catch (err) {
|
||||
// master doesn't exist either
|
||||
logWarning("recovery", `master branch not found: ${err instanceof Error ? err.message : String(err)}`);
|
||||
} catch (_) {
|
||||
// Expected — master doesn't exist either
|
||||
void _;
|
||||
}
|
||||
return "main"; // default fallback
|
||||
// Neither main nor master found — warn and fall back
|
||||
logWarning("recovery", "neither main nor master branch found, defaulting to main");
|
||||
return "main";
|
||||
}
|
||||
|
||||
/**
|
||||
|
|
|
|||
|
|
@ -104,16 +104,10 @@ export async function ensureDbOpen(): Promise<boolean> {
|
|||
return opened;
|
||||
}
|
||||
|
||||
logWarning("bootstrap", `ensureDbOpen failed — no .gsd directory found (resolvedPath=${resolveProjectRootDbPath(basePath)}, cwd=${basePath})`);
|
||||
logWarning("bootstrap", "ensureDbOpen failed — no .gsd directory found");
|
||||
return false;
|
||||
} catch (err) {
|
||||
const basePath = process.cwd();
|
||||
const diagnostic = {
|
||||
resolvedPath: resolveProjectRootDbPath(basePath),
|
||||
cwd: basePath,
|
||||
error: (err as Error).message ?? String(err),
|
||||
};
|
||||
logWarning("bootstrap", `ensureDbOpen failed — ${JSON.stringify(diagnostic)}`);
|
||||
logWarning("bootstrap", `ensureDbOpen failed: ${(err as Error).message ?? String(err)}`);
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -94,11 +94,11 @@ const dynamicToolsSrc = readFileSync(
|
|||
"utf-8",
|
||||
);
|
||||
|
||||
// ensureDbOpen should return a structured result, not just boolean false
|
||||
// Check that the catch block provides diagnostic information
|
||||
// ensureDbOpen should surface diagnostic context, not just boolean false
|
||||
// Check that the catch block logs error details via workflow-logger
|
||||
assertTrue(
|
||||
dynamicToolsSrc.includes("resolvedPath") || dynamicToolsSrc.includes("diagnostic"),
|
||||
"ensureDbOpen catch block surfaces diagnostic information (resolvedPath or diagnostic) instead of bare false (#2517)",
|
||||
dynamicToolsSrc.includes("ensureDbOpen failed") && dynamicToolsSrc.includes("logWarning"),
|
||||
"ensureDbOpen catch block surfaces diagnostic information via logWarning instead of bare false (#2517)",
|
||||
);
|
||||
|
||||
// ── Part 3: post-unit does NOT artifact-retry on db_unavailable ──────────
|
||||
|
|
|
|||
120
src/resources/extensions/gsd/tests/workflow-logger-audit.test.ts
Normal file
120
src/resources/extensions/gsd/tests/workflow-logger-audit.test.ts
Normal file
|
|
@ -0,0 +1,120 @@
|
|||
// GSD Extension — Workflow Logger Audit Persistence Tests
|
||||
// Validates error-only persistence, sanitization, and warning ephemeral behavior.
|
||||
|
||||
import { describe, test, beforeEach, afterEach } from "node:test";
|
||||
import assert from "node:assert/strict";
|
||||
import { mkdtempSync, mkdirSync, readFileSync, existsSync, rmSync } from "node:fs";
|
||||
import { join } from "node:path";
|
||||
import { tmpdir } from "node:os";
|
||||
|
||||
import {
|
||||
logWarning,
|
||||
logError,
|
||||
setLogBasePath,
|
||||
_resetLogs,
|
||||
peekLogs,
|
||||
drainLogs,
|
||||
} from "../workflow-logger.ts";
|
||||
|
||||
function createTempProject(): string {
|
||||
const tmp = mkdtempSync(join(tmpdir(), "gsd-wflog-test-"));
|
||||
mkdirSync(join(tmp, ".gsd"), { recursive: true });
|
||||
return tmp;
|
||||
}
|
||||
|
||||
function readAuditLines(basePath: string): Record<string, unknown>[] {
|
||||
const auditPath = join(basePath, ".gsd", "audit-log.jsonl");
|
||||
if (!existsSync(auditPath)) return [];
|
||||
const content = readFileSync(auditPath, "utf-8").trim();
|
||||
if (!content) return [];
|
||||
return content.split("\n").map((line) => JSON.parse(line));
|
||||
}
|
||||
|
||||
describe("workflow-logger audit persistence", () => {
|
||||
let tmp: string;
|
||||
|
||||
beforeEach(() => {
|
||||
tmp = createTempProject();
|
||||
_resetLogs();
|
||||
setLogBasePath(tmp);
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
_resetLogs();
|
||||
setLogBasePath(null as unknown as string);
|
||||
rmSync(tmp, { recursive: true, force: true });
|
||||
});
|
||||
|
||||
test("logError persists to audit-log.jsonl", () => {
|
||||
logError("engine", "something broke");
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 1);
|
||||
assert.equal(lines[0].severity, "error");
|
||||
assert.equal(lines[0].component, "engine");
|
||||
});
|
||||
|
||||
test("logWarning does NOT persist to audit-log.jsonl", () => {
|
||||
logWarning("engine", "something fishy");
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 0, "warnings must not be persisted to audit log");
|
||||
});
|
||||
|
||||
test("logWarning still appears in in-memory buffer", () => {
|
||||
logWarning("recovery", "probe miss");
|
||||
const entries = peekLogs();
|
||||
assert.equal(entries.length, 1);
|
||||
assert.equal(entries[0].severity, "warn");
|
||||
assert.equal(entries[0].component, "recovery");
|
||||
});
|
||||
|
||||
test("persisted error messages are truncated at 200 chars", () => {
|
||||
const longMessage = "x".repeat(300);
|
||||
logError("engine", longMessage);
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 1);
|
||||
const msg = lines[0].message as string;
|
||||
assert.ok(msg.length <= 215, `message should be truncated, got ${msg.length} chars`);
|
||||
assert.ok(msg.endsWith("…[truncated]"));
|
||||
});
|
||||
|
||||
test("persisted errors have context filtered to safe allowlist", () => {
|
||||
logError("tool", "tool failed", {
|
||||
fn: "saveDecisionToDb",
|
||||
tool: "gsd_decision_save",
|
||||
error: "SQLITE_BUSY: database is locked",
|
||||
file: "/home/user/project/gsd.db",
|
||||
});
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 1);
|
||||
const ctx = lines[0].context as Record<string, string>;
|
||||
assert.ok(ctx, "context should exist");
|
||||
assert.equal(ctx.fn, "saveDecisionToDb");
|
||||
assert.equal(ctx.tool, "gsd_decision_save");
|
||||
assert.equal(ctx.error, undefined, "error key must be stripped from persisted context");
|
||||
assert.equal(ctx.file, undefined, "file key must be stripped from persisted context");
|
||||
});
|
||||
|
||||
test("persisted errors omit context when no safe keys present", () => {
|
||||
logError("bootstrap", "ensureDbOpen failed", {
|
||||
error: "ENOENT",
|
||||
cwd: "/home/user/project",
|
||||
});
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 1);
|
||||
assert.equal(lines[0].context, undefined, "context should be omitted when no safe keys match");
|
||||
});
|
||||
|
||||
test("mixed warnings and errors only persist errors", () => {
|
||||
logWarning("recovery", "main not found");
|
||||
logWarning("recovery", "master not found");
|
||||
logError("engine", "fatal failure");
|
||||
logWarning("prompt", "cache miss");
|
||||
|
||||
const lines = readAuditLines(tmp);
|
||||
assert.equal(lines.length, 1, "only the error should be persisted");
|
||||
assert.equal(lines[0].severity, "error");
|
||||
|
||||
const buffered = drainLogs();
|
||||
assert.equal(buffered.length, 4, "all entries should be in the in-memory buffer");
|
||||
});
|
||||
});
|
||||
|
|
@ -240,13 +240,13 @@ describe("workflow-logger", () => {
|
|||
|
||||
test("writes entry to .gsd/audit-log.jsonl after setLogBasePath", () => {
|
||||
setLogBasePath(dir);
|
||||
logWarning("engine", "audit test entry");
|
||||
logError("engine", "audit test entry");
|
||||
|
||||
const auditPath = join(dir, ".gsd", "audit-log.jsonl");
|
||||
assert.ok(existsSync(auditPath), "audit-log.jsonl should exist");
|
||||
const content = readFileSync(auditPath, "utf-8");
|
||||
const entry = JSON.parse(content.trim());
|
||||
assert.equal(entry.severity, "warn");
|
||||
assert.equal(entry.severity, "error");
|
||||
assert.equal(entry.component, "engine");
|
||||
assert.equal(entry.message, "audit test entry");
|
||||
});
|
||||
|
|
@ -254,7 +254,7 @@ describe("workflow-logger", () => {
|
|||
test("_resetLogs does not clear the audit base path", () => {
|
||||
setLogBasePath(dir);
|
||||
_resetLogs();
|
||||
logWarning("engine", "post-reset entry");
|
||||
logError("engine", "post-reset entry");
|
||||
|
||||
const auditPath = join(dir, ".gsd", "audit-log.jsonl");
|
||||
assert.ok(existsSync(auditPath), "audit-log.jsonl should exist after _resetLogs");
|
||||
|
|
@ -293,13 +293,13 @@ describe("workflow-logger", () => {
|
|||
|
||||
test("writes entry to .gsd/audit-log.jsonl after setLogBasePath", () => {
|
||||
setLogBasePath(dir);
|
||||
logWarning("engine", "audit test entry");
|
||||
logError("engine", "audit test entry");
|
||||
|
||||
const auditPath = join(dir, ".gsd", "audit-log.jsonl");
|
||||
assert.ok(existsSync(auditPath), "audit-log.jsonl should exist");
|
||||
const content = readFileSync(auditPath, "utf-8");
|
||||
const entry = JSON.parse(content.trim());
|
||||
assert.equal(entry.severity, "warn");
|
||||
assert.equal(entry.severity, "error");
|
||||
assert.equal(entry.component, "engine");
|
||||
assert.equal(entry.message, "audit test entry");
|
||||
});
|
||||
|
|
@ -307,7 +307,7 @@ describe("workflow-logger", () => {
|
|||
test("_resetLogs does not clear the audit base path", () => {
|
||||
setLogBasePath(dir);
|
||||
_resetLogs();
|
||||
logWarning("engine", "post-reset entry");
|
||||
logError("engine", "post-reset entry");
|
||||
|
||||
const auditPath = join(dir, ".gsd", "audit-log.jsonl");
|
||||
assert.ok(existsSync(auditPath), "audit-log.jsonl should exist after _resetLogs");
|
||||
|
|
|
|||
|
|
@ -2,7 +2,9 @@
|
|||
// Centralized warning/error accumulator for the workflow engine pipeline.
|
||||
// Captures structured entries that the auto-loop can drain after each unit
|
||||
// to surface root causes for stuck loops, silent degradation, and blocked writes.
|
||||
// All entries are also persisted to .gsd/audit-log.jsonl for post-mortem analysis.
|
||||
// Error-severity entries are persisted to .gsd/audit-log.jsonl (sanitized) for
|
||||
// post-mortem analysis. Warnings are ephemeral (stderr + buffer only) to avoid
|
||||
// log amplification from expected-control-flow catch paths.
|
||||
//
|
||||
// Stderr policy: every logWarning/logError call writes immediately to stderr
|
||||
// for terminal visibility. This is intentional — unlike debug-logger (which is
|
||||
|
|
@ -243,15 +245,47 @@ function _push(
|
|||
_buffer.shift();
|
||||
}
|
||||
|
||||
// Persist to .gsd/audit-log.jsonl so entries survive context resets
|
||||
if (_auditBasePath) {
|
||||
// Persist errors to .gsd/audit-log.jsonl so they survive context resets.
|
||||
// Only error-severity entries are persisted — warnings are ephemeral (stderr + buffer)
|
||||
// to avoid log amplification from expected-control-flow catch paths.
|
||||
if (_auditBasePath && severity === "error") {
|
||||
try {
|
||||
const auditDir = join(_auditBasePath, ".gsd");
|
||||
mkdirSync(auditDir, { recursive: true });
|
||||
appendFileSync(join(auditDir, "audit-log.jsonl"), JSON.stringify(entry) + "\n", "utf-8");
|
||||
const sanitized = _sanitizeForAudit(entry);
|
||||
appendFileSync(join(auditDir, "audit-log.jsonl"), JSON.stringify(sanitized) + "\n", "utf-8");
|
||||
} catch (auditErr) {
|
||||
// Best-effort — never let audit write failures bubble up
|
||||
process.stderr.write(`[gsd:audit] failed to persist log entry: ${(auditErr as Error).message}\n`);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Sanitize a log entry before persisting to the audit JSONL file.
|
||||
* Strips potentially sensitive context (raw paths, cwd, full error text)
|
||||
* to avoid leaking local environment details into durable telemetry.
|
||||
*/
|
||||
function _sanitizeForAudit(entry: LogEntry): LogEntry {
|
||||
const sanitized: LogEntry = {
|
||||
ts: entry.ts,
|
||||
severity: entry.severity,
|
||||
component: entry.component,
|
||||
// Truncate message to avoid persisting oversized raw error dumps
|
||||
message: entry.message.length > 200 ? entry.message.slice(0, 200) + "…[truncated]" : entry.message,
|
||||
};
|
||||
if (entry.context) {
|
||||
// Allowlist: only persist known-safe structured keys
|
||||
const SAFE_KEYS = new Set(["fn", "tool", "mid", "sid", "tid", "worktree"]);
|
||||
const filtered: Record<string, string> = {};
|
||||
for (const [k, v] of Object.entries(entry.context)) {
|
||||
if (SAFE_KEYS.has(k)) {
|
||||
filtered[k] = v;
|
||||
}
|
||||
}
|
||||
if (Object.keys(filtered).length > 0) {
|
||||
sanitized.context = filtered;
|
||||
}
|
||||
}
|
||||
return sanitized;
|
||||
}
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue