fix: preserve subagent failure timing context

This commit is contained in:
Gustavo Madeira Santana
2026-04-19 17:31:26 -04:00
parent c092370f40
commit 98e00b1613
8 changed files with 204 additions and 20 deletions

View File

@@ -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

View File

@@ -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<SubagentRunOutcome, "startedAt" | "endedAt" | "elapsedMs"> = {};
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<SubagentRunOutcome, "startedAt" | "endedAt" | "elapsedMs"> = {};
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;
}

View File

@@ -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();

View File

@@ -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,

View File

@@ -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(

View File

@@ -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,

View File

@@ -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 {

View File

@@ -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",