refactor(state): centralize pipeline logging through workflow logger (#3282)
* refactor(state): centralize pipeline logging through workflow logger Route 15 raw process.stderr.write calls through the structured workflow logger (logWarning/logError). Adds "db" and "dispatch" as new LogComponent values. Enables auto-loop drain/summarize, audit-log persistence, and doctor integration for reconciliation and DB events that previously bypassed structured logging. Files changed: - workflow-logger.ts: add "db" and "dispatch" components - state.ts: 3 reconciliation calls → logWarning/logError - gsd-db.ts: 4 DB operation calls → logError - workflow-reconcile.ts: 3 event merge calls → logWarning/logError - auto-dispatch.ts: 1 reactive dispatch call → logError - auto-post-unit.ts: 3 triage/rogue calls → logWarning/logError * test(workflow-logger): add tests for db and dispatch log components Cover the new LogComponent values added in this refactor to satisfy the CI require-tests gate.
This commit is contained in:
parent
17471ea280
commit
706a2f8e9f
7 changed files with 70 additions and 27 deletions
|
|
@ -28,6 +28,7 @@ import {
|
|||
buildSliceFileName,
|
||||
} from "./paths.js";
|
||||
import { existsSync, mkdirSync, readFileSync, writeFileSync } from "node:fs";
|
||||
import { logError } from "./workflow-logger.js";
|
||||
import { join } from "node:path";
|
||||
import { hasImplementationArtifacts } from "./auto-recovery.js";
|
||||
import {
|
||||
|
|
@ -526,7 +527,7 @@ export const DISPATCH_RULES: DispatchRule[] = [
|
|||
};
|
||||
} catch (err) {
|
||||
// Non-fatal — fall through to sequential execution
|
||||
process.stderr.write(`gsd-reactive: graph derivation failed: ${(err as Error).message}\n`);
|
||||
logError("dispatch", "reactive graph derivation failed", { error: (err as Error).message });
|
||||
return null;
|
||||
}
|
||||
},
|
||||
|
|
|
|||
|
|
@ -13,6 +13,7 @@
|
|||
|
||||
import type { ExtensionContext, ExtensionAPI } from "@gsd/pi-coding-agent";
|
||||
import { deriveState } from "./state.js";
|
||||
import { logWarning, logError } from "./workflow-logger.js";
|
||||
import { loadFile, parseSummary, resolveAllOverrides } from "./files.js";
|
||||
import { loadPrompt } from "./prompt-loader.js";
|
||||
import {
|
||||
|
|
@ -412,10 +413,10 @@ export async function postUnitPreVerification(pctx: PostUnitContext, opts?: PreV
|
|||
);
|
||||
}
|
||||
for (const action of triageResult.actions) {
|
||||
process.stderr.write(`gsd-triage: ${action}\n`);
|
||||
logWarning("engine", `triage resolution: ${action}`);
|
||||
}
|
||||
} catch (err) {
|
||||
process.stderr.write(`gsd-triage: resolution execution failed: ${(err as Error).message}\n`);
|
||||
logError("engine", "triage resolution failed", { error: (err as Error).message });
|
||||
}
|
||||
}
|
||||
|
||||
|
|
@ -423,7 +424,7 @@ export async function postUnitPreVerification(pctx: PostUnitContext, opts?: PreV
|
|||
try {
|
||||
const rogueFiles = detectRogueFileWrites(s.currentUnit.type, s.currentUnit.id, s.basePath);
|
||||
for (const rogue of rogueFiles) {
|
||||
process.stderr.write(`gsd-rogue: detected rogue file write: ${rogue.path} (unit: ${rogue.unitId})\n`);
|
||||
logWarning("engine", "rogue file write detected", { path: rogue.path, unitId: rogue.unitId });
|
||||
ctx.ui.notify(`Rogue file write detected: ${rogue.path}`, "warning");
|
||||
}
|
||||
} catch (e) {
|
||||
|
|
|
|||
|
|
@ -10,6 +10,7 @@ import { existsSync, copyFileSync, mkdirSync, realpathSync } from "node:fs";
|
|||
import { dirname } from "node:path";
|
||||
import type { Decision, Requirement, GateRow, GateId, GateScope, GateStatus, GateVerdict } from "./types.js";
|
||||
import { GSDError, GSD_STALE_STATE } from "./errors.js";
|
||||
import { logError } from "./workflow-logger.js";
|
||||
|
||||
const _require = createRequire(import.meta.url);
|
||||
|
||||
|
|
@ -1773,7 +1774,7 @@ export function copyWorktreeDb(srcDbPath: string, destDbPath: string): boolean {
|
|||
copyFileSync(srcDbPath, destDbPath);
|
||||
return true;
|
||||
} catch (err) {
|
||||
process.stderr.write(`gsd-db: failed to copy DB to worktree: ${(err as Error).message}\n`);
|
||||
logError("db", "failed to copy DB to worktree", { error: (err as Error).message });
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
|
@ -1805,13 +1806,13 @@ export function reconcileWorktreeDb(
|
|||
// ATTACH DATABASE doesn't support parameterized paths in all providers,
|
||||
// so we use strict allowlist validation instead.
|
||||
if (/['";\x00]/.test(worktreeDbPath)) {
|
||||
process.stderr.write("gsd-db: worktree DB reconciliation failed: path contains unsafe characters\n");
|
||||
logError("db", "worktree DB reconciliation failed: path contains unsafe characters");
|
||||
return zero;
|
||||
}
|
||||
if (!currentDb) {
|
||||
const opened = openDatabase(mainDbPath);
|
||||
if (!opened) {
|
||||
process.stderr.write("gsd-db: worktree DB reconciliation failed: cannot open main DB\n");
|
||||
logError("db", "worktree DB reconciliation failed: cannot open main DB");
|
||||
return zero;
|
||||
}
|
||||
}
|
||||
|
|
@ -1945,7 +1946,7 @@ export function reconcileWorktreeDb(
|
|||
try { adapter.exec("DETACH DATABASE wt"); } catch { /* best effort */ }
|
||||
}
|
||||
} catch (err) {
|
||||
process.stderr.write(`gsd-db: worktree DB reconciliation failed: ${(err as Error).message}\n`);
|
||||
logError("db", "worktree DB reconciliation failed", { error: (err as Error).message });
|
||||
return { ...zero, conflicts };
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -42,6 +42,7 @@ import { join, resolve } from 'path';
|
|||
import { existsSync, readdirSync, readFileSync } from 'node:fs';
|
||||
import { debugCount, debugTime } from './debug-logger.js';
|
||||
import { extractVerdict } from './verdict-parser.js';
|
||||
import { logWarning, logError } from './workflow-logger.js';
|
||||
|
||||
import {
|
||||
isDbAvailable,
|
||||
|
|
@ -704,15 +705,11 @@ export async function deriveStateFromDb(basePath: string): Promise<GSDState> {
|
|||
if (summaryPath && existsSync(summaryPath)) {
|
||||
try {
|
||||
updateTaskStatus(activeMilestone.id, activeSlice.id, t.id, "complete");
|
||||
process.stderr.write(
|
||||
`gsd-reconcile: task ${activeMilestone.id}/${activeSlice.id}/${t.id} had SUMMARY on disk but DB status was "${t.status}" — updated to "complete" (#2514)\n`,
|
||||
);
|
||||
logWarning("reconcile", `task ${activeMilestone.id}/${activeSlice.id}/${t.id} status reconciled from "${t.status}" to "complete" (#2514)`, { mid: activeMilestone.id, sid: activeSlice.id, tid: t.id });
|
||||
reconciled = true;
|
||||
} catch (e) {
|
||||
// DB write failed — continue with stale status rather than crash
|
||||
process.stderr.write(
|
||||
`gsd-reconcile: failed to update task ${t.id}: ${(e as Error).message}\n`,
|
||||
);
|
||||
logError("reconcile", `failed to update task ${t.id}`, { tid: t.id, error: (e as Error).message });
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -1367,9 +1364,7 @@ export async function _deriveStateImpl(basePath: string): Promise<GSDState> {
|
|||
const summaryPath = resolveTaskFile(basePath, activeMilestone.id, activeSlice.id, t.id, "SUMMARY");
|
||||
if (summaryPath && existsSync(summaryPath)) {
|
||||
t.done = true;
|
||||
process.stderr.write(
|
||||
`gsd-reconcile: task ${activeMilestone.id}/${activeSlice.id}/${t.id} has SUMMARY on disk but plan shows incomplete — marking done (#2514)\n`,
|
||||
);
|
||||
logWarning("reconcile", `task ${activeMilestone.id}/${activeSlice.id}/${t.id} reconciled via SUMMARY on disk (#2514)`, { mid: activeMilestone.id, sid: activeSlice.id, tid: t.id });
|
||||
}
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -317,6 +317,54 @@ describe("workflow-logger", () => {
|
|||
});
|
||||
});
|
||||
|
||||
describe("new log components (db, dispatch)", () => {
|
||||
test("logError with 'db' component stores correct component", () => {
|
||||
logError("db", "failed to copy DB to worktree", { error: "ENOENT" });
|
||||
const entries = peekLogs();
|
||||
assert.equal(entries.length, 1);
|
||||
assert.equal(entries[0].severity, "error");
|
||||
assert.equal(entries[0].component, "db");
|
||||
assert.equal(entries[0].message, "failed to copy DB to worktree");
|
||||
assert.deepEqual(entries[0].context, { error: "ENOENT" });
|
||||
});
|
||||
|
||||
test("logError with 'dispatch' component stores correct component", () => {
|
||||
logError("dispatch", "reactive graph derivation failed", { error: "timeout" });
|
||||
const entries = peekLogs();
|
||||
assert.equal(entries.length, 1);
|
||||
assert.equal(entries[0].severity, "error");
|
||||
assert.equal(entries[0].component, "dispatch");
|
||||
assert.deepEqual(entries[0].context, { error: "timeout" });
|
||||
});
|
||||
|
||||
test("logWarning with 'reconcile' component for centralized logging path", () => {
|
||||
logWarning("reconcile", "could not acquire sync lock — another reconciliation may be in progress");
|
||||
const entries = peekLogs();
|
||||
assert.equal(entries.length, 1);
|
||||
assert.equal(entries[0].severity, "warn");
|
||||
assert.equal(entries[0].component, "reconcile");
|
||||
});
|
||||
|
||||
test("summarizeLogs includes db and dispatch entries", () => {
|
||||
logError("db", "worktree DB reconciliation failed: path contains unsafe characters");
|
||||
logWarning("dispatch", "graph derivation timeout");
|
||||
const summary = summarizeLogs()!;
|
||||
assert.ok(summary.includes("1 error(s)"));
|
||||
assert.ok(summary.includes("1 warning(s)"));
|
||||
assert.ok(summary.includes("unsafe characters"));
|
||||
assert.ok(summary.includes("graph derivation timeout"));
|
||||
});
|
||||
|
||||
test("formatForNotification renders db and dispatch components", () => {
|
||||
logError("db", "copy failed");
|
||||
logWarning("dispatch", "slow derivation");
|
||||
const entries = drainLogs();
|
||||
const formatted = formatForNotification(entries);
|
||||
assert.ok(formatted.includes("[db] copy failed"));
|
||||
assert.ok(formatted.includes("[dispatch] slow derivation"));
|
||||
});
|
||||
});
|
||||
|
||||
describe("stderr output", () => {
|
||||
test("writes WARN prefix to stderr for warnings", (t) => {
|
||||
const written: string[] = [];
|
||||
|
|
|
|||
|
|
@ -31,7 +31,9 @@ export type LogComponent =
|
|||
| "state" // deriveState fallback/degradation
|
||||
| "tool" // Tool handler errors
|
||||
| "compaction" // Event compaction
|
||||
| "reconcile"; // Worktree reconciliation
|
||||
| "reconcile" // Worktree reconciliation
|
||||
| "db" // Database operations (gsd-db)
|
||||
| "dispatch"; // Auto-dispatch rule evaluation
|
||||
|
||||
export interface LogEntry {
|
||||
ts: string;
|
||||
|
|
|
|||
|
|
@ -1,5 +1,6 @@
|
|||
import { join } from "node:path";
|
||||
import { mkdirSync, existsSync, readFileSync, unlinkSync } from "node:fs";
|
||||
import { logWarning, logError } from "./workflow-logger.js";
|
||||
import { readEvents, findForkPoint, appendEvent, getSessionId } from "./workflow-events.js";
|
||||
import type { WorkflowEvent } from "./workflow-events.js";
|
||||
import {
|
||||
|
|
@ -308,9 +309,7 @@ export function reconcileWorktreeLogs(
|
|||
// Acquire advisory lock to prevent concurrent reconcile + append races
|
||||
const lock = acquireSyncLock(mainBasePath);
|
||||
if (!lock.acquired) {
|
||||
process.stderr.write(
|
||||
`[gsd] reconcile: could not acquire sync lock — another reconciliation may be in progress\n`,
|
||||
);
|
||||
logWarning("reconcile", "could not acquire sync lock — another reconciliation may be in progress");
|
||||
return { autoMerged: 0, conflicts: [] };
|
||||
}
|
||||
|
||||
|
|
@ -349,9 +348,7 @@ function _reconcileWorktreeLogsInner(
|
|||
if (conflicts.length > 0) {
|
||||
// D-04: atomic all-or-nothing — block entire merge
|
||||
writeConflictsFile(mainBasePath, conflicts, worktreeBasePath);
|
||||
process.stderr.write(
|
||||
`[gsd] reconcile: ${conflicts.length} conflict(s) detected — see ${join(mainBasePath, ".gsd", "CONFLICTS.md")}\n`,
|
||||
);
|
||||
logError("reconcile", `${conflicts.length} conflict(s) detected`, { count: String(conflicts.length), path: join(mainBasePath, ".gsd", "CONFLICTS.md") });
|
||||
return { autoMerged: 0, conflicts };
|
||||
}
|
||||
|
||||
|
|
@ -375,9 +372,7 @@ function _reconcileWorktreeLogsInner(
|
|||
try {
|
||||
writeManifest(mainBasePath);
|
||||
} catch (err) {
|
||||
process.stderr.write(
|
||||
`[gsd] reconcile: manifest write failed (non-fatal): ${(err as Error).message}\n`,
|
||||
);
|
||||
logWarning("reconcile", "manifest write failed (non-fatal)", { error: (err as Error).message });
|
||||
}
|
||||
|
||||
return { autoMerged: merged.length, conflicts: [] };
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue