fix(FN-2090): log and cover engine warning fallbacks
- Add structured warning logs for plugin-runner fallback paths instead of silent catches - Add warning telemetry in agent-tools for agent-memory directory, QMD search, and index refresh failures - Log cron-runner session disposal failures and update agent-logger persistence warnings to use logger output - Expand engine tests to cover warning behavior across plugin-runner, agent-tools, cron-runner, and agent-logger
This commit is contained in:
@@ -7,17 +7,26 @@ import { PluginRunner, type PluginRunnerOptions } from "../plugin-runner.js";
|
||||
import type { PluginLoader, PluginStore } from "@fusion/core";
|
||||
import type { FusionPlugin, PluginToolDefinition, PluginRouteDefinition } from "@fusion/core";
|
||||
|
||||
const loggerSpies = vi.hoisted(() => ({
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
executorLog: vi.fn(),
|
||||
executorWarn: vi.fn(),
|
||||
executorError: vi.fn(),
|
||||
}));
|
||||
|
||||
// Mock the logger to suppress output during tests
|
||||
vi.mock("../logger.js", () => ({
|
||||
createLogger: () => ({
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
log: loggerSpies.log,
|
||||
warn: loggerSpies.warn,
|
||||
error: loggerSpies.error,
|
||||
}),
|
||||
executorLog: {
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
log: loggerSpies.executorLog,
|
||||
warn: loggerSpies.executorWarn,
|
||||
error: loggerSpies.executorError,
|
||||
},
|
||||
}));
|
||||
|
||||
@@ -253,6 +262,52 @@ describe("PluginRunner", () => {
|
||||
});
|
||||
});
|
||||
|
||||
it("should fall back to empty settings when plugin store lookup fails", async () => {
|
||||
const executeFn = vi.fn().mockResolvedValue({
|
||||
content: [{ type: "text", text: "ok" }],
|
||||
isError: false,
|
||||
});
|
||||
|
||||
const pluginTool: PluginToolDefinition = {
|
||||
name: "testTool",
|
||||
description: "A test tool",
|
||||
parameters: { type: "object", properties: {} },
|
||||
execute: executeFn,
|
||||
};
|
||||
|
||||
const plugin = createMockPlugin({
|
||||
manifest: { id: "test-plugin", name: "Test Plugin", version: "1.0.0" },
|
||||
tools: [pluginTool],
|
||||
});
|
||||
|
||||
mockPluginStore.getPlugin.mockRejectedValue(new Error("Plugin lookup failed"));
|
||||
mockPluginLoader.getLoadedPlugins.mockReturnValue([plugin]);
|
||||
mockPluginLoader.getPluginTools.mockReturnValue([pluginTool]);
|
||||
mockPluginLoader.getPlugin.mockReturnValue(plugin);
|
||||
|
||||
await pluginRunner.init();
|
||||
const tools = pluginRunner.getPluginTools();
|
||||
|
||||
await expect(
|
||||
tools[0].execute("tool-call-1", { input: "test" }, undefined, undefined, {} as any),
|
||||
).resolves.toEqual({
|
||||
content: [{ type: "text", text: "ok" }],
|
||||
isError: false,
|
||||
details: {},
|
||||
});
|
||||
|
||||
expect(executeFn).toHaveBeenCalledWith(
|
||||
{ input: "test" },
|
||||
expect.objectContaining({
|
||||
pluginId: "test-plugin",
|
||||
settings: {},
|
||||
}),
|
||||
);
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to get settings for plugin test-plugin: Plugin lookup failed"),
|
||||
);
|
||||
});
|
||||
|
||||
it("should invalidate cache when plugin state changes", async () => {
|
||||
const pluginTool: PluginToolDefinition = {
|
||||
name: "testTool",
|
||||
@@ -403,6 +458,36 @@ describe("PluginRunner", () => {
|
||||
// The invokeHook should complete (the slow plugin's error is logged but not thrown)
|
||||
await expect(runner.invokeHook("onTaskCreated", {})).resolves.not.toThrow();
|
||||
});
|
||||
|
||||
it("should warn when invokeHookSafe times out", async () => {
|
||||
const slowMockLoader = {
|
||||
...mockPluginLoader,
|
||||
invokeHook: vi.fn().mockImplementation(async () => {
|
||||
await new Promise((r) => setTimeout(r, 100));
|
||||
}),
|
||||
};
|
||||
|
||||
const runner = new PluginRunner({
|
||||
pluginLoader: slowMockLoader as unknown as PluginLoader,
|
||||
pluginStore: mockPluginStore as unknown as PluginStore,
|
||||
taskStore: mockTaskStore as any,
|
||||
rootDir: "/test/project",
|
||||
hookTimeoutMs: 50,
|
||||
});
|
||||
|
||||
await runner.init();
|
||||
|
||||
const createdHandler = mockTaskStore.on.mock.calls.find(
|
||||
(call) => call[0] === "task:created",
|
||||
)?.[1] as (task: any) => void;
|
||||
|
||||
expect(() => createdHandler?.({ id: "FN-001" })).not.toThrow();
|
||||
await new Promise((resolve) => setTimeout(resolve, 80));
|
||||
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Hook onTaskCreated failed: Hook onTaskCreated timed out"),
|
||||
);
|
||||
});
|
||||
});
|
||||
|
||||
describe("Hot-load via store events", () => {
|
||||
@@ -451,6 +536,23 @@ describe("PluginRunner", () => {
|
||||
expect(mockPluginLoader.stopPlugin).toHaveBeenCalledWith("test-plugin");
|
||||
});
|
||||
|
||||
it("should warn and isolate errors when unregistered plugin stop fails", async () => {
|
||||
await pluginRunner.init();
|
||||
mockPluginLoader.stopPlugin.mockRejectedValue(new Error("Plugin already stopped"));
|
||||
|
||||
const unregisteredHandler = mockPluginStore.on.mock.calls.find(
|
||||
(call) => call[0] === "plugin:unregistered",
|
||||
)?.[1] as (plugin: any) => void;
|
||||
|
||||
await expect(
|
||||
unregisteredHandler?.({ id: "test-plugin", name: "Test Plugin", version: "1.0.0" }),
|
||||
).resolves.not.toThrow();
|
||||
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to stop unregistered plugin test-plugin: Plugin already stopped"),
|
||||
);
|
||||
});
|
||||
|
||||
it("should isolate errors in auto-load", async () => {
|
||||
await pluginRunner.init();
|
||||
|
||||
|
||||
@@ -2,6 +2,16 @@ import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
|
||||
import { AgentLogger, summarizeToolArgs } from "./agent-logger.js";
|
||||
import type { TaskStore } from "@fusion/core";
|
||||
|
||||
const loggerWarnSpy = vi.hoisted(() => vi.fn());
|
||||
|
||||
vi.mock("./logger.js", () => ({
|
||||
createLogger: () => ({
|
||||
log: vi.fn(),
|
||||
warn: loggerWarnSpy,
|
||||
error: vi.fn(),
|
||||
}),
|
||||
}));
|
||||
|
||||
// ── summarizeToolArgs tests ──────────────────────────────────────────
|
||||
|
||||
describe("summarizeToolArgs", () => {
|
||||
@@ -51,6 +61,7 @@ function createMockStore() {
|
||||
|
||||
describe("AgentLogger", () => {
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks();
|
||||
vi.useFakeTimers();
|
||||
});
|
||||
|
||||
@@ -346,114 +357,68 @@ describe("AgentLogger", () => {
|
||||
});
|
||||
|
||||
describe("persistence failure observability", () => {
|
||||
const warningFor = (warnSpy: ReturnType<typeof vi.spyOn>): string => {
|
||||
return warnSpy.mock.calls.map((call) => call.map((arg) => String(arg)).join(" ")).join("\n");
|
||||
};
|
||||
it("onToolStart warns on persistence failure", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("EACCES: permission denied")),
|
||||
} as unknown as TaskStore;
|
||||
const logger = new AgentLogger({ store, taskId: "FN-2090-TOOL-START" });
|
||||
|
||||
it("text flush failure logs structured warning", async () => {
|
||||
expect(() => logger.onToolStart("Bash", { command: "ls" })).not.toThrow();
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
expect(loggerWarnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to log tool start \"Bash\" for FN-2090-TOOL-START"),
|
||||
);
|
||||
});
|
||||
|
||||
it("onToolEnd warns on persistence failure", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("EPERM: operation not permitted")),
|
||||
} as unknown as TaskStore;
|
||||
const logger = new AgentLogger({ store, taskId: "FN-2090-TOOL-END" });
|
||||
|
||||
expect(() => logger.onToolEnd("Bash", false, "output")).not.toThrow();
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
expect(loggerWarnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to log tool end \"Bash\" (tool_result) for FN-2090-TOOL-END"),
|
||||
);
|
||||
});
|
||||
|
||||
it("flushTextBuffer warns on persistence failure", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("ENOSPC: no space left on device")),
|
||||
} as unknown as TaskStore;
|
||||
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const logger = new AgentLogger({
|
||||
store,
|
||||
taskId: "FN-2083-TEXT",
|
||||
taskId: "FN-2090-TEXT",
|
||||
flushSizeBytes: 1,
|
||||
});
|
||||
|
||||
logger.onText("some text");
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
const warning = warningFor(warnSpy);
|
||||
expect(warning).toContain("[agent-logger]");
|
||||
expect(warning).toContain("FN-2083-TEXT");
|
||||
expect(warning).toContain("ENOSPC");
|
||||
|
||||
warnSpy.mockRestore();
|
||||
expect(loggerWarnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to flush text buffer for FN-2090-TEXT"),
|
||||
);
|
||||
});
|
||||
|
||||
it("thinking flush failure logs structured warning", async () => {
|
||||
it("flushThinkingBuffer warns on persistence failure", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("ENOSPC: no space left on device")),
|
||||
} as unknown as TaskStore;
|
||||
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const logger = new AgentLogger({
|
||||
store,
|
||||
taskId: "FN-2083-THINK",
|
||||
taskId: "FN-2090-THINKING",
|
||||
flushSizeBytes: 1,
|
||||
});
|
||||
|
||||
logger.onThinking("deep thought");
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
const warning = warningFor(warnSpy);
|
||||
expect(warning).toContain("[agent-logger]");
|
||||
expect(warning).toContain("FN-2083-THINK");
|
||||
expect(warning).toContain("thinking");
|
||||
expect(warning).toContain("ENOSPC");
|
||||
|
||||
warnSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("tool-start persistence failure logs structured warning", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("EACCES: permission denied")),
|
||||
} as unknown as TaskStore;
|
||||
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const logger = new AgentLogger({ store, taskId: "FN-2083-TOOL-START" });
|
||||
|
||||
logger.onToolStart("Bash", { command: "ls" });
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
const warning = warningFor(warnSpy);
|
||||
expect(warning).toContain("[agent-logger]");
|
||||
expect(warning).toContain("FN-2083-TOOL-START");
|
||||
expect(warning).toContain("Bash");
|
||||
expect(warning).toContain("EACCES");
|
||||
|
||||
warnSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("tool-end persistence failure logs structured warning", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("EPERM: operation not permitted")),
|
||||
} as unknown as TaskStore;
|
||||
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const logger = new AgentLogger({ store, taskId: "FN-2083-TOOL-END" });
|
||||
|
||||
logger.onToolEnd("Bash", false, "output");
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
|
||||
const warning = warningFor(warnSpy);
|
||||
expect(warning).toContain("[agent-logger]");
|
||||
expect(warning).toContain("FN-2083-TOOL-END");
|
||||
expect(warning).toContain("EPERM");
|
||||
|
||||
warnSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("flush() propagates text and thinking warnings", async () => {
|
||||
const store = {
|
||||
appendAgentLog: vi.fn().mockRejectedValue(new Error("ENOSPC: no space left on device")),
|
||||
} as unknown as TaskStore;
|
||||
const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const logger = new AgentLogger({
|
||||
store,
|
||||
taskId: "FN-2083-FLUSH",
|
||||
flushSizeBytes: 1024,
|
||||
});
|
||||
|
||||
logger.onText("text");
|
||||
logger.onThinking("thought");
|
||||
await logger.flush();
|
||||
|
||||
const warning = warningFor(warnSpy);
|
||||
expect(warnSpy).toHaveBeenCalledTimes(2);
|
||||
expect(warning).toContain("[agent-logger]");
|
||||
expect(warning).toContain("FN-2083-FLUSH");
|
||||
expect(warning).toContain("ENOSPC");
|
||||
|
||||
warnSpy.mockRestore();
|
||||
expect(loggerWarnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Failed to flush thinking buffer for FN-2090-THINKING"),
|
||||
);
|
||||
});
|
||||
});
|
||||
});
|
||||
|
||||
@@ -6,8 +6,6 @@ const FLUSH_SIZE_BYTES = 1024;
|
||||
/** Default timer interval (ms) for periodic flush of small writes. */
|
||||
const FLUSH_INTERVAL_MS = 500;
|
||||
|
||||
const log = createLogger("agent-logger");
|
||||
|
||||
/**
|
||||
* Produce a human-readable summary from tool arguments.
|
||||
* Returns the full argument value without truncation.
|
||||
@@ -92,6 +90,7 @@ export class AgentLogger {
|
||||
private readonly agent?: AgentRole;
|
||||
private readonly externalTextCb?: (taskId: string, delta: string) => void;
|
||||
private readonly externalToolCb?: (taskId: string, toolName: string) => void;
|
||||
private readonly log = createLogger("agent-logger");
|
||||
|
||||
constructor(options: AgentLoggerOptions) {
|
||||
this.store = options.store;
|
||||
@@ -151,12 +150,7 @@ export class AgentLogger {
|
||||
this.flushThinkingBuffer();
|
||||
const detail = summarizeToolArgs(name, args);
|
||||
this.store.appendAgentLog(this.taskId, name, "tool", detail, this.agent).catch((err) => {
|
||||
log.warn(
|
||||
"Failed to persist tool-start log for task %s (tool: %s): %s",
|
||||
this.taskId,
|
||||
name,
|
||||
err instanceof Error ? err.message : String(err),
|
||||
);
|
||||
this.log.warn(`Failed to log tool start "${name}" for ${this.taskId}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
});
|
||||
}
|
||||
|
||||
@@ -176,13 +170,7 @@ export class AgentLogger {
|
||||
detail = str.length > 500 ? str.slice(0, 500) + "…" : str;
|
||||
}
|
||||
this.store.appendAgentLog(this.taskId, name, type, detail, this.agent).catch((err) => {
|
||||
log.warn(
|
||||
"Failed to persist tool-end log for task %s (tool: %s, type: %s): %s",
|
||||
this.taskId,
|
||||
name,
|
||||
type,
|
||||
err instanceof Error ? err.message : String(err),
|
||||
);
|
||||
this.log.warn(`Failed to log tool end "${name}" (${type}) for ${this.taskId}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
});
|
||||
}
|
||||
|
||||
@@ -204,11 +192,7 @@ export class AgentLogger {
|
||||
const chunk = this.textBuffer;
|
||||
this.textBuffer = "";
|
||||
return this.store.appendAgentLog(this.taskId, chunk, "text", undefined, this.agent).catch((err) => {
|
||||
log.warn(
|
||||
"Failed to persist text log for task %s: %s",
|
||||
this.taskId,
|
||||
err instanceof Error ? err.message : String(err),
|
||||
);
|
||||
this.log.warn(`Failed to flush text buffer for ${this.taskId}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
});
|
||||
}
|
||||
|
||||
@@ -217,11 +201,7 @@ export class AgentLogger {
|
||||
const chunk = this.thinkingBuffer;
|
||||
this.thinkingBuffer = "";
|
||||
return this.store.appendAgentLog(this.taskId, chunk, "thinking", undefined, this.agent).catch((err) => {
|
||||
log.warn(
|
||||
"Failed to persist thinking log for task %s: %s",
|
||||
this.taskId,
|
||||
err instanceof Error ? err.message : String(err),
|
||||
);
|
||||
this.log.warn(`Failed to flush thinking buffer for ${this.taskId}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
});
|
||||
}
|
||||
|
||||
|
||||
@@ -14,16 +14,43 @@ import {
|
||||
} from "./agent-tools.js";
|
||||
import type { MessageStore, Message } from "@fusion/core";
|
||||
|
||||
// Mock logger
|
||||
vi.mock("./logger.js", () => {
|
||||
const createMockLogger = () => ({
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
});
|
||||
const loggerSpies = vi.hoisted(() => ({
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
}));
|
||||
|
||||
const execFileMock = vi.hoisted(() => vi.fn());
|
||||
const readdirMock = vi.hoisted(() => vi.fn());
|
||||
|
||||
vi.mock("node:fs/promises", async () => {
|
||||
const actual = await vi.importActual<typeof import("node:fs/promises")>("node:fs/promises");
|
||||
readdirMock.mockImplementation(((...args: Parameters<typeof actual.readdir>) => actual.readdir(...args)) as typeof actual.readdir);
|
||||
return {
|
||||
createLogger: vi.fn(() => createMockLogger()),
|
||||
heartbeatLog: createMockLogger(),
|
||||
...actual,
|
||||
readdir: readdirMock,
|
||||
};
|
||||
});
|
||||
|
||||
// Mock logger
|
||||
vi.mock("./logger.js", () => ({
|
||||
createLogger: vi.fn(() => ({
|
||||
log: loggerSpies.log,
|
||||
warn: loggerSpies.warn,
|
||||
error: loggerSpies.error,
|
||||
})),
|
||||
heartbeatLog: {
|
||||
log: loggerSpies.log,
|
||||
warn: loggerSpies.warn,
|
||||
error: loggerSpies.error,
|
||||
},
|
||||
}));
|
||||
|
||||
vi.mock("node:child_process", async () => {
|
||||
const actual = await vi.importActual<typeof import("node:child_process")>("node:child_process");
|
||||
return {
|
||||
...actual,
|
||||
execFile: execFileMock,
|
||||
};
|
||||
});
|
||||
|
||||
@@ -31,10 +58,20 @@ describe("createMemoryTools", () => {
|
||||
let tempDir: string;
|
||||
|
||||
beforeEach(async () => {
|
||||
vi.clearAllMocks();
|
||||
delete process.env.FUSION_ENABLE_QMD_REFRESH_IN_TESTS;
|
||||
execFileMock.mockImplementation((...args: unknown[]) => {
|
||||
const callback = args[args.length - 1];
|
||||
if (typeof callback === "function") {
|
||||
callback(null, "", "");
|
||||
}
|
||||
return undefined;
|
||||
});
|
||||
tempDir = await mkdtemp(join(tmpdir(), "agent-memory-tools-"));
|
||||
});
|
||||
|
||||
afterEach(async () => {
|
||||
delete process.env.FUSION_ENABLE_QMD_REFRESH_IN_TESTS;
|
||||
await rm(tempDir, { recursive: true, force: true });
|
||||
});
|
||||
|
||||
@@ -172,6 +209,93 @@ describe("createMemoryTools", () => {
|
||||
"7",
|
||||
]);
|
||||
});
|
||||
|
||||
|
||||
it("logs a warning and continues when agent memory directory read fails", async () => {
|
||||
readdirMock.mockRejectedValueOnce(new Error("EACCES"));
|
||||
|
||||
const [searchTool] = createMemoryTools(tempDir, { memoryBackendType: "file" }, {
|
||||
agentMemory: {
|
||||
agentId: "ceo-agent",
|
||||
agentName: "CEO",
|
||||
memory: "Roadmap delegation priorities are tracked here.",
|
||||
},
|
||||
});
|
||||
|
||||
const result = await (searchTool as any).execute("call-1", {
|
||||
query: "delegation",
|
||||
limit: 5,
|
||||
}, undefined, undefined, undefined);
|
||||
|
||||
expect(result.content[0]!.text).toContain(".fusion/agent-memory/ceo-agent/MEMORY.md");
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("Failed to read agent memory directory"));
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("EACCES"));
|
||||
});
|
||||
|
||||
it("logs a warning and falls back to file search when qmd search fails", async () => {
|
||||
process.env.FUSION_ENABLE_QMD_REFRESH_IN_TESTS = "1";
|
||||
execFileMock.mockImplementation((...args: unknown[]) => {
|
||||
const callback = args[args.length - 1];
|
||||
const commandArgs = args[1] as string[];
|
||||
if (typeof callback === "function") {
|
||||
if (Array.isArray(commandArgs) && commandArgs[0] === "search") {
|
||||
callback(new Error("qmd search failed"), "", "");
|
||||
return undefined;
|
||||
}
|
||||
callback(null, "", "");
|
||||
}
|
||||
return undefined;
|
||||
});
|
||||
|
||||
const [searchTool] = createMemoryTools(tempDir, { memoryBackendType: "qmd" }, {
|
||||
agentMemory: {
|
||||
agentId: "ceo-agent",
|
||||
agentName: "CEO",
|
||||
memory: "Roadmap delegation priorities are tracked here.",
|
||||
},
|
||||
});
|
||||
|
||||
const result = await (searchTool as any).execute("call-1", {
|
||||
query: "delegation",
|
||||
limit: 5,
|
||||
}, undefined, undefined, undefined);
|
||||
|
||||
expect(result.details.results[0].backend).toBe("agent-memory");
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("QMD agent memory search failed for agent ceo-agent"));
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("qmd search failed"));
|
||||
});
|
||||
|
||||
it("logs a warning when background qmd refresh fails after memory append", async () => {
|
||||
process.env.FUSION_ENABLE_QMD_REFRESH_IN_TESTS = "1";
|
||||
execFileMock.mockImplementation((...args: unknown[]) => {
|
||||
const callback = args[args.length - 1];
|
||||
if (typeof callback === "function") {
|
||||
callback(new Error("qmd refresh failed"), "", "");
|
||||
}
|
||||
return undefined;
|
||||
});
|
||||
|
||||
const tools = createMemoryTools(tempDir, { memoryBackendType: "qmd" }, {
|
||||
agentMemory: {
|
||||
agentId: "ceo-agent",
|
||||
agentName: "CEO",
|
||||
memory: "Roadmap delegation priorities are tracked here.",
|
||||
},
|
||||
});
|
||||
const appendTool = tools.find((tool) => tool.name === "memory_append")!;
|
||||
|
||||
const result = await (appendTool as any).execute("call-1", {
|
||||
scope: "agent",
|
||||
layer: "daily",
|
||||
content: "- Follow up on delegated roadmap work.",
|
||||
}, undefined, undefined, undefined);
|
||||
|
||||
expect(result.content[0]!.text).toContain("Appended to agent daily memory.");
|
||||
await vi.waitFor(() => {
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("Agent memory QMD index refresh failed for ceo-agent"));
|
||||
});
|
||||
expect(loggerSpies.warn).toHaveBeenCalledWith(expect.stringContaining("qmd refresh failed"));
|
||||
});
|
||||
});
|
||||
|
||||
function createMessage(overrides: Partial<Message> = {}): Message {
|
||||
|
||||
@@ -16,6 +16,7 @@ import { dailyMemoryPath, ensureOpenClawMemoryFiles, getMemoryBackendCapabilitie
|
||||
import type { ToolDefinition } from "@mariozechner/pi-coding-agent";
|
||||
import { Type, type Static } from "@mariozechner/pi-ai";
|
||||
import type { AgentReflectionService } from "./agent-reflection.js";
|
||||
import { createLogger } from "./logger.js";
|
||||
|
||||
// ── Tool parameter schemas (canonical definitions) ────────────────────────
|
||||
|
||||
@@ -132,6 +133,8 @@ type MemorySearchHit = {
|
||||
backend: string;
|
||||
};
|
||||
|
||||
const log = createLogger("agent-tools");
|
||||
|
||||
const AGENT_MEMORY_ROOT = ".fusion/agent-memory";
|
||||
const AGENT_MEMORY_FILENAME = "MEMORY.md";
|
||||
const AGENT_DREAMS_FILENAME = "DREAMS.md";
|
||||
@@ -234,7 +237,15 @@ async function listAgentMemoryFiles(rootDir: string, agentMemory: AgentMemoryCon
|
||||
{ absPath: agentMemoryFilePath(rootDir, agentMemory.agentId), displayPath: agentMemoryDisplayPath(agentMemory.agentId) },
|
||||
{ absPath: agentDreamsFilePath(rootDir, agentMemory.agentId), displayPath: agentDreamsDisplayPath(agentMemory.agentId) },
|
||||
];
|
||||
for (const entry of await readdir(dir).catch(() => [] as string[])) {
|
||||
let entries: string[];
|
||||
try {
|
||||
entries = await readdir(dir);
|
||||
} catch (err) {
|
||||
log.warn(`Failed to read agent memory directory ${dir}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
entries = [];
|
||||
}
|
||||
|
||||
for (const entry of entries) {
|
||||
if (!DAILY_AGENT_MEMORY_RE.test(entry)) continue;
|
||||
const absPath = join(dir, entry);
|
||||
const fileStat = await stat(absPath);
|
||||
@@ -356,7 +367,10 @@ async function searchAgentMemoryWithQmd(rootDir: string, agentMemory: AgentMemor
|
||||
score: Number(result.score ?? 1) + 1000,
|
||||
backend: "qmd-agent-memory",
|
||||
})).filter((result: MemorySearchHit) => result.snippet.trim().length > 0);
|
||||
} catch {
|
||||
} catch (err) {
|
||||
log.warn(
|
||||
`QMD agent memory search failed for agent ${agentMemory.agentId}, falling back to file search: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
return searchAgentMemoryFile(rootDir, agentMemory, query, limit);
|
||||
}
|
||||
}
|
||||
@@ -694,13 +708,18 @@ export function createMemoryAppendTool(rootDir: string, settings?: MemoryToolSet
|
||||
if (!options?.agentMemory) {
|
||||
return { content: [{ type: "text" as const, text: "ERROR: agent memory is not available in this session" }], details: {} };
|
||||
}
|
||||
await syncAgentMemoryFile(rootDir, options.agentMemory);
|
||||
const agentMemory = options.agentMemory;
|
||||
await syncAgentMemoryFile(rootDir, agentMemory);
|
||||
const targetPath = params.layer === "long-term"
|
||||
? agentMemoryFilePath(rootDir, options.agentMemory.agentId)
|
||||
: agentDailyFilePath(rootDir, options.agentMemory.agentId);
|
||||
? agentMemoryFilePath(rootDir, agentMemory.agentId)
|
||||
: agentDailyFilePath(rootDir, agentMemory.agentId);
|
||||
await appendFile(targetPath, `\n${content}\n`, "utf-8");
|
||||
if (resolveMemoryBackend(settings).type === "qmd") {
|
||||
void refreshAgentMemoryQmdIndex(rootDir, options.agentMemory).catch(() => {});
|
||||
void refreshAgentMemoryQmdIndex(rootDir, agentMemory).catch((err) => {
|
||||
log.warn(
|
||||
`Agent memory QMD index refresh failed for ${agentMemory.agentId}: ${err instanceof Error ? err.message : String(err)}`,
|
||||
);
|
||||
});
|
||||
}
|
||||
return {
|
||||
content: [{ type: "text" as const, text: `Appended to agent ${params.layer} memory.` }],
|
||||
|
||||
@@ -1,9 +1,33 @@
|
||||
import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
|
||||
import { CronRunner } from "./cron-runner.js";
|
||||
import { CronRunner, createAiPromptExecutor } from "./cron-runner.js";
|
||||
import type { AiPromptExecutor } from "./cron-runner.js";
|
||||
import type { TaskStore, AutomationStore, ScheduledTask, AutomationRunResult, AutomationStep, Settings } from "@fusion/core";
|
||||
import { randomUUID } from "node:crypto";
|
||||
|
||||
const cronLoggerSpies = vi.hoisted(() => ({
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
}));
|
||||
|
||||
const piModuleMocks = vi.hoisted(() => ({
|
||||
createKbAgent: vi.fn(),
|
||||
promptWithFallback: vi.fn(),
|
||||
}));
|
||||
|
||||
vi.mock("./logger.js", () => ({
|
||||
createLogger: () => ({
|
||||
log: cronLoggerSpies.log,
|
||||
warn: cronLoggerSpies.warn,
|
||||
error: cronLoggerSpies.error,
|
||||
}),
|
||||
}));
|
||||
|
||||
vi.mock("./pi.js", () => ({
|
||||
createKbAgent: piModuleMocks.createKbAgent,
|
||||
promptWithFallback: piModuleMocks.promptWithFallback,
|
||||
}));
|
||||
|
||||
// Default settings inline to avoid @fusion/core build dependency during tests
|
||||
const DEFAULT_SETTINGS: Settings = {
|
||||
maxConcurrent: 2,
|
||||
@@ -72,6 +96,16 @@ function createMockAutomationStore(schedules: ScheduledTask[] = []): AutomationS
|
||||
describe("CronRunner", () => {
|
||||
let runner: CronRunner;
|
||||
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks();
|
||||
piModuleMocks.promptWithFallback.mockResolvedValue(undefined);
|
||||
piModuleMocks.createKbAgent.mockResolvedValue({
|
||||
session: {
|
||||
dispose: vi.fn(),
|
||||
},
|
||||
});
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
if (runner) runner.stop();
|
||||
});
|
||||
@@ -109,6 +143,31 @@ describe("CronRunner", () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("createAiPromptExecutor", () => {
|
||||
it("returns response text even when session disposal throws", async () => {
|
||||
piModuleMocks.createKbAgent.mockImplementation(async (options: { onText?: (delta: string) => void }) => {
|
||||
options.onText?.("hello ");
|
||||
options.onText?.("world");
|
||||
return {
|
||||
session: {
|
||||
dispose: () => {
|
||||
throw new Error("dispose failed");
|
||||
},
|
||||
},
|
||||
};
|
||||
});
|
||||
|
||||
const executor = await createAiPromptExecutor("/test/project");
|
||||
const result = await executor("Summarize this");
|
||||
|
||||
expect(result).toBe("hello world");
|
||||
expect(piModuleMocks.promptWithFallback).toHaveBeenCalledTimes(1);
|
||||
expect(cronLoggerSpies.warn).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Session disposal failed: dispose failed"),
|
||||
);
|
||||
});
|
||||
});
|
||||
|
||||
describe("tick", () => {
|
||||
it("skips when globalPause is true", async () => {
|
||||
const store = createMockStore({ globalPause: true });
|
||||
|
||||
@@ -630,6 +630,7 @@ export async function createAiPromptExecutor(cwd: string): Promise<AiPromptExecu
|
||||
// We import lazily to keep the factory self-contained and to avoid
|
||||
// pulling pi.ts into the module graph when AI execution isn't used.
|
||||
const { createKbAgent, promptWithFallback } = await import("./pi.js");
|
||||
const disposeLog = createLogger("cron-runner");
|
||||
|
||||
return async (prompt: string, modelProvider?: string, modelId?: string): Promise<string> => {
|
||||
let responseText = "";
|
||||
@@ -651,8 +652,8 @@ export async function createAiPromptExecutor(cwd: string): Promise<AiPromptExecu
|
||||
} finally {
|
||||
try {
|
||||
session.dispose();
|
||||
} catch {
|
||||
// Best-effort disposal — don't mask the original error
|
||||
} catch (err) {
|
||||
disposeLog.warn(`Session disposal failed: ${err instanceof Error ? err.message : String(err)}`);
|
||||
}
|
||||
}
|
||||
};
|
||||
|
||||
@@ -285,8 +285,8 @@ export class PluginRunner {
|
||||
try {
|
||||
executorLog.log(`Stopping unregistered plugin: ${plugin.id}`);
|
||||
await this.options.pluginLoader.stopPlugin(plugin.id);
|
||||
} catch {
|
||||
// Ignore - plugin might not be loaded
|
||||
} catch (err) {
|
||||
this.log.warn(`Failed to stop unregistered plugin ${plugin.id}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -452,7 +452,8 @@ export class PluginRunner {
|
||||
try {
|
||||
const plugin = await this.options.pluginStore.getPlugin(pluginId);
|
||||
return plugin.settings;
|
||||
} catch {
|
||||
} catch (err) {
|
||||
this.log.warn(`Failed to get settings for plugin ${pluginId}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
return {};
|
||||
}
|
||||
}
|
||||
@@ -551,8 +552,8 @@ export class PluginRunner {
|
||||
this.hookTimeoutMs,
|
||||
`Hook ${hookName} timed out`,
|
||||
);
|
||||
} catch {
|
||||
// Error already logged by invokeHook
|
||||
} catch (err) {
|
||||
this.log.warn(`Hook ${hookName} failed: ${err instanceof Error ? err.message : String(err)}`);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user