Skip to content

Commit face219

Browse files
edelaunaedelauna
committed
chore: add subtask delegation diagnostics
1 parent 98c629f commit face219

5 files changed

Lines changed: 202 additions & 4 deletions

File tree

‎apps/vscode-e2e/src/fixtures/subtasks.ts‎

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,10 +5,14 @@ import { toolResultContains } from "./tool-result"
55

66
const SUBTASK_PARENT_MARKER = "SUBTASK_PARENT_CANCELLATION_SMOKE"
77
const SUBTASK_CHILD_MARKER = "SUBTASK_CHILD_CALCULATOR_SMOKE"
8+
const SUBTASK_FAST_PARENT_MARKER = "SUBTASK_PARENT_IMMEDIATE_COMPLETION"
9+
const SUBTASK_FAST_CHILD_MARKER = "SUBTASK_CHILD_IMMEDIATE_COMPLETION"
810

911
const SUBTASK_CHILD_PROMPT = `${SUBTASK_CHILD_MARKER}: Ask the user exactly this follow-up question: What is the square root of 81? After the user answers, complete with only the answer.`
1012
export const SUBTASK_PARENT_PROMPT = `${SUBTASK_PARENT_MARKER}: Use the new_task tool exactly once. Create an ask-mode subtask with this exact message: "${SUBTASK_CHILD_PROMPT}" Do not answer directly.`
1113
export const SUBTASK_CHILD_FOLLOWUP_ANSWER = "9"
14+
const SUBTASK_FAST_CHILD_PROMPT = `${SUBTASK_FAST_CHILD_MARKER}: Complete immediately with the exact result "Fast child completed".`
15+
export const SUBTASK_FAST_PARENT_PROMPT = `${SUBTASK_FAST_PARENT_MARKER}: Use the new_task tool exactly once. Create an ask-mode subtask with this exact message: "${SUBTASK_FAST_CHILD_PROMPT}" Do not answer directly.`
1216

1317
const requestContains = (req: ChatCompletionRequest, expected: string[]) => {
1418
const rawRequest = JSON.stringify(req)
@@ -40,6 +44,54 @@ const completionAfterAnswer = (followupId: string, completionId: string) => ({
4044
})
4145

4246
export function addSubtaskFixtures(mock: InstanceType<typeof LLMock>) {
47+
mock.addFixture({
48+
match: {
49+
userMessage: new RegExp(SUBTASK_FAST_PARENT_MARKER),
50+
},
51+
response: {
52+
toolCalls: [
53+
{
54+
name: "new_task",
55+
arguments: JSON.stringify({
56+
mode: "ask",
57+
message: SUBTASK_FAST_CHILD_PROMPT,
58+
}),
59+
id: "call_subtasks_fast_parent_new_task_001",
60+
},
61+
],
62+
},
63+
})
64+
65+
mock.addFixture({
66+
match: {
67+
userMessage: new RegExp(SUBTASK_FAST_CHILD_MARKER),
68+
},
69+
response: {
70+
toolCalls: [
71+
{
72+
name: "attempt_completion",
73+
arguments: JSON.stringify({ result: "Fast child completed" }),
74+
id: "call_subtasks_fast_child_completion_002",
75+
},
76+
],
77+
},
78+
})
79+
80+
mock.addFixture({
81+
match: {
82+
toolCallId: "call_subtasks_fast_parent_new_task_001",
83+
},
84+
response: {
85+
toolCalls: [
86+
{
87+
name: "attempt_completion",
88+
arguments: JSON.stringify({ result: "Fast parent resumed" }),
89+
id: "call_subtasks_fast_parent_completion_003",
90+
},
91+
],
92+
},
93+
})
94+
4395
mock.addFixture({
4496
match: {
4597
userMessage: new RegExp(SUBTASK_PARENT_MARKER),

‎apps/vscode-e2e/src/suite/subtasks.test.ts‎

Lines changed: 134 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,11 +4,144 @@ import { RooCodeEventName, type ClineMessage } from "@roo-code/types"
44

55
import { setDefaultSuiteTimeout } from "./test-utils"
66
import { waitFor, waitUntilCompleted } from "./utils"
7-
import { SUBTASK_CHILD_FOLLOWUP_ANSWER, SUBTASK_PARENT_PROMPT } from "../fixtures/subtasks"
7+
import { SUBTASK_CHILD_FOLLOWUP_ANSWER, SUBTASK_FAST_PARENT_PROMPT, SUBTASK_PARENT_PROMPT } from "../fixtures/subtasks"
88

99
suite("Roo Code Subtasks", function () {
1010
setDefaultSuiteTimeout(this)
1111

12+
test("child completing on its first response returns to parent", async () => {
13+
const api = globalThis.api
14+
const says: Record<string, ClineMessage[]> = {}
15+
16+
const messageHandler = ({ taskId, message }: { taskId: string; message: ClineMessage }) => {
17+
if (message.type === "say" && message.partial === false) {
18+
says[taskId] = says[taskId] || []
19+
says[taskId].push(message)
20+
}
21+
}
22+
23+
api.on(RooCodeEventName.Message, messageHandler)
24+
25+
try {
26+
const parentTaskId = await waitUntilCompleted({
27+
api,
28+
start: () =>
29+
api.startNewTask({
30+
configuration: {
31+
mode: "ask",
32+
alwaysAllowModeSwitch: true,
33+
alwaysAllowSubtasks: true,
34+
autoApprovalEnabled: true,
35+
enableCheckpoints: false,
36+
},
37+
text: SUBTASK_FAST_PARENT_PROMPT,
38+
}),
39+
})
40+
41+
assert.ok(
42+
Object.entries(says).some(
43+
([taskId, messages]) =>
44+
taskId !== parentTaskId &&
45+
messages.some(
46+
({ say, text }) => say === "completion_result" && text?.trim() === "Fast child completed",
47+
),
48+
),
49+
"Immediately-completing child should emit its expected result",
50+
)
51+
assert.strictEqual(
52+
says[parentTaskId]
53+
?.filter(({ say }) => say === "completion_result")
54+
.map(({ text }) => text?.trim())
55+
.find((text): text is string => !!text),
56+
"Fast parent resumed",
57+
"Parent should resume after the child completes on its first response",
58+
)
59+
} finally {
60+
api.off(RooCodeEventName.Message, messageHandler)
61+
while (api.getCurrentTaskStack().length > 0) {
62+
await api.clearCurrentTask()
63+
}
64+
}
65+
})
66+
67+
// Smoke: child completing normally must resume the parent task.
68+
test("child task returns to parent after normal completion", async () => {
69+
const api = globalThis.api
70+
const asks: Record<string, ClineMessage[]> = {}
71+
const says: Record<string, ClineMessage[]> = {}
72+
73+
const messageHandler = ({ taskId, message }: { taskId: string; message: ClineMessage }) => {
74+
if (message.type === "ask") {
75+
asks[taskId] = asks[taskId] || []
76+
asks[taskId].push(message)
77+
}
78+
if (message.type === "say" && message.partial === false) {
79+
says[taskId] = says[taskId] || []
80+
says[taskId].push(message)
81+
}
82+
}
83+
84+
api.on(RooCodeEventName.Message, messageHandler)
85+
86+
try {
87+
const parentTaskId = await api.startNewTask({
88+
configuration: {
89+
mode: "ask",
90+
alwaysAllowModeSwitch: true,
91+
alwaysAllowSubtasks: true,
92+
autoApprovalEnabled: true,
93+
enableCheckpoints: false,
94+
},
95+
text: SUBTASK_PARENT_PROMPT,
96+
})
97+
98+
// Wait for child to spawn.
99+
let childTaskId: string | undefined
100+
await waitFor(() => {
101+
const stack = api.getCurrentTaskStack()
102+
const current = stack[stack.length - 1]
103+
if (current && current !== parentTaskId) {
104+
childTaskId = current
105+
return true
106+
}
107+
return false
108+
})
109+
110+
// Wait for the child's followup question, then answer so it can complete.
111+
// Register the completion listener before sending the answer to avoid a race.
112+
await waitFor(() => asks[childTaskId!]?.some(({ ask }) => ask === "followup") ?? false)
113+
await waitUntilCompleted({
114+
api,
115+
start: async () => {
116+
await api.sendMessage(SUBTASK_CHILD_FOLLOWUP_ANSWER)
117+
return parentTaskId
118+
},
119+
})
120+
121+
const parentCompletionText = says[parentTaskId]
122+
?.filter(({ say }) => say === "completion_result")
123+
.map(({ text }) => text?.trim())
124+
.find((t): t is string => !!t)
125+
126+
assert.strictEqual(
127+
parentCompletionText,
128+
"Parent task resumed",
129+
"Parent should complete with the expected result after child returns",
130+
)
131+
} finally {
132+
api.off(RooCodeEventName.Message, messageHandler)
133+
// Drain the stack so partially-completed tasks don't leak into the next test.
134+
// On the happy path the parent is already gone; on failure both tasks may still be active.
135+
if (api.getCurrentTaskStack().length > 0) {
136+
await api.clearCurrentTask()
137+
}
138+
if (api.getCurrentTaskStack().length > 0) {
139+
await api.clearCurrentTask()
140+
}
141+
await waitFor(() => api.getCurrentTaskStack().length === 0).catch(() => {})
142+
}
143+
})
144+
12145
// Race mitigation: skipDelegationRepair prevents removeClineFromStack from
13146
// auto-resuming the parent when the child is cancelled (Race 2).
14147
test("parent stays paused after subtask cancellation", async () => {

‎src/core/tools/AttemptCompletionTool.ts‎

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ export interface AttemptCompletionCallbacks extends ToolCallbacks {
2525
* Interface for provider methods needed by AttemptCompletionTool for delegation handling.
2626
*/
2727
interface DelegationProvider {
28+
log(message: string): void
2829
getTaskWithId(id: string): Promise<{ historyItem: HistoryItem }>
2930
reopenParentFromDelegation(params: {
3031
parentTaskId: string
@@ -118,20 +119,25 @@ export class AttemptCompletionTool extends BaseTool<"attempt_completion"> {
118119
} else {
119120
// Parent already detached, such as when the user cancelled this child.
120121
// Fall through to the normal completion ask flow.
122+
provider.log(
123+
`[AttemptCompletionTool] Skipping delegation for child ${task.taskId}: ` +
124+
`parent ${task.parentTaskId} is not awaiting this child. ` +
125+
`Diagnostic: { childStatus: "${status}", parentStatus: "${parentHistory?.status}", awaitingChildId: "${parentHistory?.awaitingChildId}" }`,
126+
)
121127
}
122128
} else {
123129
// Unexpected status (undefined or "delegated") - log error and skip delegation
124130
// undefined indicates a bug in status persistence during child creation
125131
// "delegated" would mean this child has its own grandchild pending (shouldn't reach attempt_completion)
126-
console.error(
132+
provider.log(
127133
`[AttemptCompletionTool] Unexpected child task status "${status}" for task ${task.taskId}. ` +
128134
`Expected "active" or "completed". Skipping delegation to prevent data corruption.`,
129135
)
130136
// Fall through to normal completion ask flow
131137
}
132138
} catch (err) {
133139
// If we can't get the history, log error and skip delegation
134-
console.error(
140+
provider.log(
135141
`[AttemptCompletionTool] Failed to get history for task ${historyLookupTaskId}: ${(err as Error)?.message ?? String(err)}. ` +
136142
`Skipping delegation.`,
137143
)

‎src/core/tools/__tests__/attemptCompletionTool.spec.ts‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -493,6 +493,7 @@ describe("attemptCompletionTool", () => {
493493
partial: false,
494494
}
495495
const mockProvider = {
496+
log: vi.fn(),
496497
getTaskWithId: vi.fn().mockImplementation((id: string) => {
497498
if (id === "child-1") {
498499
return Promise.resolve({ historyItem: { id, status: "active" } })
@@ -543,6 +544,7 @@ describe("attemptCompletionTool", () => {
543544
partial: false,
544545
}
545546
const mockProvider = {
547+
log: vi.fn(),
546548
getTaskWithId: vi.fn().mockImplementation((id: string) => {
547549
if (id === "child-1") {
548550
return Promise.resolve({ historyItem: { id, status: "active" } })
@@ -594,6 +596,7 @@ describe("attemptCompletionTool", () => {
594596
partial: false,
595597
}
596598
const mockProvider = {
599+
log: vi.fn(),
597600
getTaskWithId: vi.fn().mockImplementation((id: string) => {
598601
if (id === "child-1") {
599602
return Promise.resolve({ historyItem: { id, status: "active" } })
@@ -627,6 +630,7 @@ describe("attemptCompletionTool", () => {
627630

628631
expect(mockAskFinishSubTaskApproval).not.toHaveBeenCalled()
629632
expect(mockProvider.reopenParentFromDelegation).not.toHaveBeenCalled()
633+
expect(mockProvider.log).toHaveBeenCalledWith(expect.stringContaining("Skipping delegation"))
630634
expect(mockTask.ask).toHaveBeenCalledWith("completion_result", "", false)
631635
expect(mockCaptureTaskCompleted).toHaveBeenCalledWith("child-1")
632636
})

‎src/core/webview/ClineProvider.ts‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -469,6 +469,8 @@ export class ClineProvider
469469
// Removes and destroys the top Cline instance (the current finished task),
470470
// activating the previous one (resuming the parent task).
471471
async removeClineFromStack(options?: { skipDelegationRepair?: boolean }) {
472+
const callerStack = new Error().stack
473+
472474
if (this.clineStack.length === 0) {
473475
return
474476
}
@@ -525,7 +527,8 @@ export class ClineProvider
525527
awaitingChildId: undefined,
526528
})
527529
this.log(
528-
`[ClineProvider#removeClineFromStack] Repaired parent ${parentTaskId} metadata: delegated → active (child ${childTaskId} removed)`,
530+
`[ClineProvider#removeClineFromStack] Repaired parent ${parentTaskId} metadata: delegated → active (child ${childTaskId} removed). ` +
531+
`Caller stack: ${callerStack?.split("\n").slice(1, 5).join(" | ")}`,
529532
)
530533
}
531534
})

0 commit comments

Comments
 (0)