fix(agents): restore compaction gateway logs

This commit is contained in:
Ruben Cuevas
2026-05-10 11:59:57 -04:00
committed by Peter Steinberger
parent 190d1ce848
commit d88e11acf7
13 changed files with 246 additions and 22 deletions

View File

@@ -24,6 +24,7 @@ Auto-compaction is on by default. It runs when the session nears the context lim
You will see:
- `embedded run auto-compaction start` / `complete` in normal Gateway logs.
- `🧹 Auto-compaction complete` in verbose mode.
- `/status` showing `🧹 Compactions: <count>`.

View File

@@ -376,6 +376,7 @@ You can observe compaction and session state via:
- `/status` (in any chat session)
- `openclaw status` (CLI)
- `openclaw sessions` / `sessions --json`
- Gateway logs (`pnpm gateway:watch` or `openclaw logs --follow`): `embedded run auto-compaction start` + `complete`
- Verbose mode: `🧹 Auto-compaction complete` + compaction count
---

View File

@@ -47,7 +47,7 @@ function createToolHandlerCtx(): ToolHandlerContext {
messagingToolSentTargets: [] as MessagingToolSend[],
successfulCronAdds: 0,
},
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
flushBlockReplyBuffer: vi.fn(),
shouldEmitToolResult: () => false,
shouldEmitToolOutput: () => false,

View File

@@ -10,6 +10,7 @@ import {
} from "./pi-embedded-subscribe.compaction-test-helpers.js";
import {
handleCompactionEnd,
handleCompactionStart,
reconcileSessionStoreCompactionCountAfterSuccess,
} from "./pi-embedded-subscribe.handlers.compaction.js";
import type { EmbeddedPiSubscribeContext } from "./pi-embedded-subscribe.handlers.types.js";
@@ -19,6 +20,7 @@ function createCompactionContext(params: {
sessionKey: string;
agentId?: string;
initialCount: number;
info?: (message: string, meta?: Record<string, unknown>) => void;
}): EmbeddedPiSubscribeContext {
let compactionCount = params.initialCount;
return {
@@ -37,6 +39,7 @@ function createCompactionContext(params: {
} as never,
log: {
debug: vi.fn(),
info: params.info ?? vi.fn(),
warn: vi.fn(),
},
ensureCompactionPromise: vi.fn(),
@@ -103,6 +106,168 @@ describe("reconcileSessionStoreCompactionCountAfterSuccess", () => {
});
});
describe("compaction lifecycle logging", () => {
it("logs lifecycle events at info level for gateway watch visibility", async () => {
const tmp = await fs.mkdtemp(path.join(os.tmpdir(), "openclaw-compaction-log-"));
const storePath = path.join(tmp, "sessions.json");
const sessionKey = "main";
await seedSessionStore({
storePath,
sessionKey,
compactionCount: 0,
});
const info = vi.fn();
const ctx = createCompactionContext({
storePath,
sessionKey,
initialCount: 0,
info,
});
handleCompactionStart(ctx, {
type: "compaction_start",
reason: "threshold",
});
handleCompactionEnd(ctx, {
type: "compaction_end",
reason: "threshold",
result: { kept: 12 },
willRetry: false,
aborted: false,
});
expect(info).toHaveBeenNthCalledWith(
1,
"embedded run auto-compaction start",
expect.objectContaining({
event: "embedded_run_compaction_start",
reason: "threshold",
runId: "run-test",
consoleMessage: "embedded run auto-compaction start: runId=run-test reason=threshold",
}),
);
expect(info).toHaveBeenNthCalledWith(
2,
"embedded run auto-compaction complete",
expect.objectContaining({
event: "embedded_run_compaction_end",
reason: "threshold",
runId: "run-test",
completed: true,
compactionCount: 1,
consoleMessage:
"embedded run auto-compaction complete: runId=run-test reason=threshold compactionCount=1 willRetry=false",
}),
);
});
it("logs manual compaction as incomplete when no result is produced", async () => {
const tmp = await fs.mkdtemp(path.join(os.tmpdir(), "openclaw-compaction-incomplete-log-"));
const storePath = path.join(tmp, "sessions.json");
const sessionKey = "main";
await seedSessionStore({
storePath,
sessionKey,
compactionCount: 0,
});
const info = vi.fn();
const ctx = createCompactionContext({
storePath,
sessionKey,
initialCount: 0,
info,
});
handleCompactionStart(ctx, {
type: "compaction_start",
reason: "manual",
});
handleCompactionEnd(ctx, {
type: "compaction_end",
reason: "manual",
result: undefined,
willRetry: false,
aborted: false,
});
expect(info).toHaveBeenNthCalledWith(
1,
"embedded run manual compaction start",
expect.objectContaining({
event: "embedded_run_compaction_start",
reason: "manual",
runId: "run-test",
consoleMessage: "embedded run manual compaction start: runId=run-test reason=manual",
}),
);
expect(info).toHaveBeenNthCalledWith(
2,
"embedded run manual compaction incomplete",
expect.objectContaining({
event: "embedded_run_compaction_end",
reason: "manual",
runId: "run-test",
completed: false,
aborted: false,
consoleMessage:
"embedded run manual compaction incomplete: runId=run-test reason=manual aborted=false willRetry=false",
}),
);
});
it("defaults legacy synthetic compaction events to threshold logs", async () => {
const tmp = await fs.mkdtemp(path.join(os.tmpdir(), "openclaw-compaction-legacy-log-"));
const storePath = path.join(tmp, "sessions.json");
const sessionKey = "main";
await seedSessionStore({
storePath,
sessionKey,
compactionCount: 0,
});
const info = vi.fn();
const ctx = createCompactionContext({
storePath,
sessionKey,
initialCount: 0,
info,
});
handleCompactionStart(ctx, {
type: "compaction_start",
});
handleCompactionEnd(ctx, {
type: "compaction_end",
result: { kept: 12 },
willRetry: false,
aborted: false,
});
expect(info).toHaveBeenNthCalledWith(
1,
"embedded run auto-compaction start",
expect.objectContaining({
event: "embedded_run_compaction_start",
reason: "threshold",
runId: "run-test",
consoleMessage: "embedded run auto-compaction start: runId=run-test reason=threshold",
}),
);
expect(info).toHaveBeenNthCalledWith(
2,
"embedded run auto-compaction complete",
expect.objectContaining({
event: "embedded_run_compaction_end",
reason: "threshold",
runId: "run-test",
completed: true,
compactionCount: 1,
consoleMessage:
"embedded run auto-compaction complete: runId=run-test reason=threshold compactionCount=1 willRetry=false",
}),
);
});
});
describe("handleCompactionEnd", () => {
it("reconciles the session store after a successful compaction end event", async () => {
const tmp = await fs.mkdtemp(path.join(os.tmpdir(), "openclaw-compaction-handler-"));
@@ -122,10 +287,11 @@ describe("handleCompactionEnd", () => {
handleCompactionEnd(ctx, {
type: "compaction_end",
reason: "threshold",
result: { kept: 12 },
willRetry: false,
aborted: false,
} as never);
});
await waitForCompactionCount({
storePath,

View File

@@ -1,14 +1,48 @@
import type { AgentEvent } from "@earendil-works/pi-agent-core";
import type { AgentSessionEvent } from "@earendil-works/pi-coding-agent";
import { emitAgentEvent } from "../infra/agent-events.js";
import { getGlobalHookRunner } from "../plugins/hook-runner-global.js";
import type { EmbeddedPiSubscribeContext } from "./pi-embedded-subscribe.handlers.types.js";
import { makeZeroUsageSnapshot } from "./usage.js";
export function handleCompactionStart(ctx: EmbeddedPiSubscribeContext) {
type SessionCompactionStartEvent = Extract<AgentSessionEvent, { type: "compaction_start" }>;
type SessionCompactionEndEvent = Extract<AgentSessionEvent, { type: "compaction_end" }>;
type CompactionReason = SessionCompactionStartEvent["reason"];
type CompactionStartEvent = SessionCompactionStartEvent | {
type: "compaction_start";
reason?: unknown;
};
type CompactionEndEvent = SessionCompactionEndEvent | {
type: "compaction_end";
reason?: unknown;
willRetry?: unknown;
result?: unknown;
aborted?: unknown;
};
function normalizeCompactionReason(reason: unknown): CompactionReason {
return reason === "manual" || reason === "threshold" || reason === "overflow"
? reason
: "threshold";
}
function compactionLogKind(reason: CompactionReason): string {
return reason === "manual" ? "manual compaction" : "auto-compaction";
}
export function handleCompactionStart(ctx: EmbeddedPiSubscribeContext, evt: CompactionStartEvent) {
const reason = normalizeCompactionReason(evt.reason);
const kind = compactionLogKind(reason);
ctx.state.compactionInFlight = true;
ctx.state.livenessState = "paused";
ctx.ensureCompactionPromise();
ctx.log.debug(`embedded run compaction start: runId=${ctx.params.runId}`);
ctx.log.info(`embedded run ${kind} start`, {
event: "embedded_run_compaction_start",
runId: ctx.params.runId,
reason,
consoleMessage: `embedded run ${kind} start: runId=${ctx.params.runId} reason=${reason}`,
});
emitAgentEvent({
runId: ctx.params.runId,
stream: "compaction",
@@ -39,10 +73,9 @@ export function handleCompactionStart(ctx: EmbeddedPiSubscribeContext) {
}
}
export function handleCompactionEnd(
ctx: EmbeddedPiSubscribeContext,
evt: AgentEvent & { willRetry?: unknown; result?: unknown; aborted?: unknown },
) {
export function handleCompactionEnd(ctx: EmbeddedPiSubscribeContext, evt: CompactionEndEvent) {
const reason = normalizeCompactionReason(evt.reason);
const kind = compactionLogKind(reason);
ctx.state.compactionInFlight = false;
const willRetry = Boolean(evt.willRetry);
// Increment counter whenever compaction actually produced a result,
@@ -59,6 +92,15 @@ export function handleCompactionEnd(
: undefined;
ctx.noteCompactionTokensAfter(tokensAfter);
const observedCompactionCount = ctx.getCompactionCount();
ctx.log.info(`embedded run ${kind} complete`, {
event: "embedded_run_compaction_end",
runId: ctx.params.runId,
reason,
completed: true,
willRetry,
compactionCount: observedCompactionCount,
consoleMessage: `embedded run ${kind} complete: runId=${ctx.params.runId} reason=${reason} compactionCount=${observedCompactionCount} willRetry=${willRetry}`,
});
void reconcileSessionStoreCompactionCountAfterSuccess({
sessionKey: ctx.params.sessionKey,
agentId: ctx.params.agentId,
@@ -79,6 +121,17 @@ export function handleCompactionEnd(
ctx.maybeResolveCompactionWait();
clearStaleAssistantUsageOnSessionMessages(ctx);
}
if (!hasResult || wasAborted) {
ctx.log.info(`embedded run ${kind} incomplete`, {
event: "embedded_run_compaction_end",
runId: ctx.params.runId,
reason,
completed: false,
willRetry,
aborted: wasAborted,
consoleMessage: `embedded run ${kind} incomplete: runId=${ctx.params.runId} reason=${reason} aborted=${wasAborted} willRetry=${willRetry}`,
});
}
emitAgentEvent({
runId: ctx.params.runId,
stream: "compaction",

View File

@@ -125,7 +125,7 @@ function createMessageEndContext(
noteLastAssistant: vi.fn(),
recordAssistantUsage: vi.fn(),
commitAssistantUsage: vi.fn(),
log: { debug: vi.fn(), warn: params.warn ?? vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: params.warn ?? vi.fn() },
builtinToolNames: params.builtinToolNames,
stripBlockTags: (text: string) => text,
finalizeAssistantTexts: params.finalizeAssistantTexts ?? vi.fn(),

View File

@@ -40,7 +40,7 @@ function createMockContext(overrides?: {
deterministicApprovalPromptPending: false,
deterministicApprovalPromptSent: false,
},
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
builtinToolNames: overrides?.builtinToolNames,
shouldEmitToolResult: vi.fn(() => false),
shouldEmitToolOutput: vi.fn(() => overrides?.shouldEmitToolOutput ?? false),

View File

@@ -41,6 +41,7 @@ function createTestContext(): {
hookRunner: undefined,
log: {
debug: vi.fn(),
info: vi.fn(),
warn,
},
state: {

View File

@@ -115,12 +115,12 @@ export function createEmbeddedPiSessionEventHandler(ctx: EmbeddedPiSubscribeCont
return;
case "compaction_start":
scheduleEvent(evt, () => {
handleCompactionStart(ctx);
handleCompactionStart(ctx, evt);
});
return;
case "compaction_end":
scheduleEvent(evt, () => {
handleCompactionEnd(ctx, evt as never);
handleCompactionEnd(ctx, evt);
});
return;
case "agent_end":

View File

@@ -1,4 +1,5 @@
import type { AgentEvent, AgentMessage } from "@earendil-works/pi-agent-core";
import type { AgentMessage } from "@earendil-works/pi-agent-core";
import type { AgentSessionEvent } from "@earendil-works/pi-coding-agent";
import type { HeartbeatToolResponse } from "../auto-reply/heartbeat-tool-response.js";
import type { ReplyDirectiveParseResult } from "../auto-reply/reply/reply-directives.js";
import type { ReasoningLevel } from "../auto-reply/thinking.js";
@@ -18,6 +19,7 @@ import type { NormalizedUsage } from "./usage.js";
type EmbeddedSubscribeLogger = {
debug: (message: string, meta?: Record<string, unknown>) => void;
info: (message: string, meta?: Record<string, unknown>) => void;
warn: (message: string, meta?: Record<string, unknown>) => void;
};
@@ -237,6 +239,6 @@ export type ToolHandlerContext = {
};
export type EmbeddedPiSubscribeEvent =
| AgentEvent
| AgentSessionEvent
| { type: string; [k: string]: unknown }
| { type: "message_start"; message: AgentMessage };

View File

@@ -73,7 +73,7 @@ function createToolHandlerCtx() {
...createBaseToolHandlerState(),
successfulCronAdds: 0,
},
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
flushBlockReplyBuffer: vi.fn(),
shouldEmitToolResult: () => false,
shouldEmitToolOutput: () => false,

View File

@@ -43,7 +43,7 @@ function createToolHandlerCtx(params: {
state: {
...createBaseToolHandlerState(),
},
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
flushBlockReplyBuffer: vi.fn(),
shouldEmitToolResult: () => false,
shouldEmitToolOutput: () => false,

View File

@@ -55,7 +55,7 @@ describe("compaction hook wiring", () => {
},
},
state: { compactionInFlight: true },
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
maybeResolveCompactionWait: vi.fn(),
incrementCompactionCount: vi.fn(),
getCompactionCount: () => params.compactionCount ?? 0,
@@ -136,12 +136,12 @@ describe("compaction hook wiring", () => {
onAgentEvent: vi.fn(),
},
state: { compactionInFlight: false },
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
incrementCompactionCount: vi.fn(),
ensureCompactionPromise: vi.fn(),
};
handleCompactionStart(ctx as never);
handleCompactionStart(ctx as never, { type: "compaction_start", reason: "threshold" });
expect(hookMocks.runner.runBeforeCompaction).toHaveBeenCalledTimes(1);
expectCompactionEvent({
@@ -253,7 +253,7 @@ describe("compaction hook wiring", () => {
const ctx = {
params: { runId: "r4", session: { messages } },
state: { compactionInFlight: true },
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
maybeResolveCompactionWait: vi.fn(),
getCompactionCount: () => 1,
incrementCompactionCount: vi.fn(),
@@ -281,7 +281,7 @@ describe("compaction hook wiring", () => {
const ctx = {
params: { runId: "r5", session: { messages } },
state: { compactionInFlight: true },
log: { debug: vi.fn(), warn: vi.fn() },
log: { debug: vi.fn(), info: vi.fn(), warn: vi.fn() },
noteCompactionRetry: vi.fn(),
resetForCompactionRetry: vi.fn(),
getCompactionCount: () => 0,