From d0ea9667ee6d5d99aab81932bcba697451849566 Mon Sep 17 00:00:00 2001 From: Rajvardhan Patil Date: Tue, 12 May 2026 18:08:14 +0530 Subject: [PATCH] fix: add cli turn output digests --- ...cli-runner.before-agent-reply-cron.test.ts | 61 ++++++++++++------- src/agents/cli-runner.spawn.test.ts | 16 +++++ src/agents/cli-runner.ts | 9 ++- src/agents/cli-runner/claude-live-session.ts | 4 +- src/agents/cli-runner/log.ts | 7 +++ 5 files changed, 70 insertions(+), 27 deletions(-) diff --git a/src/agents/cli-runner.before-agent-reply-cron.test.ts b/src/agents/cli-runner.before-agent-reply-cron.test.ts index 41c9fda1285..c2d5239c5d6 100644 --- a/src/agents/cli-runner.before-agent-reply-cron.test.ts +++ b/src/agents/cli-runner.before-agent-reply-cron.test.ts @@ -1,5 +1,6 @@ import { afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; import { SILENT_REPLY_TOKEN } from "../auto-reply/tokens.js"; +import { cliBackendLog } from "./cli-runner/log.js"; // vi.mock factories are hoisted above imports, so any references inside them // must come from vi.hoisted() so they exist at hoist time (otherwise they'd @@ -114,6 +115,7 @@ afterEach(() => { describe("runCliAgent cron before_agent_reply seam", () => { it("lets before_agent_reply claim cron runs before the CLI subprocess is invoked", async () => { + const logInfoSpy = vi.spyOn(cliBackendLog, "info").mockImplementation(() => undefined); hasHooksMock.mockImplementation((hookName) => hookName === "before_agent_reply"); runBeforeAgentReplyMock.mockResolvedValue({ handled: true, @@ -121,30 +123,43 @@ describe("runCliAgent cron before_agent_reply seam", () => { }); const onExecutionPhase = vi.fn(); - const result = await runCliAgent({ - ...baseRunParams, - trigger: "cron", - jobId: "cron-job-123", - onExecutionPhase, - }); + try { + const result = await runCliAgent({ + ...baseRunParams, + trigger: "cron", + jobId: "cron-job-123", + onExecutionPhase, + }); - expect(runBeforeAgentReplyMock).toHaveBeenCalledTimes(1); - expect(onExecutionPhase).toHaveBeenCalledWith({ - phase: "before_agent_reply", - provider: baseRunParams.provider, - model: baseRunParams.model, - }); - const [event, context] = runBeforeAgentReplyMock.mock.calls.at(0) ?? []; - expect(event).toEqual({ cleanedBody: baseRunParams.prompt }); - const hookContext = context as Record | undefined; - expect(hookContext?.jobId).toBe("cron-job-123"); - expect(hookContext?.agentId).toBe(baseRunParams.agentId); - expect(hookContext?.sessionId).toBe(baseRunParams.sessionId); - expect(hookContext?.sessionKey).toBe(baseRunParams.sessionKey); - expect(hookContext?.workspaceDir).toBe(baseRunParams.workspaceDir); - expect(hookContext?.trigger).toBe("cron"); - expect(executePreparedCliRunMock).not.toHaveBeenCalled(); - expect(result.payloads?.[0]?.text).toBe("dreaming claimed via cli runner"); + expect(runBeforeAgentReplyMock).toHaveBeenCalledTimes(1); + expect(onExecutionPhase).toHaveBeenCalledWith({ + phase: "before_agent_reply", + provider: baseRunParams.provider, + model: baseRunParams.model, + }); + const [event, context] = runBeforeAgentReplyMock.mock.calls.at(0) ?? []; + expect(event).toEqual({ cleanedBody: baseRunParams.prompt }); + const hookContext = context as Record | undefined; + expect(hookContext?.jobId).toBe("cron-job-123"); + expect(hookContext?.agentId).toBe(baseRunParams.agentId); + expect(hookContext?.sessionId).toBe(baseRunParams.sessionId); + expect(hookContext?.sessionKey).toBe(baseRunParams.sessionKey); + expect(hookContext?.workspaceDir).toBe(baseRunParams.workspaceDir); + expect(hookContext?.trigger).toBe("cron"); + expect(executePreparedCliRunMock).not.toHaveBeenCalled(); + expect(result.payloads?.[0]?.text).toBe("dreaming claimed via cli runner"); + + const syntheticTurnLog = logInfoSpy.mock.calls + .map(([message]) => message) + .find((message) => message.startsWith("cli synthetic turn:")); + expect(syntheticTurnLog).toContain("provider=codex-cli"); + expect(syntheticTurnLog).toContain("model="); + expect(syntheticTurnLog).toContain("requestedModel=gpt-5.5"); + expect(syntheticTurnLog).toContain("outBytes=31 outHash=96317e453543"); + expect(syntheticTurnLog).not.toContain("dreaming claimed via cli runner"); + } finally { + logInfoSpy.mockRestore(); + } }); it("does not run prepareCliRunContext when the cron hook claims (no resource allocation, no leak)", async () => { diff --git a/src/agents/cli-runner.spawn.test.ts b/src/agents/cli-runner.spawn.test.ts index aef89e23ae9..8b10d44c4af 100644 --- a/src/agents/cli-runner.spawn.test.ts +++ b/src/agents/cli-runner.spawn.test.ts @@ -39,6 +39,7 @@ import { executePreparedCliRun, } from "./cli-runner/execute.js"; import { buildSystemPrompt } from "./cli-runner/helpers.js"; +import { cliBackendLog, formatCliBackendOutputDigest } from "./cli-runner/log.js"; import { setCliRunnerPrepareTestDeps } from "./cli-runner/prepare.js"; import type { PreparedCliRunContext } from "./cli-runner/types.js"; import { createClaudeApiErrorFixture } from "./test-helpers/claude-api-error-fixture.js"; @@ -261,6 +262,11 @@ async function withTempOpenClawHome(run: (home: string) => Promise): Promi } describe("runCliAgent spawn path", () => { + it("formats output digests without logging response content", () => { + expect(formatCliBackendOutputDigest("one")).toBe("outBytes=3 outHash=7692c3ad3540"); + expect(formatCliBackendOutputDigest("∑")).toBe("outBytes=3 outHash=be27c7179a61"); + }); + it("formats redacted CLI resume diagnostics without exposing raw session ids", () => { const logLine = buildCliExecLogLine({ provider: "claude-cli", @@ -890,6 +896,7 @@ describe("runCliAgent spawn path", () => { }); it("reuses a Claude live session process across turns", async () => { + const logInfoSpy = vi.spyOn(cliBackendLog, "info").mockImplementation(() => undefined); const agentEvents: unknown[] = []; const stop = onAgentEvent((evt) => { if (evt.stream === "assistant") { @@ -988,7 +995,16 @@ describe("runCliAgent spawn path", () => { { text: "one", delta: "one" }, { text: "two", delta: "two" }, ]); + const turnLogs = logInfoSpy.mock.calls + .map(([message]) => message) + .filter((message) => message.startsWith("claude live session turn:")); + expect(turnLogs).toHaveLength(2); + expect(turnLogs[0]).toContain("outBytes=3 outHash=7692c3ad3540"); + expect(turnLogs[1]).toContain("outBytes=3 outHash=3fc4ccfe7458"); + expect(turnLogs.join("\n")).not.toContain("one"); + expect(turnLogs.join("\n")).not.toContain("two"); } finally { + logInfoSpy.mockRestore(); stop(); } }); diff --git a/src/agents/cli-runner.ts b/src/agents/cli-runner.ts index bb189d8f6be..2a6d16be93b 100644 --- a/src/agents/cli-runner.ts +++ b/src/agents/cli-runner.ts @@ -5,6 +5,7 @@ import { createSubsystemLogger } from "../logging/subsystem.js"; import { buildAgentHookContextChannelFields } from "../plugins/hook-agent-context.js"; import { resolveBlockMessage } from "../plugins/hook-decision-types.js"; import { getGlobalHookRunner } from "../plugins/hook-runner-global.js"; +import { cliBackendLog, formatCliBackendOutputDigest } from "./cli-runner/log.js"; import { loadCliSessionContextEngineMessages, loadCliSessionHistoryMessages, @@ -238,6 +239,10 @@ export async function runCliAgent(params: RunCliAgentParams): Promise requestedModel=${params.model ?? ""} durationMs=${Date.now() - startedAt} ${formatCliBackendOutputDigest(finalText)}`, + ); return { payloads: buildHandledReplyPayloads(hookResult.reply), meta: { @@ -247,8 +252,8 @@ export async function runCliAgent(params: RunCliAgentParams): Promise