root/fusion
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix: suppress execution output on stdout

Browse Source
This commit is contained in:
gsxdsm
2026-04-11 21:13:16 -07:00
parent 4625b6ea87
commit d423dfcff6
9 changed files with 89 additions and 53 deletions
Download Patch File Download Diff File Expand all files Collapse all files

3
packages/engine/src/executor.test.ts
View File

@@ -6627,10 +6627,13 @@ describe("Workflow Steps Execution", () => {
workflowStepId: "WS-001",
workflowStepName: "Run Tests",
status: "passed",
output: "Script 'test' completed successfully",
}),
]),
}),
);
const updatePayloads = store.updateTask.mock.calls.map((call: any[]) => call[1]);
expect(JSON.stringify(updatePayloads)).not.toContain("all tests passed");
});
it("fails task when script-mode workflow step exits non-zero", async () => {

17
packages/engine/src/executor.ts
View File

@@ -55,6 +55,12 @@ const STEP_STATUSES: StepStatus[] = ["pending", "in-progress", "done", "skipped"
/** Maximum retry attempts for workflow step hard failures before giving up */
const MAX_WORKFLOW_STEP_RETRIES = 3;
const WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS = 4_000;
function truncateWorkflowScriptOutput(output: string): string {
if (output.length <= WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS) return output;
return `... output truncated to last ${WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS} characters ...\n${output.slice(-WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS)}`;
}
// ── Tool parameter schemas (module-level for reuse in ToolDefinition generics) ──
@@ -2804,7 +2810,7 @@ ${failureFeedback}
`[pre-merge] Workflow step failed: ${ws.name}`,
result.error || "Unknown error",
);
executorLog.error(`${task.id} — [pre-merge] workflow step failed: ${ws.name} — ${result.error}`);
executorLog.error(`${task.id} — [pre-merge] workflow step failed: ${ws.name}; output captured in task log`);
results.push({
workflowStepId: ws.id,
workflowStepName: ws.name,
@@ -2878,20 +2884,19 @@ ${failureFeedback}
try {
// Non-blocking: async exec so the executor event loop keeps running
// while the user-configured workflow script executes.
const { stdout: out } = await execAsync(scriptCommand, {
await execAsync(scriptCommand, {
cwd: worktreePath,
timeout: 120_000,
});
const stdout = out.toString().trim();
return { success: true, output: stdout || `Script '${scriptName}' completed successfully` };
return { success: true, output: `Script '${scriptName}' completed successfully` };
} catch (err: any) {
const stderr = err.stderr?.toString()?.trim() || "";
const stdout = err.stdout?.toString()?.trim() || "";
const exitCode = err.code ?? err.status;
const parts: string[] = [];
if (exitCode !== undefined) parts.push(`Exit code: ${exitCode}`);
if (stdout) parts.push(`stdout: ${stdout}`);
if (stderr) parts.push(`stderr: ${stderr}`);
if (stdout) parts.push(`stdout: ${truncateWorkflowScriptOutput(stdout)}`);
if (stderr) parts.push(`stderr: ${truncateWorkflowScriptOutput(stderr)}`);
if (!parts.length) parts.push(err.message || "Unknown error");
const errorOutput = parts.join("\n");
return { success: false, error: errorOutput };

25
packages/engine/src/logger.test.ts
View File

@@ -27,10 +27,11 @@ describe("createLogger", () => {
errorSpy.mockRestore();
});
it("formats log output as [prefix] message", () => {
it("formats log output as [prefix] message on stderr", () => {
const logger = createLogger("test");
logger.log("hello world");
expect(logSpy).toHaveBeenCalledWith("[test] hello world");
expect(logSpy).not.toHaveBeenCalled();
expect(errorSpy).toHaveBeenCalledWith("[test] hello world");
});
it("formats warn output as [prefix] message", () => {
@@ -52,36 +53,36 @@ describe("createLogger", () => {
expect(errorSpy).toHaveBeenCalledWith("[test] failed:", err);
});
it("delegates log to console.log, warn to console.warn, error to console.error", () => {
it("keeps log output off stdout", () => {
const logger = createLogger("x");
logger.log("a");
logger.warn("b");
logger.error("c");
expect(logSpy).toHaveBeenCalledTimes(1);
expect(logSpy).not.toHaveBeenCalled();
expect(warnSpy).toHaveBeenCalledTimes(1);
expect(errorSpy).toHaveBeenCalledTimes(1);
expect(errorSpy).toHaveBeenCalledTimes(2);
});
it("pre-built instances use correct prefixes", () => {
schedulerLog.log("tick");
expect(logSpy).toHaveBeenCalledWith("[scheduler] tick");
expect(errorSpy).toHaveBeenCalledWith("[scheduler] tick");
executorLog.log("run");
expect(logSpy).toHaveBeenCalledWith("[executor] run");
expect(errorSpy).toHaveBeenCalledWith("[executor] run");
triageLog.log("spec");
expect(logSpy).toHaveBeenCalledWith("[triage] spec");
expect(errorSpy).toHaveBeenCalledWith("[triage] spec");
mergerLog.log("merge");
expect(logSpy).toHaveBeenCalledWith("[merger] merge");
expect(errorSpy).toHaveBeenCalledWith("[merger] merge");
worktreePoolLog.log("prune");
expect(logSpy).toHaveBeenCalledWith("[worktree-pool] prune");
expect(errorSpy).toHaveBeenCalledWith("[worktree-pool] prune");
reviewerLog.log("review");
expect(logSpy).toHaveBeenCalledWith("[reviewer] review");
expect(errorSpy).toHaveBeenCalledWith("[reviewer] review");
remoteNodeLog.log("stream");
expect(logSpy).toHaveBeenCalledWith("[remote-node] stream");
expect(errorSpy).toHaveBeenCalledWith("[remote-node] stream");
});
});

9
packages/engine/src/logger.ts
View File

@@ -5,7 +5,7 @@
* ```ts
* import { createLogger } from "./logger.js";
* const log = createLogger("my-module");
* log.log("hello"); // → console.log("[my-module] hello")
* log.log("hello"); // → console.error("[my-module] hello")
* log.warn("oops"); // → console.warn("[my-module] oops")
* log.error("fail"); // → console.error("[my-module] fail")
* ```
@@ -26,14 +26,15 @@ export interface Logger {
* Create a structured logger that prefixes every message with `[prefix]`.
*
* @param prefix - Short subsystem name, e.g. `"scheduler"` or `"executor"`.
* @returns A `Logger` whose `log`, `warn`, and `error` methods delegate to
* the corresponding `console` method with the prefix prepended.
* @returns A `Logger` whose output is prefixed and sent to stderr. Keeping
* engine logs off stdout prevents command/test output consumers from
* receiving Fusion execution chatter.
*/
export function createLogger(prefix: string): Logger {
const tag = `[${prefix}]`;
return {
log(message: string, ...args: unknown[]) {
console.log(`${tag} ${message}`, ...args);
console.error(`${tag} ${message}`, ...args);
},
warn(message: string, ...args: unknown[]) {
console.warn(`${tag} ${message}`, ...args);

26
packages/engine/src/merger.test.ts
View File

@@ -2130,6 +2130,7 @@ describe("aiMergeTask — deterministic merge verification", () => {
});
it("fails merge when testCommand fails and does not move task to done", async () => {
const errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
mockedExecSync.mockImplementation((cmd: any) => {
const cmdStr = String(cmd);
if (cmdStr.includes("rev-parse --verify")) return Buffer.from("abc123");
@@ -2169,9 +2170,15 @@ describe("aiMergeTask — deterministic merge verification", () => {
testCommand: "vitest run",
});
await expect(aiMergeTask(store, "/tmp/root", "FN-050")).rejects.toThrow(
"Deterministic test verification failed",
);
try {
await expect(aiMergeTask(store, "/tmp/root", "FN-050")).rejects.toThrow(
"Deterministic test verification failed",
);
const consoleErrors = errorSpy.mock.calls.flat().join("\n");
expect(consoleErrors).not.toContain("FAIL: some test failed");
} finally {
errorSpy.mockRestore();
}
// Verify task was NOT moved to done
expect(store.moveTask).not.toHaveBeenCalled();
@@ -2235,6 +2242,7 @@ describe("aiMergeTask — deterministic merge verification", () => {
});
it("fails merge when buildCommand fails and does not move task to done", async () => {
const errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
// Setup exec mock that will be updated after agent commits
mockedExecSync.mockImplementation((cmd: any) => {
const cmdStr = String(cmd);
@@ -2293,9 +2301,15 @@ describe("aiMergeTask — deterministic merge verification", () => {
buildCommand: "pnpm build",
});
await expect(aiMergeTask(store, "/tmp/root", "FN-050")).rejects.toThrow(
"Deterministic build verification failed",
);
try {
await expect(aiMergeTask(store, "/tmp/root", "FN-050")).rejects.toThrow(
"Deterministic build verification failed",
);
const consoleErrors = errorSpy.mock.calls.flat().join("\n");
expect(consoleErrors).not.toContain("Type error in src/utils.ts");
} finally {
errorSpy.mockRestore();
}
// Verify task was NOT moved to done
expect(store.moveTask).not.toHaveBeenCalled();

25
packages/engine/src/merger.ts
View File

@@ -68,6 +68,7 @@ const DEPENDENCY_SYNC_TRIGGER_PATTERNS = [
const VERIFICATION_COMMAND_MAX_BUFFER = 50 * 1024 * 1024;
const VERIFICATION_LOG_MAX_CHARS = 20_000;
const WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS = 4_000;
/** Maximum characters for commit log in merge prompt — prevents context overflow on large branches */
const MERGE_COMMIT_LOG_MAX_CHARS = 5000;
@@ -89,6 +90,11 @@ function truncateVerificationOutput(output: string): string {
return `... output truncated to last ${VERIFICATION_LOG_MAX_CHARS} characters ...\n${output.slice(-VERIFICATION_LOG_MAX_CHARS)}`;
}
function truncateWorkflowScriptOutput(output: string): string {
if (output.length <= WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS) return output;
return `... output truncated to last ${WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS} characters ...\n${output.slice(-WORKFLOW_SCRIPT_OUTPUT_MAX_CHARS)}`;
}
/** Check if a path matches a glob pattern (simple glob support: * and **) */
function matchGlob(path: string, pattern: string): boolean {
// Handle ** which matches across directory boundaries (must do before single *)
@@ -360,9 +366,10 @@ async function runVerificationCommand(
return result;
}
// Build a useful error summary
// Keep command output out of process logs. The bounded excerpt is stored on
// the task for diagnostics without dumping test output to the engine stdout.
const summary = truncateVerificationOutput(result.stderr || result.stdout || error.message || "Unknown error");
mergerLog.error(`${taskId}: ${type} command failed (exit ${result.exitCode}): ${summary.trim()}`);
mergerLog.error(`${taskId}: ${type} command failed (exit ${result.exitCode}); output captured in task log`);
await store.logEntry(
taskId,
`[verification] ${type} command failed (exit ${result.exitCode}): ${summary.trim()}`,
@@ -2072,7 +2079,7 @@ async function runPostMergeWorkflowSteps(
} else {
// Post-merge failures are logged but do NOT block task completion
await store.logEntry(taskId, `[post-merge] Workflow step failed: ${ws.name}`, result.error || "Unknown error");
mergerLog.error(`${taskId}: [post-merge] workflow step failed: ${ws.name} — ${result.error}`);
mergerLog.error(`${taskId}: [post-merge] workflow step failed: ${ws.name}; output captured in task log`);
existingResults.push({
workflowStepId: ws.id,
workflowStepName: ws.name,
@@ -2120,21 +2127,21 @@ async function executePostMergeScriptStep(
}
try {
const output = execSync(scriptCommand, {
await execAsync(scriptCommand, {
cwd: rootDir,
encoding: "utf-8",
timeout: 120_000,
stdio: ["pipe", "pipe", "pipe"],
maxBuffer: 10 * 1024 * 1024,
});
return { success: true, output: output.trim() };
return { success: true, output: `Script '${scriptName}' completed successfully` };
} catch (err: any) {
const stderr = err.stderr?.toString()?.trim() || "";
const stdout = err.stdout?.toString()?.trim() || "";
const exitCode = err.status;
const exitCode = err.code ?? err.status;
const parts: string[] = [];
if (exitCode !== undefined) parts.push(`Exit code: ${exitCode}`);
if (stdout) parts.push(`stdout: ${stdout}`);
if (stderr) parts.push(`stderr: ${stderr}`);
if (stdout) parts.push(`stdout: ${truncateWorkflowScriptOutput(stdout)}`);
if (stderr) parts.push(`stderr: ${truncateWorkflowScriptOutput(stderr)}`);
if (!parts.length) parts.push(err.message || "Unknown error");
return { success: false, error: parts.join("\n") };
}

8
packages/engine/src/node-health-monitor.test.ts
View File

@@ -23,13 +23,13 @@ describe("NodeHealthMonitor", () => {
let checkNodeHealthMock: ReturnType<typeof vi.fn>;
let monitor: NodeHealthMonitor;
let warnSpy: ReturnType<typeof vi.spyOn>;
let logSpy: ReturnType<typeof vi.spyOn>;
let errorSpy: ReturnType<typeof vi.spyOn>;
beforeEach(() => {
vi.useFakeTimers();
warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
logSpy = vi.spyOn(console, "log").mockImplementation(() => {});
errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
listNodesMock = vi.fn().mockResolvedValue([
createNode({ id: "node-local", name: "Local Node", type: "local", status: "online" }),
@@ -49,7 +49,7 @@ describe("NodeHealthMonitor", () => {
await monitor.stop();
vi.useRealTimers();
warnSpy.mockRestore();
logSpy.mockRestore();
errorSpy.mockRestore();
vi.clearAllMocks();
});
@@ -111,7 +111,7 @@ describe("NodeHealthMonitor", () => {
await monitor.checkAllNodes();
await monitor.checkAllNodes();
expect(logSpy).toHaveBeenCalledWith(
expect(errorSpy).toHaveBeenCalledWith(
expect.stringContaining("[node-health-monitor] Remote node Remote Node (node-remote) recovered")
);
expect(monitor.getNodeHealth("node-remote")).toBe("online");

24
packages/engine/src/pi.ts
View File

@@ -38,19 +38,19 @@ export interface PromptableSession extends AgentSession {
export async function promptWithFallback(session: AgentSession, prompt: string, options?: unknown): Promise<void> {
const maybePromptable = session as Partial<PromptableSession>;
if (typeof maybePromptable.promptWithFallback === "function") {
console.log(`[pi] promptWithFallback: delegating to session.promptWithFallback (prompt length=${prompt.length})`);
console.error(`[pi] promptWithFallback: delegating to session.promptWithFallback (prompt length=${prompt.length})`);
await maybePromptable.promptWithFallback(prompt, options);
console.log(`[pi] promptWithFallback: completed`);
console.error(`[pi] promptWithFallback: completed`);
return;
}
console.log(`[pi] promptWithFallback: calling session.prompt (prompt length=${prompt.length})`);
console.error(`[pi] promptWithFallback: calling session.prompt (prompt length=${prompt.length})`);
if (options === undefined) {
await session.prompt(prompt);
} else {
await (session.prompt as any)(prompt, options);
}
console.log(`[pi] promptWithFallback: prompt completed`);
console.error(`[pi] promptWithFallback: prompt completed`);
}
/**
@@ -162,7 +162,7 @@ function resolveConfiguredModel(
const providerModels = modelRegistry.getAll().filter((m) => m.provider === provider);
if (providerModels.length > 0) {
const baseModel = providerModels[0]!;
console.log(`[pi] ${kind} model ${provider}/${modelId} not in registry; using provider base model as template`);
console.error(`[pi] ${kind} model ${provider}/${modelId} not in registry; using provider base model as template`);
return { ...baseModel, id: modelId, name: modelId };
}
@@ -232,7 +232,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
const extensionsResult = await discoverAndLoadExtensions(packageExtensionPaths, cwd, undefined);
for (const { path, error } of extensionsResult.errors) {
console.log(`[extensions] Failed to load ${path}: ${error}`);
console.error(`[extensions] Failed to load ${path}: ${error}`);
}
for (const { name, config, extensionPath } of extensionsResult.runtime.pendingProviderRegistrations) {
@@ -240,7 +240,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
modelRegistry.registerProvider(name, config);
} catch (error) {
const message = error instanceof Error ? error.message : String(error);
console.log(`[extensions] Failed to register provider from ${extensionPath}: ${message}`);
console.error(`[extensions] Failed to register provider from ${extensionPath}: ${message}`);
}
}
@@ -248,7 +248,7 @@ async function registerExtensionProviders(cwd: string, modelRegistry: ModelRegis
modelRegistry.refresh();
} catch (error) {
const message = error instanceof Error ? error.message : String(error);
console.log(`[extensions] Failed to discover extensions: ${message}`);
console.error(`[extensions] Failed to discover extensions: ${message}`);
createExtensionRuntime();
modelRegistry.refresh();
}
@@ -414,7 +414,7 @@ export function wrapToolsWithBoundary(
* Reuses the user's existing pi auth and model configuration.
*/
export async function createKbAgent(options: AgentOptions): Promise<AgentResult> {
console.log(`[pi] createKbAgent called (cwd=${options.cwd}, tools=${options.tools}, provider=${options.defaultProvider}, model=${options.defaultModelId})`);
console.error(`[pi] createKbAgent called (cwd=${options.cwd}, tools=${options.tools}, provider=${options.defaultProvider}, model=${options.defaultModelId})`);
const authStorage = AuthStorage.create();
const modelRegistry = new ModelRegistry(authStorage, join(getAgentDir(), "models.json"));
await registerExtensionProviders(options.cwd, modelRegistry);
@@ -485,16 +485,16 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
let usingFallback = false;
try {
sessionResult = await createSessionWithModel(selectedModel);
console.log(`[pi] Session created successfully (model=${selectedModel ? `${selectedModel.provider}/${selectedModel.id}` : "default"})`);
console.error(`[pi] 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}`);
throw err;
}
console.log(`[pi] Primary model failed (${err.message}), trying fallback`);
console.error(`[pi] Primary model failed (${err.message}), trying fallback`);
usingFallback = true;
sessionResult = await createSessionWithModel(fallbackModel);
console.log(`[pi] Fallback session created successfully`);
console.error(`[pi] Fallback session created successfully`);
}
const { session } = sessionResult;