From 98e00b16137db7066ac8eea1ba984d529108df48 Mon Sep 17 00:00:00 2001 From: Gustavo Madeira Santana Date: Sun, 19 Apr 2026 17:31:26 -0400 Subject: [PATCH] fix: preserve subagent failure timing context --- CHANGELOG.md | 1 + src/agents/subagent-announce-output.ts | 58 ++++++++++++----- src/agents/subagent-announce.test.ts | 26 ++++++++ .../subagent-registry-completion.test.ts | 15 +++++ src/agents/subagent-registry-completion.ts | 6 +- .../subagent-registry-lifecycle.test.ts | 42 ++++++++++++ src/agents/subagent-registry-lifecycle.ts | 11 +++- src/agents/tools/sessions-spawn-tool.test.ts | 65 +++++++++++++++++++ 8 files changed, 204 insertions(+), 20 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3d8325bf4a0..fd60b682b8f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -25,6 +25,7 @@ Docs: https://docs.openclaw.ai - Matrix/allowlists: hot-reload `dm.allowFrom` and `groupAllowFrom` entries on inbound messages while keeping config removals authoritative, so Matrix allowlist changes no longer require a channel restart to add or revoke a sender. (#68546) Thanks @johnlanni. - BlueBubbles: always set `method` explicitly on outbound text sends (`"private-api"` when available, `"apple-script"` otherwise), and prefer Private API on macOS 26 even for plain text. Fixes silent delivery failure on macOS setups without Private API where an omitted `method` let BB Server fall back to version-dependent default behavior that silently drops the message (#64480), and the AppleScript `-1700` error on macOS 26 Tahoe plain text sends (#53159). (#69070) Thanks @xqing3. - Matrix/commands: recognize slash commands that are prefixed with the bot's Matrix mention, so room messages like `@bot:server /new` trigger the command path without requiring custom mention regexes. (#68570) Thanks @nightq and @johnlanni. +- Agents/subagents: include requested role and runtime timing on subagent failure payloads so parent agents can correlate failed or timed-out child work. (#68726) Thanks @BKF-Gitty. ## 2026.4.19-beta.2 diff --git a/src/agents/subagent-announce-output.ts b/src/agents/subagent-announce-output.ts index 02e13cb0cdd..785dc4ed0ff 100644 --- a/src/agents/subagent-announce-output.ts +++ b/src/agents/subagent-announce-output.ts @@ -63,6 +63,42 @@ export type SubagentRunOutcome = { elapsedMs?: number; }; +function readFiniteNumber(value: number | undefined): number | undefined { + return typeof value === "number" && Number.isFinite(value) ? value : undefined; +} + +export function withSubagentOutcomeTiming( + outcome: SubagentRunOutcome, + timing: { + startedAt?: number; + endedAt?: number; + }, +): SubagentRunOutcome; +export function withSubagentOutcomeTiming( + outcome: SubagentRunOutcome | undefined, + timing: { + startedAt?: number; + endedAt?: number; + }, +): SubagentRunOutcome | undefined { + if (!outcome) { + return undefined; + } + const startedAt = readFiniteNumber(timing.startedAt) ?? readFiniteNumber(outcome.startedAt); + const endedAt = readFiniteNumber(timing.endedAt) ?? readFiniteNumber(outcome.endedAt); + const nextTiming: Pick = {}; + if (typeof startedAt === "number") { + nextTiming.startedAt = startedAt; + } + if (typeof endedAt === "number") { + nextTiming.endedAt = endedAt; + } + if (typeof startedAt === "number" && typeof endedAt === "number") { + nextTiming.elapsedMs = Math.max(0, endedAt - startedAt); + } + return { ...outcome, ...nextTiming }; +} + function extractToolResultText(content: unknown): string { if (typeof content === "string") { return sanitizeTextContent(content); @@ -300,29 +336,21 @@ export function applySubagentWaitOutcome(params: { startedAt: params.startedAt, endedAt: params.endedAt, }; - if (typeof params.wait?.startedAt === "number" && !next.startedAt) { + if (typeof params.wait?.startedAt === "number" && typeof next.startedAt !== "number") { next.startedAt = params.wait.startedAt; } - if (typeof params.wait?.endedAt === "number" && !next.endedAt) { + if (typeof params.wait?.endedAt === "number" && typeof next.endedAt !== "number") { next.endedAt = params.wait.endedAt; } - const timing: Pick = {}; - if (typeof next.startedAt === "number") { - timing.startedAt = next.startedAt; - } - if (typeof next.endedAt === "number") { - timing.endedAt = next.endedAt; - } - if (typeof next.startedAt === "number" && typeof next.endedAt === "number") { - timing.elapsedMs = Math.max(0, next.endedAt - next.startedAt); - } const waitError = typeof params.wait?.error === "string" ? params.wait.error : undefined; if (params.wait?.status === "timeout") { - next.outcome = { status: "timeout", ...timing }; + next.outcome = withSubagentOutcomeTiming({ status: "timeout" }, next); } else if (params.wait?.status === "error") { - next.outcome = { status: "error", error: waitError, ...timing }; + next.outcome = withSubagentOutcomeTiming({ status: "error", error: waitError }, next); } else if (params.wait?.status === "ok") { - next.outcome = { status: "ok", ...timing }; + next.outcome = withSubagentOutcomeTiming({ status: "ok" }, next); + } else { + next.outcome = withSubagentOutcomeTiming(next.outcome, next); } return next; } diff --git a/src/agents/subagent-announce.test.ts b/src/agents/subagent-announce.test.ts index 448fa3d3dbf..838cb1eb859 100644 --- a/src/agents/subagent-announce.test.ts +++ b/src/agents/subagent-announce.test.ts @@ -168,8 +168,34 @@ vi.mock("./subagent-announce-delivery.js", () => ({ })); vi.mock("./subagent-announce.registry.runtime.js", () => subagentRegistryRuntimeMock); +import { applySubagentWaitOutcome } from "./subagent-announce-output.js"; import { runSubagentAnnounceFlow } from "./subagent-announce.js"; +describe("subagent wait outcome timing", () => { + it.each([ + { wait: { status: "ok" }, expected: { status: "ok" } }, + { wait: { status: "timeout" }, expected: { status: "timeout" } }, + { + wait: { status: "error", error: "boom" }, + expected: { status: "error", error: "boom" }, + }, + ] as const)("adds timing to $wait.status outcomes", ({ wait, expected }) => { + const result = applySubagentWaitOutcome({ + wait, + outcome: undefined, + startedAt: 1_000, + endedAt: 1_250, + }); + + expect(result.outcome).toEqual({ + ...expected, + startedAt: 1_000, + endedAt: 1_250, + elapsedMs: 250, + }); + }); +}); + describe("subagent announce seam flow", () => { beforeEach(() => { agentSpy.mockClear(); diff --git a/src/agents/subagent-registry-completion.test.ts b/src/agents/subagent-registry-completion.test.ts index e171f230d9d..3c4d01ed9a9 100644 --- a/src/agents/subagent-registry-completion.test.ts +++ b/src/agents/subagent-registry-completion.test.ts @@ -49,6 +49,21 @@ describe("emitSubagentEndedHookOnce", () => { lifecycleMocks.runSubagentEnded.mockClear(); }); + it("treats timing differences as different run outcomes", () => { + expect( + mod.runOutcomesEqual( + { status: "timeout", startedAt: 1_000, endedAt: 2_000, elapsedMs: 1_000 }, + { status: "timeout", startedAt: 1_000, endedAt: 2_500, elapsedMs: 1_500 }, + ), + ).toBe(false); + expect( + mod.runOutcomesEqual( + { status: "error", error: "boom", startedAt: 1_000, endedAt: 2_000, elapsedMs: 1_000 }, + { status: "error", error: "boom", startedAt: 1_000, endedAt: 2_000, elapsedMs: 1_000 }, + ), + ).toBe(true); + }); + it("records ended hook marker even when no subagent_ended hooks are registered", async () => { lifecycleMocks.getGlobalHookRunner.mockReturnValue({ hasHooks: () => false, diff --git a/src/agents/subagent-registry-completion.ts b/src/agents/subagent-registry-completion.ts index c3c7e02b507..e78bda27b1f 100644 --- a/src/agents/subagent-registry-completion.ts +++ b/src/agents/subagent-registry-completion.ts @@ -24,9 +24,11 @@ export function runOutcomesEqual( return false; } if (a.status === "error" && b.status === "error") { - return (a.error ?? "") === (b.error ?? ""); + if ((a.error ?? "") !== (b.error ?? "")) { + return false; + } } - return true; + return a.startedAt === b.startedAt && a.endedAt === b.endedAt && a.elapsedMs === b.elapsedMs; } export function resolveLifecycleOutcomeFromRunOutcome( diff --git a/src/agents/subagent-registry-lifecycle.test.ts b/src/agents/subagent-registry-lifecycle.test.ts index b44ef3579ba..d1abc3eb5c1 100644 --- a/src/agents/subagent-registry-lifecycle.test.ts +++ b/src/agents/subagent-registry-lifecycle.test.ts @@ -238,6 +238,48 @@ describe("subagent registry lifecycle hardening", () => { ); }); + it("enriches registered-run outcomes with persisted timing before cleanup", async () => { + const persist = vi.fn(); + const runSubagentAnnounceFlow = vi.fn(async () => true); + const entry = createRunEntry({ + startedAt: 2_000, + expectsCompletionMessage: false, + }); + + const controller = createLifecycleController({ entry, persist, runSubagentAnnounceFlow }); + + await expect( + controller.completeSubagentRun({ + runId: entry.runId, + endedAt: 4_250, + outcome: { status: "timeout" }, + reason: SUBAGENT_ENDED_REASON_COMPLETE, + triggerCleanup: true, + }), + ).resolves.toBeUndefined(); + + const enrichedOutcome = { + status: "timeout" as const, + startedAt: 2_000, + endedAt: 4_250, + elapsedMs: 2_250, + }; + expect(entry.outcome).toEqual(enrichedOutcome); + expect(taskExecutorMocks.failTaskRunByRunId).toHaveBeenCalledWith( + expect.objectContaining({ + status: "timed_out", + }), + ); + expect(runSubagentAnnounceFlow).toHaveBeenCalledWith( + expect.objectContaining({ + startedAt: 2_000, + endedAt: 4_250, + outcome: enrichedOutcome, + }), + ); + expect(persist).toHaveBeenCalled(); + }); + it("does not wait for a completion reply when the run does not expect one", async () => { const entry = createRunEntry({ expectsCompletionMessage: false, diff --git a/src/agents/subagent-registry-lifecycle.ts b/src/agents/subagent-registry-lifecycle.ts index 7b84a8183ca..c278d62a86d 100644 --- a/src/agents/subagent-registry-lifecycle.ts +++ b/src/agents/subagent-registry-lifecycle.ts @@ -9,6 +9,7 @@ import { setDetachedTaskDeliveryStatusByRunId, } from "../tasks/detached-task-runtime.js"; import { normalizeDeliveryContext } from "../utils/delivery-context.js"; +import { withSubagentOutcomeTiming } from "./subagent-announce-output.js"; import { captureSubagentCompletionReply, runSubagentAnnounceFlow, @@ -589,8 +590,12 @@ export function createSubagentRegistryLifecycleController(params: { entry.endedAt = endedAt; mutated = true; } - if (!runOutcomesEqual(entry.outcome, completeParams.outcome)) { - entry.outcome = completeParams.outcome; + const outcome = withSubagentOutcomeTiming(completeParams.outcome, { + startedAt: entry.startedAt, + endedAt, + }); + if (!runOutcomesEqual(entry.outcome, outcome)) { + entry.outcome = outcome; mutated = true; } if (entry.endedReason !== completeParams.reason) { @@ -607,7 +612,7 @@ export function createSubagentRegistryLifecycleController(params: { } safeFinalizeSubagentTaskRun({ entry, - outcome: completeParams.outcome, + outcome, }); try { diff --git a/src/agents/tools/sessions-spawn-tool.test.ts b/src/agents/tools/sessions-spawn-tool.test.ts index 1c525c7bbf1..cca546ac46a 100644 --- a/src/agents/tools/sessions-spawn-tool.test.ts +++ b/src/agents/tools/sessions-spawn-tool.test.ts @@ -66,6 +66,7 @@ describe("sessions_spawn tool", () => { childSessionKey: "agent:main:subagent:1", runId: "run-subagent", }); + expect(result.details).not.toHaveProperty("role"); expect(hoisted.spawnSubagentDirectMock).toHaveBeenCalledWith( expect.objectContaining({ task: "build feature", @@ -84,6 +85,46 @@ describe("sessions_spawn tool", () => { expect(hoisted.spawnAcpDirectMock).not.toHaveBeenCalled(); }); + it.each([ + { status: "error" as const, error: "spawn failed" }, + { status: "forbidden" as const, error: "not allowed" }, + ])("adds requested role to forwarded subagent $status results", async (spawnResult) => { + hoisted.spawnSubagentDirectMock.mockResolvedValueOnce(spawnResult); + const tool = createSessionsSpawnTool({ + agentSessionKey: "agent:main:main", + }); + + const result = await tool.execute("call-role-error", { + task: "build feature", + agentId: "reviewer", + }); + + expect(result.details).toMatchObject({ + ...spawnResult, + role: "reviewer", + }); + }); + + it("does not add role to forwarded failures when agentId is absent", async () => { + hoisted.spawnSubagentDirectMock.mockResolvedValueOnce({ + status: "error", + error: "spawn failed", + }); + const tool = createSessionsSpawnTool({ + agentSessionKey: "agent:main:main", + }); + + const result = await tool.execute("call-no-role-error", { + task: "build feature", + }); + + expect(result.details).toMatchObject({ + status: "error", + error: "spawn failed", + }); + expect(result.details).not.toHaveProperty("role"); + }); + it("supports legacy timeoutSeconds alias", async () => { const tool = createSessionsSpawnTool({ agentSessionKey: "agent:main:main", @@ -198,6 +239,30 @@ describe("sessions_spawn tool", () => { expect(hoisted.spawnSubagentDirectMock).not.toHaveBeenCalled(); }); + it("adds requested role to forwarded ACP failures", async () => { + hoisted.spawnAcpDirectMock.mockResolvedValueOnce({ + status: "forbidden", + error: "ACP disabled", + errorCode: "acp_disabled", + }); + const tool = createSessionsSpawnTool({ + agentSessionKey: "agent:main:main", + }); + + const result = await tool.execute("call-acp-role-error", { + runtime: "acp", + task: "investigate", + agentId: "codex", + }); + + expect(result.details).toMatchObject({ + status: "forbidden", + error: "ACP disabled", + errorCode: "acp_disabled", + role: "codex", + }); + }); + it("forwards ACP sandbox options and requester sandbox context", async () => { const tool = createSessionsSpawnTool({ agentSessionKey: "agent:main:subagent:parent",