feat(FN-2104): merge fusion/fn-2104
This commit is contained in:
@@ -5,6 +5,19 @@
|
||||
*/
|
||||
|
||||
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
|
||||
|
||||
const { mockPiLog } = vi.hoisted(() => ({
|
||||
mockPiLog: {
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
},
|
||||
}));
|
||||
|
||||
vi.mock("../logger.js", () => ({
|
||||
piLog: mockPiLog,
|
||||
}));
|
||||
|
||||
import { buildSessionSkillContext } from "../session-skill-context.js";
|
||||
import { resolveSessionSkills, createSkillsOverrideFromSelection } from "../skill-resolver.js";
|
||||
import type { Agent, AgentStore } from "@fusion/core";
|
||||
@@ -45,15 +58,16 @@ function createMockProjectDir(settings: Record<string, unknown> | null): string
|
||||
// ── Tests ───────────────────────────────────────────────────────────────────
|
||||
|
||||
describe("agent skills flow - full integration", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
beforeEach(() => {
|
||||
mockFiles.clear();
|
||||
mockDirCounter = 0;
|
||||
mockPiLog.log.mockClear();
|
||||
mockPiLog.warn.mockClear();
|
||||
mockPiLog.error.mockClear();
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
consoleErrorSpy.mockRestore();
|
||||
vi.clearAllMocks();
|
||||
});
|
||||
|
||||
it("full end-to-end flow: settings patterns + agent metadata + discovered skills produce correct override", async () => {
|
||||
@@ -130,8 +144,8 @@ describe("agent skills flow - full integration", () => {
|
||||
expect(disabledLintWarning).toBeDefined();
|
||||
expect(disabledLintWarning?.type).toBe("warning");
|
||||
|
||||
// Step 10: Verify console.error was called with disabled skill warning
|
||||
const loggedMessages = consoleErrorSpy.mock.calls.map(c => c[0] as string);
|
||||
// Step 10: Verify structured logger warning was called with disabled skill warning
|
||||
const loggedMessages = mockPiLog.warn.mock.calls.map(c => c[0] as string);
|
||||
const hasDisabledLintWarning = loggedMessages.some(m =>
|
||||
m.includes("disabled") && m.includes("lint")
|
||||
);
|
||||
|
||||
@@ -54,9 +54,12 @@ export const executorLog = createLogger("executor");
|
||||
/** Logger for the triage processor subsystem. */
|
||||
export const triageLog = createLogger("triage");
|
||||
|
||||
/** Logger for the AI session (pi) subsystem. */
|
||||
/** Logger for the pi agent session subsystem. */
|
||||
export const piLog = createLogger("pi");
|
||||
|
||||
/** Logger for extension discovery/provider registration. */
|
||||
export const extensionsLog = createLogger("extensions");
|
||||
|
||||
/** Logger for the merge/auto-merge subsystem. */
|
||||
export const mergerLog = createLogger("merger");
|
||||
|
||||
|
||||
@@ -760,8 +760,6 @@ describe("createKbAgent", () => {
|
||||
return "{}";
|
||||
});
|
||||
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
let capturedResourceLoaderOptions: any;
|
||||
vi.doMock("@mariozechner/pi-coding-agent", () => ({
|
||||
AuthStorage: {
|
||||
@@ -831,13 +829,9 @@ describe("createKbAgent", () => {
|
||||
});
|
||||
expect(result.skills).toHaveLength(1); // All skills pass through
|
||||
}
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("with skillSelection (specific requested names) activates skill filtering", async () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
let capturedResourceLoaderOptions: any;
|
||||
vi.doMock("@mariozechner/pi-coding-agent", () => ({
|
||||
AuthStorage: {
|
||||
@@ -915,12 +909,11 @@ describe("createKbAgent", () => {
|
||||
// Only paperclip should pass through (matching requested name)
|
||||
expect(result.skills).toHaveLength(1);
|
||||
expect(result.skills[0].name).toBe("paperclip");
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("diagnostics are logged via console.error with [pi] [skills] prefix", async () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
it("diagnostics are logged via structured logger with [skills] context", async () => {
|
||||
const { piLog } = await import("./logger.js");
|
||||
const piWarnSpy = vi.spyOn(piLog, "warn").mockImplementation(() => {});
|
||||
|
||||
// Test diagnostics logging by directly calling createSkillsOverrideFromSelection
|
||||
const { createSkillsOverrideFromSelection } = await import("./skill-resolver.js");
|
||||
@@ -945,9 +938,9 @@ describe("createKbAgent", () => {
|
||||
// Check that diagnostics were produced
|
||||
expect(result.diagnostics.length).toBeGreaterThan(0);
|
||||
|
||||
// Check that diagnostics were logged with correct prefix
|
||||
const skillLogs = consoleErrorSpy.mock.calls.filter(call =>
|
||||
String(call[0]).includes("[pi] [skills]")
|
||||
// Check that diagnostics were logged with [skills] context
|
||||
const skillLogs = piWarnSpy.mock.calls.filter(call =>
|
||||
String(call[0]).includes("[skills]")
|
||||
);
|
||||
expect(skillLogs.length).toBeGreaterThan(0);
|
||||
|
||||
@@ -955,7 +948,7 @@ describe("createKbAgent", () => {
|
||||
const lastLog = skillLogs[skillLogs.length - 1][0] as string;
|
||||
expect(lastLog).toContain("[executor]");
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
piWarnSpy.mockRestore();
|
||||
});
|
||||
});
|
||||
});
|
||||
|
||||
@@ -264,18 +264,22 @@ describe("promptWithFallback context recovery", () => {
|
||||
});
|
||||
|
||||
describe("createKbAgent skills parameter", () => {
|
||||
let consoleErrorSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piLogSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piWarnSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piErrorSpy: ReturnType<typeof vi.spyOn>;
|
||||
let mockResolveSessionSkills: ReturnType<typeof vi.fn>;
|
||||
let mockCreateSkillsOverride: ReturnType<typeof vi.fn>;
|
||||
|
||||
beforeEach(async () => {
|
||||
consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
piLogSpy = vi.spyOn(piLog, "log").mockImplementation(() => {});
|
||||
piWarnSpy = vi.spyOn(piLog, "warn").mockImplementation(() => {});
|
||||
piErrorSpy = vi.spyOn(piLog, "error").mockImplementation(() => {});
|
||||
|
||||
// Access the mocked module to get/set mocks
|
||||
const skillResolver = await import("./skill-resolver.js");
|
||||
mockResolveSessionSkills = vi.mocked(skillResolver.resolveSessionSkills);
|
||||
mockCreateSkillsOverride = vi.mocked(skillResolver.createSkillsOverrideFromSelection);
|
||||
|
||||
|
||||
mockResolveSessionSkills.mockReturnValue({
|
||||
allowedSkillPaths: new Set(),
|
||||
excludedSkillPaths: new Set(),
|
||||
@@ -289,7 +293,9 @@ describe("createKbAgent skills parameter", () => {
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
consoleErrorSpy.mockRestore();
|
||||
piLogSpy.mockRestore();
|
||||
piWarnSpy.mockRestore();
|
||||
piErrorSpy.mockRestore();
|
||||
vi.clearAllMocks();
|
||||
});
|
||||
|
||||
@@ -332,7 +338,7 @@ describe("createKbAgent skills parameter", () => {
|
||||
expect(callArgs.sessionPurpose).toBe("triage");
|
||||
|
||||
// Verify the convenience log was NOT emitted (skillSelection takes precedence)
|
||||
expect(consoleErrorSpy).not.toHaveBeenCalledWith(
|
||||
expect(piLogSpy).not.toHaveBeenCalledWith(
|
||||
expect.stringContaining("Using skills from convenience parameter")
|
||||
);
|
||||
});
|
||||
@@ -361,8 +367,8 @@ describe("createKbAgent skills parameter", () => {
|
||||
await createKbAgent(options);
|
||||
|
||||
// Verify the log message includes the skill names
|
||||
expect(consoleErrorSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("[pi] Using skills from convenience parameter: [review, fusion]")
|
||||
expect(piLogSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("Using skills from convenience parameter: [review, fusion]")
|
||||
);
|
||||
});
|
||||
|
||||
@@ -387,21 +393,27 @@ describe("createKbAgent skills parameter", () => {
|
||||
|
||||
// The diagnostics should be logged
|
||||
expect(mockResolveSessionSkills).toHaveBeenCalled();
|
||||
expect(consoleErrorSpy).toHaveBeenCalledWith(
|
||||
expect(piWarnSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("warning")
|
||||
);
|
||||
});
|
||||
});
|
||||
|
||||
describe("promptWithFallback auto-compaction", () => {
|
||||
let consoleErrorSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piLogSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piWarnSpy: ReturnType<typeof vi.spyOn>;
|
||||
let piErrorSpy: ReturnType<typeof vi.spyOn>;
|
||||
|
||||
beforeEach(() => {
|
||||
consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
piLogSpy = vi.spyOn(piLog, "log").mockImplementation(() => {});
|
||||
piWarnSpy = vi.spyOn(piLog, "warn").mockImplementation(() => {});
|
||||
piErrorSpy = vi.spyOn(piLog, "error").mockImplementation(() => {});
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
consoleErrorSpy.mockRestore();
|
||||
piLogSpy.mockRestore();
|
||||
piWarnSpy.mockRestore();
|
||||
piErrorSpy.mockRestore();
|
||||
vi.clearAllMocks();
|
||||
});
|
||||
|
||||
@@ -607,3 +619,97 @@ describe("session failure diagnostics", () => {
|
||||
warnSpy.mockRestore();
|
||||
});
|
||||
});
|
||||
|
||||
describe("piLog structured diagnostics", () => {
|
||||
let logSpy: ReturnType<typeof vi.spyOn>;
|
||||
let warnSpy: ReturnType<typeof vi.spyOn>;
|
||||
let errorSpy: ReturnType<typeof vi.spyOn>;
|
||||
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks();
|
||||
logSpy = vi.spyOn(piLog, "log").mockImplementation(() => {});
|
||||
warnSpy = vi.spyOn(piLog, "warn").mockImplementation(() => {});
|
||||
errorSpy = vi.spyOn(piLog, "error").mockImplementation(() => {});
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
logSpy.mockRestore();
|
||||
warnSpy.mockRestore();
|
||||
errorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("logs session creation with model info", async () => {
|
||||
await createKbAgent({
|
||||
cwd: "/test/project",
|
||||
systemPrompt: "Test",
|
||||
defaultProvider: "test",
|
||||
defaultModelId: "test-model",
|
||||
});
|
||||
|
||||
const hasModelLog = logSpy.mock.calls.some(([message]) =>
|
||||
String(message).includes("Session created successfully (model=test/test-model)"),
|
||||
);
|
||||
expect(hasModelLog).toBe(true);
|
||||
});
|
||||
|
||||
it("logs warning on primary model failure and fallback attempt", async () => {
|
||||
const createAgentSessionMock = vi.mocked(createAgentSession);
|
||||
createAgentSessionMock.mockReset();
|
||||
createAgentSessionMock
|
||||
.mockRejectedValueOnce(new Error("429 Too Many Requests"))
|
||||
.mockResolvedValueOnce({
|
||||
session: {
|
||||
model: { provider: "test", id: "fallback-model" },
|
||||
prompt: vi.fn(),
|
||||
subscribe: vi.fn(),
|
||||
dispose: vi.fn(),
|
||||
setThinkingLevel: vi.fn(),
|
||||
sessionFile: undefined,
|
||||
},
|
||||
} as any);
|
||||
|
||||
await createKbAgent({
|
||||
cwd: "/test/project",
|
||||
systemPrompt: "Test",
|
||||
defaultProvider: "test",
|
||||
defaultModelId: "primary-model",
|
||||
fallbackProvider: "test",
|
||||
fallbackModelId: "fallback-model",
|
||||
});
|
||||
|
||||
expect(warnSpy).toHaveBeenCalledWith(
|
||||
"Primary model failed (429 Too Many Requests), trying fallback",
|
||||
);
|
||||
expect(logSpy).toHaveBeenCalledWith("Fallback session created successfully");
|
||||
});
|
||||
|
||||
it("logs error when session creation fails with non-retryable error", async () => {
|
||||
const createAgentSessionMock = vi.mocked(createAgentSession);
|
||||
createAgentSessionMock.mockReset();
|
||||
createAgentSessionMock.mockRejectedValueOnce(new Error("fatal model failure"));
|
||||
|
||||
await expect(createKbAgent({
|
||||
cwd: "/test/project",
|
||||
systemPrompt: "Test",
|
||||
defaultProvider: "test",
|
||||
defaultModelId: "primary-model",
|
||||
})).rejects.toThrow("fatal model failure");
|
||||
|
||||
expect(errorSpy).toHaveBeenCalledWith("Session creation failed: fatal model failure");
|
||||
});
|
||||
|
||||
it("logs promptWithFallback trace at log level", async () => {
|
||||
const session = {
|
||||
prompt: vi.fn().mockResolvedValue(undefined),
|
||||
} as unknown as AgentSession;
|
||||
|
||||
await promptWithFallback(session, "test prompt");
|
||||
|
||||
expect(logSpy).toHaveBeenCalledWith(
|
||||
expect.stringContaining("promptWithFallback: calling session.prompt (prompt length=11)"),
|
||||
);
|
||||
expect(logSpy).toHaveBeenCalledWith("promptWithFallback: prompt completed");
|
||||
expect(warnSpy).not.toHaveBeenCalled();
|
||||
expect(errorSpy).not.toHaveBeenCalled();
|
||||
});
|
||||
});
|
||||
|
||||
@@ -34,7 +34,7 @@ import {
|
||||
} from "./skill-resolver.js";
|
||||
import { isContextLimitError } from "./context-limit-detector.js";
|
||||
import { createFusionAuthStorage, getModelRegistryModelsPath } from "./auth-storage.js";
|
||||
import { piLog } from "./logger.js";
|
||||
import { piLog, extensionsLog } from "./logger.js";
|
||||
|
||||
export interface AgentResult {
|
||||
session: AgentSession;
|
||||
@@ -81,20 +81,20 @@ async function promptSessionAndCheck(session: AgentSession, prompt: string, opti
|
||||
export async function promptWithFallback(session: AgentSession, prompt: string, options?: unknown): Promise<void> {
|
||||
const maybePromptable = session as Partial<PromptableSession>;
|
||||
if (typeof maybePromptable.promptWithFallback === "function") {
|
||||
console.error(`[pi] promptWithFallback: delegating to session.promptWithFallback (prompt length=${prompt.length})`);
|
||||
piLog.log(`promptWithFallback: delegating to session.promptWithFallback (prompt length=${prompt.length})`);
|
||||
await maybePromptable.promptWithFallback(prompt, options);
|
||||
console.error(`[pi] promptWithFallback: completed`);
|
||||
piLog.log("promptWithFallback: completed");
|
||||
return;
|
||||
}
|
||||
|
||||
console.error(`[pi] promptWithFallback: calling session.prompt (prompt length=${prompt.length})`);
|
||||
piLog.log(`promptWithFallback: calling session.prompt (prompt length=${prompt.length})`);
|
||||
try {
|
||||
await promptSessionAndCheck(session, prompt, options);
|
||||
console.error(`[pi] promptWithFallback: prompt completed`);
|
||||
piLog.log("promptWithFallback: prompt completed");
|
||||
} catch (err: unknown) {
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
if (!isContextLimitError(errorMessage)) {
|
||||
console.error(`[pi] promptWithFallback: non-context error — propagating: ${errorMessage}`);
|
||||
piLog.error(`promptWithFallback: non-context error — propagating: ${errorMessage}`);
|
||||
throw err;
|
||||
}
|
||||
|
||||
@@ -110,21 +110,21 @@ export async function promptWithFallback(session: AgentSession, prompt: string,
|
||||
}
|
||||
}
|
||||
|
||||
console.error(`[pi] promptWithFallback: context limit error — attempting auto-compaction`);
|
||||
piLog.warn("promptWithFallback: context limit error — attempting auto-compaction");
|
||||
await flushMemoryBeforeSessionCompaction(session);
|
||||
const compactResult = await compactSessionContext(session);
|
||||
if (!compactResult) {
|
||||
console.error(`[pi] promptWithFallback: compaction unavailable — propagating original error`);
|
||||
piLog.error("promptWithFallback: compaction unavailable — propagating original error");
|
||||
throw err;
|
||||
}
|
||||
|
||||
console.error(`[pi] promptWithFallback: compaction succeeded (${compactResult.tokensBefore} tokens) — retrying prompt`);
|
||||
piLog.log(`promptWithFallback: compaction succeeded (${compactResult.tokensBefore} tokens) — retrying prompt`);
|
||||
try {
|
||||
await promptSessionAndCheck(session, prompt, options);
|
||||
console.error(`[pi] promptWithFallback: prompt completed after auto-compaction`);
|
||||
piLog.log("promptWithFallback: prompt completed after auto-compaction");
|
||||
} catch (retryErr: unknown) {
|
||||
const retryErrorMessage = retryErr instanceof Error ? retryErr.message : String(retryErr);
|
||||
console.error(`[pi] promptWithFallback: retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
piLog.error(`promptWithFallback: retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
throw err; // Throw original error to preserve original context
|
||||
}
|
||||
}
|
||||
@@ -226,17 +226,17 @@ async function retryWithCompactedPromptMemory(
|
||||
return { recovered: false };
|
||||
}
|
||||
|
||||
console.error(
|
||||
`[pi] promptWithFallback: retrying with compacted prompt memory (${prompt.length} → ${compactedPrompt.length} chars)`,
|
||||
piLog.log(
|
||||
`promptWithFallback: retrying with compacted prompt memory (${prompt.length} → ${compactedPrompt.length} chars)`,
|
||||
);
|
||||
|
||||
try {
|
||||
await promptSessionAndCheck(session, compactedPrompt, options);
|
||||
console.error(`[pi] promptWithFallback: prompt completed after prompt-memory compaction`);
|
||||
piLog.log("promptWithFallback: prompt completed after prompt-memory compaction");
|
||||
return { recovered: true };
|
||||
} catch (err: unknown) {
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
console.error(`[pi] promptWithFallback: retry after prompt-memory compaction failed: ${errorMessage}`);
|
||||
piLog.error(`promptWithFallback: retry after prompt-memory compaction failed: ${errorMessage}`);
|
||||
return { recovered: false, error: err };
|
||||
}
|
||||
}
|
||||
@@ -257,7 +257,7 @@ async function flushMemoryBeforeSessionCompaction(session: AgentSession): Promis
|
||||
await promptSessionAndCheck(session, flushPrompt);
|
||||
} catch (err: unknown) {
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
console.error(`[pi] promptWithFallback: memory flush before compaction skipped: ${errorMessage}`);
|
||||
piLog.warn(`promptWithFallback: memory flush before compaction skipped: ${errorMessage}`);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -357,7 +357,7 @@ function resolveConfiguredModel(
|
||||
const providerModels = modelRegistry.getAll().filter((m) => m.provider === provider);
|
||||
if (providerModels.length > 0) {
|
||||
const baseModel = providerModels[0]!;
|
||||
console.error(`[pi] ${kind} model ${provider}/${modelId} not in registry; using provider base model as template`);
|
||||
piLog.warn(`${kind} model ${provider}/${modelId} not in registry; using provider base model as template`);
|
||||
return { ...baseModel, id: modelId, name: modelId };
|
||||
}
|
||||
|
||||
@@ -476,7 +476,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
|
||||
);
|
||||
|
||||
for (const { path, error } of extensionsResult.errors) {
|
||||
console.error(`[extensions] Failed to load ${path}: ${error}`);
|
||||
extensionsLog.warn(`Failed to load ${path}: ${error}`);
|
||||
}
|
||||
|
||||
for (const { name, config, extensionPath } of extensionsResult.runtime.pendingProviderRegistrations) {
|
||||
@@ -484,7 +484,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
|
||||
modelRegistry.registerProvider(name, config);
|
||||
} catch (error) {
|
||||
const message = error instanceof Error ? error.message : String(error);
|
||||
console.error(`[extensions] Failed to register provider from ${extensionPath}: ${message}`);
|
||||
extensionsLog.warn(`Failed to register provider from ${extensionPath}: ${message}`);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -492,7 +492,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
|
||||
modelRegistry.refresh();
|
||||
} catch (error) {
|
||||
const message = error instanceof Error ? error.message : String(error);
|
||||
console.error(`[extensions] Failed to discover extensions: ${message}`);
|
||||
extensionsLog.error(`Failed to discover extensions: ${message}`);
|
||||
createExtensionRuntime();
|
||||
modelRegistry.refresh();
|
||||
}
|
||||
@@ -668,7 +668,7 @@ export function wrapToolsWithBoundary(
|
||||
* Reuses the user's existing pi auth and model configuration.
|
||||
*/
|
||||
export async function createKbAgent(options: AgentOptions): Promise<AgentResult> {
|
||||
console.error(`[pi] createKbAgent called (cwd=${options.cwd}, tools=${options.tools}, provider=${options.defaultProvider}, model=${options.defaultModelId})`);
|
||||
piLog.log(`createKbAgent called (cwd=${options.cwd}, tools=${options.tools}, provider=${options.defaultProvider}, model=${options.defaultModelId})`);
|
||||
const authStorage = createFusionAuthStorage();
|
||||
const modelRegistry = new ModelRegistry(authStorage, getModelRegistryModelsPath());
|
||||
await registerExtensionProviders(options.cwd, modelRegistry);
|
||||
@@ -713,7 +713,7 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
|
||||
// Resolve skill selection: explicit skillSelection wins over convenience `skills`
|
||||
let effectiveSkillSelection: SkillSelectionContext | undefined = options.skillSelection;
|
||||
if (!effectiveSkillSelection && options.skills && options.skills.length > 0) {
|
||||
console.error(`[pi] Using skills from convenience parameter: [${options.skills.join(", ")}]`);
|
||||
piLog.log(`Using skills from convenience parameter: [${options.skills.join(", ")}]`);
|
||||
effectiveSkillSelection = {
|
||||
projectRootDir: options.cwd,
|
||||
requestedSkillNames: options.skills,
|
||||
@@ -728,7 +728,7 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
|
||||
if (selectionResult.diagnostics.length > 0) {
|
||||
const purpose = effectiveSkillSelection.sessionPurpose ?? "skills";
|
||||
for (const diag of selectionResult.diagnostics) {
|
||||
console.error(`[pi] [skills] [${purpose}] ${diag.type}: ${diag.message}`);
|
||||
piLog.warn(`[skills] [${purpose}] ${diag.type}: ${diag.message}`);
|
||||
}
|
||||
}
|
||||
skillsOverrideFn = createSkillsOverrideFromSelection(selectionResult, {
|
||||
@@ -766,16 +766,16 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
|
||||
let usingFallback = false;
|
||||
try {
|
||||
sessionResult = await createSessionWithModel(selectedModel);
|
||||
console.error(`[pi] Session created successfully (model=${selectedModel ? `${selectedModel.provider}/${selectedModel.id}` : "default"})`);
|
||||
piLog.log(`Session created successfully (model=${selectedModel ? `${selectedModel.provider}/${selectedModel.id}` : "default"})`);
|
||||
} catch (err: any) {
|
||||
if (!fallbackModel || !selectedModel || !isRetryableModelSelectionError(err?.message || "")) {
|
||||
console.error(`[pi] Session creation failed: ${err.message}`);
|
||||
piLog.error(`Session creation failed: ${err.message}`);
|
||||
throw err;
|
||||
}
|
||||
console.error(`[pi] Primary model failed (${err.message}), trying fallback`);
|
||||
piLog.warn(`Primary model failed (${err.message}), trying fallback`);
|
||||
usingFallback = true;
|
||||
sessionResult = await createSessionWithModel(fallbackModel);
|
||||
console.error(`[pi] Fallback session created successfully`);
|
||||
piLog.log("Fallback session created successfully");
|
||||
}
|
||||
|
||||
const { session } = sessionResult;
|
||||
@@ -801,22 +801,22 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
|
||||
}
|
||||
}
|
||||
|
||||
console.error(`[pi] promptWithFallback: context limit error — attempting auto-compaction`);
|
||||
piLog.warn("promptWithFallback: context limit error — attempting auto-compaction");
|
||||
await flushMemoryBeforeSessionCompaction(session);
|
||||
const compactResult = await compactSessionContext(session);
|
||||
if (compactResult) {
|
||||
console.error(`[pi] promptWithFallback: compaction succeeded (${compactResult.tokensBefore} tokens) — retrying prompt`);
|
||||
piLog.log(`promptWithFallback: compaction succeeded (${compactResult.tokensBefore} tokens) — retrying prompt`);
|
||||
try {
|
||||
await promptSessionAndCheck(session, prompt, promptOptions);
|
||||
return;
|
||||
} catch (retryErr: any) {
|
||||
const retryErrorMessage = retryErr?.message || "";
|
||||
console.error(`[pi] promptWithFallback: retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
piLog.error(`promptWithFallback: retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
// Throw original error to preserve original context
|
||||
throw err;
|
||||
}
|
||||
} else {
|
||||
console.error(`[pi] promptWithFallback: compaction unavailable — propagating original error`);
|
||||
piLog.error("promptWithFallback: compaction unavailable — propagating original error");
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
@@ -880,21 +880,21 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
|
||||
}
|
||||
}
|
||||
|
||||
console.error(`[pi] promptWithFallback: fallback session context limit error — attempting auto-compaction`);
|
||||
piLog.warn("promptWithFallback: fallback session context limit error — attempting auto-compaction");
|
||||
await flushMemoryBeforeSessionCompaction(fallbackSession);
|
||||
const compactResult = await compactSessionContext(fallbackSession);
|
||||
if (compactResult) {
|
||||
console.error(`[pi] promptWithFallback: fallback compaction succeeded (${compactResult.tokensBefore} tokens) — retrying`);
|
||||
piLog.log(`promptWithFallback: fallback compaction succeeded (${compactResult.tokensBefore} tokens) — retrying`);
|
||||
try {
|
||||
await promptSessionAndCheck(fallbackSession, prompt, promptOptions);
|
||||
return;
|
||||
} catch (retryErr: any) {
|
||||
const retryErrorMessage = retryErr?.message || "";
|
||||
console.error(`[pi] promptWithFallback: fallback retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
piLog.error(`promptWithFallback: fallback retry after auto-compaction failed: ${retryErrorMessage}`);
|
||||
throw fallbackErr; // Throw original fallback error
|
||||
}
|
||||
} else {
|
||||
console.error(`[pi] promptWithFallback: fallback compaction unavailable — propagating original error`);
|
||||
piLog.error("promptWithFallback: fallback compaction unavailable — propagating original error");
|
||||
throw fallbackErr;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -3,6 +3,19 @@
|
||||
*/
|
||||
|
||||
import { beforeEach, describe, expect, it, vi } from "vitest";
|
||||
|
||||
const { mockPiLog } = vi.hoisted(() => ({
|
||||
mockPiLog: {
|
||||
log: vi.fn(),
|
||||
warn: vi.fn(),
|
||||
error: vi.fn(),
|
||||
},
|
||||
}));
|
||||
|
||||
vi.mock("./logger.js", () => ({
|
||||
piLog: mockPiLog,
|
||||
}));
|
||||
|
||||
import {
|
||||
resolveSessionSkills,
|
||||
createSkillsOverrideFromSelection,
|
||||
@@ -385,6 +398,12 @@ describe("resolveSessionSkills", () => {
|
||||
});
|
||||
|
||||
describe("createSkillsOverrideFromSelection", () => {
|
||||
beforeEach(() => {
|
||||
mockPiLog.log.mockClear();
|
||||
mockPiLog.warn.mockClear();
|
||||
mockPiLog.error.mockClear();
|
||||
});
|
||||
|
||||
describe("with filterActive: false", () => {
|
||||
it("returns base unchanged", () => {
|
||||
const selection: SkillSelectionResult = {
|
||||
@@ -510,9 +529,7 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
expect(result.diagnostics[0].message).toBe("base warning");
|
||||
});
|
||||
|
||||
it("logs diagnostics via console.error", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
it("logs diagnostics via structured logger", () => {
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set(["/path/nonexistent"]),
|
||||
excludedSkillPaths: new Set<string>(),
|
||||
@@ -531,17 +548,13 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
|
||||
override(base);
|
||||
|
||||
expect(consoleErrorSpy).toHaveBeenCalled();
|
||||
const lastCall = consoleErrorSpy.mock.calls[consoleErrorSpy.mock.calls.length - 1][0] as string;
|
||||
expect(lastCall).toContain("[pi] [skills]");
|
||||
expect(mockPiLog.warn).toHaveBeenCalled();
|
||||
const lastCall = mockPiLog.warn.mock.calls[mockPiLog.warn.mock.calls.length - 1][0] as string;
|
||||
expect(lastCall).toContain("[skills]");
|
||||
expect(lastCall).toContain("nonexistent");
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("includes sessionPurpose in log messages when provided", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
it("includes sessionPurpose in structured logger messages when provided", () => {
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set(["/path/foo"]),
|
||||
excludedSkillPaths: new Set<string>(),
|
||||
@@ -563,16 +576,12 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
|
||||
override(base);
|
||||
|
||||
const lastCall = consoleErrorSpy.mock.calls[consoleErrorSpy.mock.calls.length - 1][0] as string;
|
||||
const lastCall = mockPiLog.warn.mock.calls[mockPiLog.warn.mock.calls.length - 1][0] as string;
|
||||
expect(lastCall).toContain("[reviewer]");
|
||||
expect(lastCall).toContain("missing-skill");
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("produces warning diagnostic for disabled skills (exists but excluded by patterns)", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
// Simulate a skill that exists but was disabled by project exclusion pattern
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set<string>(),
|
||||
@@ -605,11 +614,9 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
expect(result.diagnostics[0].message).toContain("disabled-skill");
|
||||
|
||||
// Verify logging
|
||||
expect(consoleErrorSpy).toHaveBeenCalled();
|
||||
const lastCall = consoleErrorSpy.mock.calls[consoleErrorSpy.mock.calls.length - 1][0] as string;
|
||||
expect(mockPiLog.warn).toHaveBeenCalled();
|
||||
const lastCall = mockPiLog.warn.mock.calls[mockPiLog.warn.mock.calls.length - 1][0] as string;
|
||||
expect(lastCall).toContain("disabled");
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
});
|
||||
|
||||
it("distinguishes missing skills (not found) from disabled skills (excluded) via message content", () => {
|
||||
@@ -698,8 +705,6 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
});
|
||||
|
||||
it("filters discovered Skill[] by requested names and logs warnings for missing skills", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
|
||||
// Create selection with empty allowed paths (only requested names filtering)
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set<string>(),
|
||||
@@ -733,13 +738,58 @@ describe("createSkillsOverrideFromSelection", () => {
|
||||
);
|
||||
expect(missingWarning).toBeDefined();
|
||||
|
||||
// Verify console.error logging
|
||||
expect(consoleErrorSpy).toHaveBeenCalled();
|
||||
const loggedMessages = consoleErrorSpy.mock.calls.map(c => c[0] as string);
|
||||
// Verify structured logger warning output
|
||||
expect(mockPiLog.warn).toHaveBeenCalled();
|
||||
const loggedMessages = mockPiLog.warn.mock.calls.map(c => c[0] as string);
|
||||
const hasExecutorPrefix = loggedMessages.some(m => m.includes("[executor]") && m.includes("missing-skill"));
|
||||
expect(hasExecutorPrefix).toBe(true);
|
||||
});
|
||||
|
||||
it("uses structured piLog.warn for skill override diagnostics", () => {
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set(["/path/ghost"]),
|
||||
excludedSkillPaths: new Set<string>(),
|
||||
diagnostics: [],
|
||||
filterActive: true,
|
||||
};
|
||||
|
||||
const override = createSkillsOverrideFromSelection(selection, {
|
||||
sessionPurpose: "executor",
|
||||
});
|
||||
|
||||
override({ skills: [], diagnostics: [] });
|
||||
|
||||
expect(mockPiLog.warn).toHaveBeenCalledWith(
|
||||
expect.stringContaining("[skills] warning: Configured skill pattern '/path/ghost' not found in discovered skills [executor]"),
|
||||
);
|
||||
});
|
||||
|
||||
it("does not call console.error, console.warn, or console.log for diagnostics", () => {
|
||||
const consoleErrorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
|
||||
const consoleWarnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
|
||||
const consoleLogSpy = vi.spyOn(console, "log").mockImplementation(() => {});
|
||||
|
||||
const selection: SkillSelectionResult = {
|
||||
allowedSkillPaths: new Set(["/path/missing"]),
|
||||
excludedSkillPaths: new Set<string>(),
|
||||
diagnostics: [],
|
||||
filterActive: true,
|
||||
};
|
||||
|
||||
const override = createSkillsOverrideFromSelection(selection, {
|
||||
sessionPurpose: "executor",
|
||||
});
|
||||
|
||||
override({ skills: [], diagnostics: [] });
|
||||
|
||||
expect(mockPiLog.warn).toHaveBeenCalled();
|
||||
expect(consoleErrorSpy).not.toHaveBeenCalled();
|
||||
expect(consoleWarnSpy).not.toHaveBeenCalled();
|
||||
expect(consoleLogSpy).not.toHaveBeenCalled();
|
||||
|
||||
consoleErrorSpy.mockRestore();
|
||||
consoleWarnSpy.mockRestore();
|
||||
consoleLogSpy.mockRestore();
|
||||
});
|
||||
});
|
||||
|
||||
|
||||
@@ -12,6 +12,7 @@
|
||||
import { existsSync, readFileSync } from "node:fs";
|
||||
import { join } from "node:path";
|
||||
import type { ResourceDiagnostic, Skill } from "@mariozechner/pi-coding-agent";
|
||||
import { piLog } from "./logger.js";
|
||||
|
||||
// ── Types ───────────────────────────────────────────────────────────────────
|
||||
|
||||
@@ -387,7 +388,7 @@ export function createSkillsOverrideFromSelection(
|
||||
if (newDiagnostics.length > 0) {
|
||||
const _purpose = sessionPurpose ? `[${sessionPurpose}]` : "skills";
|
||||
for (const diag of newDiagnostics) {
|
||||
console.error(`[pi] [skills] ${diag.type}: ${diag.message}`);
|
||||
piLog.warn(`[skills] ${diag.type}: ${diag.message}`);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user