fix(FN-2124): harden swallowed project-engine error paths
- Replace previously silent catch blocks in auto-merge and settings-listener flows with runtimeLog.warn messages - Add warning logs for startup and periodic auto-merge sweeps plus poll interval fallback when settings reads fail - Add regression tests that force each swallowed-error path and assert structured warnings are emitted - Cover global/engine unpause resumeOrphaned failures and stuck-detector checkNow failures in project-engine tests
This commit is contained in:
@@ -1,5 +1,6 @@
|
||||
import { beforeEach, describe, expect, it, vi } from "vitest";
|
||||
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
|
||||
import { ProjectEngine } from "./project-engine.js";
|
||||
import { runtimeLog } from "./logger.js";
|
||||
|
||||
const mocks = vi.hoisted(() => ({
|
||||
syncInsightExtractionAutomation: vi.fn(),
|
||||
@@ -195,3 +196,224 @@ describe("ProjectEngine auto-summarize wiring", () => {
|
||||
await engine.stop();
|
||||
});
|
||||
});
|
||||
|
||||
describe("ProjectEngine swallowed error hardening", () => {
|
||||
let warnSpy: ReturnType<typeof vi.spyOn>;
|
||||
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks();
|
||||
const mockStore = createMockStore(baseSettings);
|
||||
mocks.currentStore = mockStore.store;
|
||||
warnSpy = vi.spyOn(runtimeLog, "warn").mockImplementation(() => {});
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
warnSpy.mockRestore();
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("warns when settings read fails during task:moved auto-merge check", async () => {
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
|
||||
mockStore.store.getSettings.mockRejectedValueOnce(new Error("db locked"));
|
||||
|
||||
const handler = mockStore.store.on.mock.calls.find((c: unknown[]) => c[0] === "task:moved")?.[1] as
|
||||
| ((payload: { task: { id: string; column: string }; to: string }) => Promise<void>)
|
||||
| undefined;
|
||||
expect(handler).toBeTypeOf("function");
|
||||
if (!handler) throw new Error("task:moved handler was not registered");
|
||||
|
||||
await handler({
|
||||
task: { id: "FN-001", column: "in-review" },
|
||||
to: "in-review",
|
||||
});
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Auto-merge: failed to read settings for task:moved on FN-001"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when startup merge sweep fails", async () => {
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
mockStore.store.listTasks.mockRejectedValueOnce(new Error("connection lost"));
|
||||
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(expect.stringContaining("Auto-merge startup sweep failed"));
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when periodic merge sweep fails", async () => {
|
||||
vi.useFakeTimers();
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
mockStore.store.listTasks.mockRejectedValueOnce(new Error("sweep db error"));
|
||||
|
||||
await vi.advanceTimersByTimeAsync(15_000);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(expect.stringContaining("Auto-merge periodic sweep failed"));
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns and uses 15s fallback when pollIntervalMs read fails during retry scheduling", async () => {
|
||||
vi.useFakeTimers();
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
mockStore.store.getSettings
|
||||
.mockResolvedValueOnce({ ...baseSettings, autoMerge: true })
|
||||
.mockRejectedValueOnce(new Error("settings read failed"));
|
||||
|
||||
await vi.advanceTimersByTimeAsync(15_000);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Auto-merge retry: failed to read pollIntervalMs"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when resumeOrphaned dispatch fails during global unpause", async () => {
|
||||
const mockStore = createMockStore(baseSettings);
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
const runtime = engine.getRuntime() as unknown as object;
|
||||
Object.defineProperty(runtime, "executor", {
|
||||
get() {
|
||||
throw new Error("executor broken");
|
||||
},
|
||||
configurable: true,
|
||||
});
|
||||
|
||||
await mockStore.emitSettingsUpdated(
|
||||
{ ...baseSettings, globalPause: false },
|
||||
{ ...baseSettings, globalPause: true },
|
||||
);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Global unpause: failed to dispatch resumeOrphaned"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when in-review task listing fails during global unpause", async () => {
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
mockStore.store.listTasks.mockRejectedValueOnce(new Error("list failed"));
|
||||
|
||||
await mockStore.emitSettingsUpdated(
|
||||
{ ...baseSettings, autoMerge: true, globalPause: false },
|
||||
{ ...baseSettings, autoMerge: true, globalPause: true },
|
||||
);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Global unpause: failed to scan in-review tasks"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when resumeOrphaned dispatch fails during engine unpause", async () => {
|
||||
const mockStore = createMockStore(baseSettings);
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
const runtime = engine.getRuntime() as unknown as object;
|
||||
Object.defineProperty(runtime, "executor", {
|
||||
get() {
|
||||
throw new Error("executor broken");
|
||||
},
|
||||
configurable: true,
|
||||
});
|
||||
|
||||
await mockStore.emitSettingsUpdated(
|
||||
{ ...baseSettings, enginePaused: false },
|
||||
{ ...baseSettings, enginePaused: true },
|
||||
);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Engine unpause: failed to dispatch resumeOrphaned"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when in-review task listing fails during engine unpause", async () => {
|
||||
const mockStore = createMockStore({ ...baseSettings, autoMerge: true });
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
mockStore.store.listTasks.mockRejectedValueOnce(new Error("list failed"));
|
||||
|
||||
await mockStore.emitSettingsUpdated(
|
||||
{ ...baseSettings, autoMerge: true, enginePaused: false },
|
||||
{ ...baseSettings, autoMerge: true, enginePaused: true },
|
||||
);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Engine unpause: failed to scan in-review tasks"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
|
||||
it("warns when stuck-detector checkNow fails on timeout change", async () => {
|
||||
const mockStore = createMockStore(baseSettings);
|
||||
mocks.currentStore = mockStore.store;
|
||||
const engine = createEngine();
|
||||
await engine.start();
|
||||
warnSpy.mockClear();
|
||||
|
||||
const runtime = engine.getRuntime() as unknown as object;
|
||||
Object.defineProperty(runtime, "stuckTaskDetector", {
|
||||
get() {
|
||||
return {
|
||||
checkNow: async () => {
|
||||
throw new Error("detector stuck");
|
||||
},
|
||||
};
|
||||
},
|
||||
configurable: true,
|
||||
});
|
||||
|
||||
await mockStore.emitSettingsUpdated(
|
||||
{ ...baseSettings, taskStuckTimeoutMs: 600_000 },
|
||||
{ ...baseSettings, taskStuckTimeoutMs: 300_000 },
|
||||
);
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Stuck-timeout change: detector.checkNow() failed"),
|
||||
);
|
||||
|
||||
await engine.stop();
|
||||
});
|
||||
});
|
||||
|
||||
@@ -748,8 +748,10 @@ export class ProjectEngine {
|
||||
if (settings.globalPause || settings.enginePaused) return;
|
||||
if (!settings.autoMerge) return;
|
||||
this.internalEnqueueMerge(task.id);
|
||||
} catch {
|
||||
// ignore settings read errors
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Auto-merge: failed to read settings for task:moved on ${task.id}: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
};
|
||||
store.on("task:moved", this.taskMovedHandler);
|
||||
@@ -786,8 +788,10 @@ export class ProjectEngine {
|
||||
this.internalEnqueueMerge(t.id);
|
||||
}
|
||||
}
|
||||
} catch {
|
||||
// ignore startup sweep errors
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Auto-merge startup sweep failed: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -808,15 +812,22 @@ export class ProjectEngine {
|
||||
}
|
||||
}
|
||||
}
|
||||
} catch {
|
||||
// ignore sweep errors
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Auto-merge periodic sweep failed: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
|
||||
if (!this.shuttingDown) {
|
||||
const interval = await store
|
||||
.getSettings()
|
||||
.then((s) => s.pollIntervalMs ?? 15_000)
|
||||
.catch(() => 15_000);
|
||||
.catch((err: unknown) => {
|
||||
runtimeLog.warn(
|
||||
`Auto-merge retry: failed to read pollIntervalMs, using default 15s: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
return 15_000;
|
||||
});
|
||||
this.mergeRetryTimer = setTimeout(() => void schedule(), interval);
|
||||
}
|
||||
};
|
||||
@@ -858,8 +869,10 @@ export class ProjectEngine {
|
||||
executor?.resumeOrphaned?.().catch((err: Error) =>
|
||||
runtimeLog.error("Failed to resume orphaned tasks on unpause:", err),
|
||||
);
|
||||
} catch {
|
||||
/* ignore */
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Global unpause: failed to dispatch resumeOrphaned: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
|
||||
if (s.autoMerge) {
|
||||
@@ -871,8 +884,10 @@ export class ProjectEngine {
|
||||
this.internalEnqueueMerge(t.id);
|
||||
}
|
||||
}
|
||||
} catch {
|
||||
/* ignore */
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Global unpause: failed to scan in-review tasks for auto-merge: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -897,8 +912,10 @@ export class ProjectEngine {
|
||||
executor?.resumeOrphaned?.().catch((err: Error) =>
|
||||
runtimeLog.error("Failed to resume orphaned tasks on engine unpause:", err),
|
||||
);
|
||||
} catch {
|
||||
/* ignore */
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Engine unpause: failed to dispatch resumeOrphaned: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
|
||||
if (s.autoMerge) {
|
||||
@@ -910,8 +927,10 @@ export class ProjectEngine {
|
||||
this.internalEnqueueMerge(t.id);
|
||||
}
|
||||
}
|
||||
} catch {
|
||||
/* ignore */
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Engine unpause: failed to scan in-review tasks for auto-merge: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -935,8 +954,10 @@ export class ProjectEngine {
|
||||
// eslint-disable-next-line @typescript-eslint/no-explicit-any
|
||||
const detector = (this.runtime as any).stuckTaskDetector;
|
||||
await detector?.checkNow?.();
|
||||
} catch {
|
||||
/* ignore */
|
||||
} catch (err: unknown) {
|
||||
runtimeLog.warn(
|
||||
`Stuck-timeout change: detector.checkNow() failed: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
}
|
||||
}
|
||||
};
|
||||
|
||||
Reference in New Issue
Block a user