fix: surface hidden-pane steer failures and demote per-turn gateway log noise (#124560)

* fix(ui): surface hidden-pane steer terminal failures globally

Three terminal branches in steer-lifecycle.ts (transport null result,
failed queue-row restore, failed queue-row removal) still gated their
error on itemStillVisible, so a steer that failed after the operator
navigated away parked the error on the queue row with no visible
outcome — the exact invariant #124473 introduced
surfaceChatDeliveryFailure() to protect.

Route all three through the canonical helper and delete the divergent
visibility-only branches. Regression test fails pre-fix
(stash-verified): steer transport failure with the pane hidden now
surfaces the session-named global toast.

* fix(logging): demote per-turn gateway log noise to debug

Live campaign evidence showed three lines dominating operator logs at
info level with no per-turn diagnostic value:

- 'tool policy removed N tool(s)': the policy pipeline runs on every
  turn, so this repeated 42x in one session. Demote to debug and delete
  the now-dead toolPolicyAuditLogLevel/auditLogLevel plumbing that only
  existed to lower diagnostic probes to the level that is now the
  default (net -13 production LOC).
- 'codex app-server one-shot cleanup checked shared client retirement':
  routine per-attempt teardown detail; demote to debug.
- 'codex trajectory capture requires the SQLite host recorder': static
  config condition warned per attempt; warn once per process.

Skipped: the [model-fetch] info carve-out in model-transport-debug.ts is
a named contract (docs/logging.md, #89648) — always-info by design.

* fix(codex): drop test-only trajectory warn-once reset export

Knip's production unused-export gate rejects
resetCodexTrajectoryRecorderWarningForTest — it was a test-only seam in
production code. Reset the process-wide warn-once flag via
vi.resetModules() + fresh dynamic import in the test instead.

* test(cron): wait for backoff re-arm instead of fixed sleep

The 0ms retry timer arms only after async watcher-state persistence, so
'await delay(5)' races it on loaded CI workers (flaked on
checks-node-compact-large-2: spawn called 1 time, expected 2). Replace
both fixed-sleep re-arm waits with vi.waitFor on the spawn count. The
remaining delay(5) guards a negative no-further-spawn assertion after
cancel, where a bounded sleep is the correct shape.

* fix(codex): scope trajectory recorder warn dedupe to session

ClawSweeper P2: the host recorder factory returns null for per-session
target-mapping conflicts, not only static config, so a process-wide
warn-once flag silenced a later distinct session's recorder loss. Warn
once per session (bounded set, cleared past 64 entries) so retries stay
quiet but each newly affected session records its loss. Regression
covers a later distinct session still warning.
This commit is contained in:
Peter Steinberger
2026-08-16 06:23:44 -07:00
committed by GitHub
parent 243f51d314
commit 7173aeb663
17 changed files with 108 additions and 100 deletions
@@ -137,7 +137,9 @@ export function prepareCodexAttemptResources(prompt: CodexAttemptPrompt) {
}
state.sharedCodexClientRetiredForOneShotCleanup = true;
const retired = clearSharedCodexAppServerClientIfCurrentAndUnclaimed(state.client);
embeddedAgentLog.info("codex app-server one-shot cleanup checked shared client retirement", {
// Runs on every one-shot attempt teardown; routine retirement checks are
// diagnostic detail, not operator-facing info.
embeddedAgentLog.debug("codex app-server one-shot cleanup checked shared client retirement", {
runId: params.runId,
sessionId: params.sessionId,
sessionKey: params.sessionKey,
@@ -117,24 +117,41 @@ function createSqliteHostTrajectoryRecorder(params: {
}
describe("Codex trajectory recorder", () => {
it("warns when the SQLite host recorder is unavailable", () => {
it("warns once per session when the SQLite host recorder is unavailable", async () => {
// Import a fresh module instance so the process-wide dedupe set starts
// clean without a test-only reset export in production code.
vi.resetModules();
const { createCodexTrajectoryRecorder: createFreshRecorder } = await import("./trajectory.js");
const warn = vi.fn();
const recorder = createCodexTrajectoryRecorder({
cwd: testWorkspace.dir,
attempt: {
sessionFile: "agent:main:session-1",
sessionId: "session-1",
model: { api: "responses" },
} as never,
env: {},
warn,
});
const makeRecorder = (sessionId: string) =>
createFreshRecorder({
cwd: testWorkspace.dir,
attempt: {
sessionFile: `agent:main:${sessionId}`,
sessionId,
model: { api: "responses" },
} as never,
env: {},
warn,
});
expect(recorder).toBeNull();
expect(makeRecorder("session-1")).toBeNull();
// Retried attempts for the same session must not repeat the warn.
expect(makeRecorder("session-1")).toBeNull();
expect(warn).toHaveBeenCalledTimes(1);
expect(warn).toHaveBeenCalledWith(
"codex trajectory capture requires the SQLite host recorder",
{ sessionId: "session-1", reason: "sqlite-recorder-unavailable" },
);
// A later distinct session's recorder loss stays visible: the host can
// reject per-session (target-mapping conflicts), not only per-process.
expect(makeRecorder("session-2")).toBeNull();
expect(warn).toHaveBeenCalledTimes(2);
expect(warn).toHaveBeenLastCalledWith(
"codex trajectory capture requires the SQLite host recorder",
{ sessionId: "session-2", reason: "sqlite-recorder-unavailable" },
);
});
it("stores SQLite-backed captures for the canonical session-key target", async () => {
+19 -4
View File
@@ -121,6 +121,13 @@ function createCodexHostTrajectorySink(params: {
};
}
// The host recorder can be absent per session (target-mapping conflicts), not
// only per process, so dedupe the warn by session: repeated attempts for one
// session stay quiet while a later distinct session still records its loss.
// Bounded: cleared past the cap so a pathological session churn cannot grow it.
const warnedRecorderUnavailableSessions = new Set<string>();
const WARNED_RECORDER_SESSIONS_CAP = 64;
/** Creates a trajectory recorder when trajectory capture is enabled for the environment. */
export function createCodexTrajectoryRecorder(
params: CodexTrajectoryInit,
@@ -136,10 +143,18 @@ export function createCodexTrajectoryRecorder(
// from a session-file string silently drops every capture once the host
// stops emitting the legacy `sqlite:` marker.
if (!params.trajectoryRecorder) {
params.warn?.("codex trajectory capture requires the SQLite host recorder", {
sessionId: params.attempt.sessionId,
reason: "sqlite-recorder-unavailable",
});
// Per-attempt repeats for one session bury real diagnostics; warn once per
// session so retries stay quiet but each newly affected session is visible.
if (!warnedRecorderUnavailableSessions.has(params.attempt.sessionId)) {
if (warnedRecorderUnavailableSessions.size >= WARNED_RECORDER_SESSIONS_CAP) {
warnedRecorderUnavailableSessions.clear();
}
warnedRecorderUnavailableSessions.add(params.attempt.sessionId);
params.warn?.("codex trajectory capture requires the SQLite host recorder", {
sessionId: params.attempt.sessionId,
reason: "sqlite-recorder-unavailable",
});
}
return null;
}
const sink = createCodexHostTrajectorySink({ recorder: params.trajectoryRecorder });
-3
View File
@@ -349,8 +349,6 @@ type OpenClawCodingToolsOptions = {
onYield?: (message: string) => Promise<void> | void;
/** Optional instrumentation callback for tool preparation stage timing. */
recordToolPrepStage?: (name: string) => void;
/** Lower routine policy-removal audits for diagnostic-only tool probes. */
toolPolicyAuditLogLevel?: "info" | "debug";
/** Live observer called after wrapped tool outcomes are recorded. */
onToolOutcome?: ToolOutcomeObserver;
/** Reads the sticky untrusted-content flag for the current user turn. */
@@ -907,7 +905,6 @@ function createOpenClawCodingToolsInternal(options?: OpenClawCodingToolsOptions)
includeRuntimeToolPolicy: true,
unavailableCoreToolReason,
}),
auditLogLevel: options?.toolPolicyAuditLogLevel,
declaredToolAllowlist: buildDeclaredToolAllowlistContext({
config: options?.config,
metadataSnapshot: options?.preparedModelRuntime?.metadataSnapshot,
@@ -38,7 +38,6 @@ type FinalEffectiveToolPolicyParams = {
metadataSnapshot?: PluginMetadataSnapshot;
conversationCapabilityProfile: ResolvedConversationCapabilityProfile;
warn: (message: string) => void;
toolPolicyAuditLogLevel?: "info" | "debug";
onFilter?: (event: ToolPolicyFilterEvent) => void;
};
@@ -78,7 +77,6 @@ export function applyFinalEffectiveToolPolicy(
toolMeta: (tool) => getPluginToolMeta(tool),
warn: params.warn,
steps: pipelineSteps,
auditLogLevel: params.toolPolicyAuditLogLevel,
onFilter: params.onFilter,
declaredToolAllowlist: buildDeclaredToolAllowlistContext({
config: params.config,
+3 -9
View File
@@ -15,9 +15,6 @@ const MAX_AUDIT_TOOL_NAMES = 50;
const MAX_AUDIT_FIELD_LENGTH = 160;
const toolPolicyAuditLogger = createSubsystemLogger("agents/tool-policy");
/** Log level used for tool-policy audit events. */
export type ToolPolicyAuditLogLevel = "info" | "debug";
type ToolPolicyRuleKind = "allow" | "deny" | "allow+deny" | "unknown";
function toolPolicyRuleKind(policy: ToolPolicyLike): ToolPolicyRuleKind {
@@ -174,7 +171,6 @@ export function auditToolPolicyFilter(params: {
policy: ToolPolicyLike;
before: readonly { name: string }[];
after: readonly { name: string }[];
logLevel?: ToolPolicyAuditLogLevel;
}): void {
const removedByRule = removedToolNamesByRule({
policy: params.policy,
@@ -208,11 +204,9 @@ export function auditToolPolicyFilter(params: {
removedTools: toolNames,
removedToolsTruncated: truncated,
};
if (params.logLevel === "debug") {
toolPolicyAuditLogger.debug(message, metadata);
} else {
toolPolicyAuditLogger.info(message, metadata);
}
// Routine policy filtering runs on every turn; per-turn removal detail is
// diagnostic, not operator-facing, so it stays out of info-level logs.
toolPolicyAuditLogger.debug(message, metadata);
}
}
+9 -38
View File
@@ -629,7 +629,7 @@ describe("tool-policy-pipeline", () => {
],
});
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 2 tool(s) via agent tools.allow: browser, write",
{
rule: "agent tools.allow",
@@ -639,35 +639,6 @@ describe("tool-policy-pipeline", () => {
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditDebug).not.toHaveBeenCalled();
});
test("can lower removal audits for diagnostic-only policy probes", () => {
const tools = [{ name: "exec" }, { name: "browser" }] as unknown as DummyTool[];
applyToolPolicyPipeline({
tools: asPolicyTools(tools),
toolMeta: () => undefined,
warn: () => {},
auditLogLevel: "debug",
steps: [
{
policy: { allow: ["exec"] },
label: "doctor tools.profile (coding)",
},
],
});
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 1 tool(s) via doctor tools.profile (coding): browser",
{
rule: "doctor tools.profile (coding)",
ruleKind: "allow",
removedToolCount: 1,
removedTools: ["browser"],
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditInfo).not.toHaveBeenCalled();
});
@@ -686,7 +657,7 @@ describe("tool-policy-pipeline", () => {
],
});
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 1 tool(s) via tools.deny: browser; matched browser",
{
rule: "tools.deny",
@@ -697,7 +668,7 @@ describe("tool-policy-pipeline", () => {
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditDebug).not.toHaveBeenCalled();
expect(toolPolicyAuditInfo).not.toHaveBeenCalled();
});
test("splits mixed allow and deny policy audit entries by cause", () => {
@@ -719,7 +690,7 @@ describe("tool-policy-pipeline", () => {
],
});
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 1 tool(s) via agents.worker.tools.deny: browser; matched browser",
{
rule: "agents.worker.tools.deny",
@@ -730,7 +701,7 @@ describe("tool-policy-pipeline", () => {
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 1 tool(s) via agents.worker.tools.allow: write",
{
rule: "agents.worker.tools.allow",
@@ -740,7 +711,7 @@ describe("tool-policy-pipeline", () => {
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditDebug).not.toHaveBeenCalled();
expect(toolPolicyAuditInfo).not.toHaveBeenCalled();
});
test("does not audit policy steps that leave the tool surface unchanged", () => {
@@ -777,7 +748,7 @@ describe("tool-policy-pipeline", () => {
],
});
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
"tool policy removed 1 tool(s) via agents.worker\\nbad.tools.allow: exec\\nbad",
{
rule: "agents.worker\\nbad.tools.allow",
@@ -787,7 +758,7 @@ describe("tool-policy-pipeline", () => {
removedToolsTruncated: false,
},
);
expect(toolPolicyAuditDebug).not.toHaveBeenCalled();
expect(toolPolicyAuditInfo).not.toHaveBeenCalled();
});
test("truncates audit fields without splitting surrogate pairs", () => {
@@ -807,7 +778,7 @@ describe("tool-policy-pipeline", () => {
});
const rule = `${labelPrefix}...`;
expect(toolPolicyAuditInfo).toHaveBeenCalledWith(
expect(toolPolicyAuditDebug).toHaveBeenCalledWith(
`tool policy removed 1 tool(s) via ${rule}: exec`,
{
rule,
+1 -3
View File
@@ -7,7 +7,7 @@ import { isFrozenClawToolAllowPolicy } from "../claws/tool-policy-runtime.js";
import { filterToolsByPolicy } from "./agent-tools.policy.js";
import type { AnyAgentTool } from "./agent-tools.types.js";
import { isKnownCoreToolId } from "./tool-catalog.js";
import { auditToolPolicyFilter, type ToolPolicyAuditLogLevel } from "./tool-policy-audit.js";
import { auditToolPolicyFilter } from "./tool-policy-audit.js";
import {
analyzeAllowlistByToolType,
buildPluginToolGroups,
@@ -138,7 +138,6 @@ export function applyToolPolicyPipeline<TTool extends { name: string }>(params:
toolMeta: (tool: TTool) => { pluginId: string } | undefined;
warn: (message: string) => void;
steps: ToolPolicyPipelineStep[];
auditLogLevel?: ToolPolicyAuditLogLevel;
declaredToolAllowlist?: DeclaredToolAllowlistContext;
onFilter?: (event: ToolPolicyFilterEvent<TTool>) => void;
}): TTool[] {
@@ -226,7 +225,6 @@ export function applyToolPolicyPipeline<TTool extends { name: string }>(params:
policy: expanded,
before,
after: filtered,
logLevel: params.auditLogLevel,
});
}
return filtered;
@@ -104,9 +104,6 @@ describe("active tool schema doctor warnings", () => {
).toEqual([
'- agents.main: active tool "fuzzplugin_move_angles" from plugin "fuzzplugin" has unsupported runtime input schema (fuzzplugin_move_angles.parameters.type must be "object"). OpenClaw will quarantine this tool at runtime; fix or disable the plugin, or remove the tool from active allowlists.',
]);
expect(toolState.createTools).toHaveBeenCalledWith(
expect.objectContaining({ toolPolicyAuditLogLevel: "debug" }),
);
});
it("warns about unreadable active tool entries without crashing", async () => {
@@ -142,7 +142,6 @@ export async function collectActiveToolSchemaProjectionWarnings(params: {
modelCompat: runtimeModelContext.modelCompat,
modelContextWindowTokens: runtimeModelContext.modelContextWindowTokens,
allowGatewaySubagentBinding: true,
toolPolicyAuditLogLevel: "debug",
});
} catch (error) {
agentWarnings.push(
+2 -2
View File
@@ -375,10 +375,10 @@ describe("doctor runtime tool schema checks", () => {
"Disable or update the offending plugin/tool so its parameters are a JSON object schema, then rerun doctor.",
});
expect(mocks.createOpenClawCodingTools).toHaveBeenCalledWith(
expect.objectContaining({ agentId: "main", toolPolicyAuditLogLevel: "debug" }),
expect.objectContaining({ agentId: "main" }),
);
expect(mocks.createOpenClawCodingTools).toHaveBeenCalledWith(
expect.objectContaining({ agentId: "worker", toolPolicyAuditLogLevel: "debug" }),
expect.objectContaining({ agentId: "worker" }),
);
expect(mocks.loadModelCatalog).toHaveBeenCalledTimes(2);
expect(mocks.loadModelCatalog).toHaveBeenNthCalledWith(
-3
View File
@@ -841,7 +841,6 @@ function collectBundleMcpRuntimeToolSchemaFindings(params: {
modelId: params.modelRef.model,
}),
warn: () => {},
toolPolicyAuditLogLevel: "debug",
});
return collectNormalizedToolSchemaFindings({
agentId: params.agentId,
@@ -904,7 +903,6 @@ function collectAgentRuntimeToolSchemaFindings(params: {
modelContextWindowTokens: params.model.contextWindow,
allowGatewaySubagentBinding: true,
emitBeforeToolCallDiagnostics: false,
toolPolicyAuditLogLevel: "debug",
});
} catch (error) {
return [agentRuntimeToolLoadFailureFinding({ agentId: params.agentId, error })];
@@ -1054,7 +1052,6 @@ function shouldReportBundleMcpRuntimeDiagnostic(params: {
modelId: params.modelRef.model,
}),
warn: () => {},
toolPolicyAuditLogLevel: "debug",
}).length > 0
);
}
+7 -8
View File
@@ -238,10 +238,10 @@ describe("createCronExitWatchers", () => {
expect.objectContaining({ consecutiveErrors: 1 }),
);
expect(w.activeJobIds()).toEqual(["job-a"]);
// The backoff timer re-arms without an external reconcile.
await delay(5);
await flush();
expect(supervisor.spawn).toHaveBeenCalledTimes(2);
// The backoff timer re-arms without an external reconcile. The 0ms retry
// timer is armed only after async state persistence, so a fixed sleep races
// it on loaded CI workers — wait for the re-arm instead.
await vi.waitFor(() => expect(supervisor.spawn).toHaveBeenCalledTimes(2));
expect(w.activeJobIds()).toEqual(["job-a"]);
});
@@ -264,10 +264,9 @@ describe("createCronExitWatchers", () => {
expect.objectContaining({ id: "job-a" }),
expect.objectContaining({ consecutiveErrors: 1 }),
);
// Backoff re-arm succeeds on the second spawn.
await delay(5);
await flush();
expect(supervisor.spawn).toHaveBeenCalledTimes(2);
// Backoff re-arm succeeds on the second spawn. Same async-persist race as
// the wait-rejection case above: wait for the re-arm, not a fixed sleep.
await vi.waitFor(() => expect(supervisor.spawn).toHaveBeenCalledTimes(2));
expect(w.activeJobIds()).toEqual(["job-a"]);
// Cancelling clears any pending retry timer; once the cancelled child
-1
View File
@@ -414,7 +414,6 @@ export function resolveGatewayScopedTools(params: {
},
// The MCP dispatcher is the shared hook and abort boundary for these tools.
wrapBeforeToolCallHook: false,
toolPolicyAuditLogLevel: "debug",
})
: [];
// CLI backends already own their local shell. This extra surface is deliberately
@@ -205,7 +205,6 @@ export function resolveSkillWorkshopToolPolicyAvailability(params: {
config: params.config,
conversationCapabilityProfile: params.conversationCapabilityProfile,
warn: () => {},
toolPolicyAuditLogLevel: "debug",
onFilter: (event) => {
if (
!exclusion &&
+32
View File
@@ -9303,6 +9303,38 @@ describe("handleSendChat", () => {
expect(host.applySettings).not.toHaveBeenCalled();
});
it("surfaces an unconfirmed steer failure globally when the pane is no longer visible", async () => {
const toastHost = document.createElement("openclaw-toast-host");
document.body.append(toastHost);
const original = { id: "queued-1", text: "tighten the plan", createdAt: 1 };
const host = makeChatHost({
requestHandlers: {
"chat.send": () => {
// The operator navigates away before transport fails, so the stale
// visibility gate used to swallow the terminal outcome entirely.
host.sessionKey = "agent:main:second";
throw new Error("network dropped");
},
},
chatRunId: "run-1",
chatDisplayedLeafEntryId: "leaf-active",
chatQueue: [original],
sessionKey: "agent:main:main",
});
expect(admitQueuedMessageForSession(host, host.sessionKey, original)).toBe(true);
await steerQueuedChatMessage(host, "queued-1");
// Pre-fix: the failure was parked on the queue row with no visible outcome.
expect(host.lastError).toBeNull();
await waitForFast(() =>
expect(document.body.textContent).toContain(
"Steer delivery could not be confirmed. Check the active run before retrying.",
),
);
document.body.replaceChildren();
});
it("removes pending steer indicators when the run finishes", () => {
const host = makeChatHost({
chatQueue: [
+3 -9
View File
@@ -479,9 +479,7 @@ export async function sendQueuedChatMessageWithQueueMode(
if (!result) {
// A transport failure does not prove active-run admission was rejected. Keep the
// durable row parked so reconnect cannot replay it as a separate turn.
if (itemStillVisible) {
setChatError(host, unconfirmedError);
}
surfaceChatDeliveryFailure(host, itemSessionKey, item.agentId, unconfirmedError);
return;
}
if (isRejectedSteerChatSend(result)) {
@@ -505,9 +503,7 @@ export async function sendQueuedChatMessageWithQueueMode(
...(entry.attachments?.length ? { attachments: entry.attachments } : {}),
}));
if (!restored) {
if (itemStillVisible) {
setChatError(host, unconfirmedError);
}
surfaceChatDeliveryFailure(host, itemSessionKey, item.agentId, unconfirmedError);
} else {
surfaceChatDeliveryFailure(
host,
@@ -521,9 +517,7 @@ export async function sendQueuedChatMessageWithQueueMode(
}
const removed = removeQueuedMessageWithoutReleasing(host, id, itemSessionKey, item.agentId);
if (!removed) {
if (itemStillVisible) {
setChatError(host, unconfirmedError);
}
surfaceChatDeliveryFailure(host, itemSessionKey, item.agentId, unconfirmedError);
return;
}
const userTurnAlreadyVisible = chatMessagesContainQueuedSend(host.chatMessages, claimed, true);