Skip to content

Commit eace967

Browse files
zoomote[bot]roomoteedelauna
authored
[Fix] Subtask e2e suite can inherit a cancelled delayed mock stream from the previous test (#1074)
* test(e2e): drain delayed mock stream deterministically in subtask suite The API-hang subtask fixture used aimock's flat latency, which applies per SSE chunk and is never interrupted by client disconnects, so a cancelled delayed stream stayed pending server-side for chunks x latency and could flush into the next test's traffic. - delay only the first chunk via streamingProfile.ttft so the pending window is exactly the shared SUBTASK_API_HANG_RESPONSE_LATENCY_MS - anchor the post-test drain to the request's aimock journal timestamp and wait out only the remainder of that bounded window * docs(e2e): clarify subtask drain invariants from code review --------- Co-authored-by: Roomote <roomote@roomote.dev> Co-authored-by: Elliott de Launay <edelauna@gmail.com>
1 parent 5971caa commit eace967

3 files changed

Lines changed: 91 additions & 16 deletions

File tree

apps/vscode-e2e/AGENTS.md

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -121,6 +121,17 @@ Example:
121121
122122
The `model` field can be added to either match when a test targets a specific model.
123123
124+
## Delaying a fixture response (simulating a slow or hung provider)
125+
126+
Use `streamingProfile: { ttft: <ms> }` on a fixture, not a flat `latency: <ms>`, when a test needs
127+
to simulate a slow or hung provider (e.g. to cancel an in-flight request mid-stream). `ttft` delays
128+
only the first SSE chunk, so the pending window is exactly the configured value. Flat `latency`
129+
delays _every_ chunk, and aimock never observes client disconnects — after a test cancels the
130+
request, a flat-latency stream keeps flushing chunks server-side for `chunks × latency` before
131+
reaching the dead socket, which can interleave with the next test's request against the same mock
132+
server. See `SUBTASK_API_HANG_RESPONSE_LATENCY_MS` in `fixtures/subtasks.ts` for an example,
133+
including the bounded post-test drain the calling suite uses to wait out that window.
134+
124135
## 404 errors in logs are expected
125136

126137
Background API calls from the extension (usage collection, initialization) hit aimock with no matching fixture and return 404. These do **not** affect test results — the tests still pass. You'll see `[OpenRouter] API error: { message: '404 No fixture matched' }` in the output; this is normal.

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

Lines changed: 14 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,12 @@ export const SUBTASK_API_HANG_RESUME_MESSAGE = "Continue after provider hang."
3333
export const SUBTASK_API_HANG_CHILD_RESULT = "Hung child completed"
3434
export const SUBTASK_API_HANG_PARENT_RESULT = "API hang parent resumed"
3535

36+
// How long the API-hang child's first mocked response stays pending before its first SSE
37+
// chunk. Shared with the subtask suite so its post-test drain waits exactly one window.
38+
// Correctness depends on no flat `latency` (fixture or LLMock default) being set on that
39+
// fixture — a flat latency would apply to every chunk after the first, not just the ttft.
40+
export const SUBTASK_API_HANG_RESPONSE_LATENCY_MS = 15_000
41+
3642
// Abandon-subtask scenario (#559) — separate markers to avoid sequenceIndex collisions with the
3743
// interrupted-child-resumes tests above, which exhaust the sequence count for INTERRUPT markers.
3844
const SUBTASK_ABANDON_PARENT_MARKER = "SUBTASK_PARENT_ABANDON_SEVER"
@@ -261,8 +267,14 @@ export function addSubtaskFixtures(mock: InstanceType<typeof LLMock>) {
261267
userMessage: apiHangChildMatch,
262268
sequenceIndex: 0,
263269
},
264-
// Keep the first child response pending long enough for the e2e test to cancel an in-flight API request.
265-
latency: 15_000,
270+
// Keep the first child response pending long enough for the e2e test to cancel an in-flight
271+
// API request. Delay only the first chunk (ttft) rather than using flat `latency`: aimock
272+
// applies `latency` to EVERY chunk and never observes client disconnects, so after the test
273+
// cancels, a flat-latency stream would stay pending server-side for chunks × latency before
274+
// flushing to the dead socket. With ttft the pending window is exactly
275+
// SUBTASK_API_HANG_RESPONSE_LATENCY_MS (see its doc comment for the no-flat-latency
276+
// invariant this relies on), which is what the suite's post-test drain waits out.
277+
streamingProfile: { ttft: SUBTASK_API_HANG_RESPONSE_LATENCY_MS },
266278
response: {
267279
toolCalls: [
268280
{

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

Lines changed: 66 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ import {
1616
SUBTASK_API_HANG_PARENT_MARKER,
1717
SUBTASK_API_HANG_PARENT_PROMPT,
1818
SUBTASK_API_HANG_PARENT_RESULT,
19+
SUBTASK_API_HANG_RESPONSE_LATENCY_MS,
1920
SUBTASK_API_HANG_RESUME_MESSAGE,
2021
SUBTASK_CHILD_FOLLOWUP_ANSWER,
2122
SUBTASK_FAST_CHILD_RESULT,
@@ -33,6 +34,7 @@ import {
3334
type AimockMessageContent = string | Array<{ type?: string; text?: string }>
3435

3536
type AimockJournalEntry = {
37+
timestamp?: number
3638
body?: {
3739
messages?: Array<{
3840
role?: string
@@ -49,24 +51,67 @@ const messageContentText = (content?: AimockMessageContent) => {
4951
return content?.map((part) => part.text ?? "").join("") ?? ""
5052
}
5153

52-
const waitForAimockRequestContaining = async (expectedText: string, excludeText?: string) => {
54+
const fetchAimockJournal = async () => {
5355
const aimockUrl = process.env.AIMOCK_URL
5456
assert.ok(aimockUrl, "AIMOCK_URL must be set for aimock journal assertions")
5557

58+
const response = await fetch(`${aimockUrl}/__aimock/journal`)
59+
return (await response.json()) as AimockJournalEntry[]
60+
}
61+
62+
const findAimockRequest = (entries: AimockJournalEntry[], expectedText: string, excludeText?: string) =>
63+
entries.find((entry) => {
64+
const messages = entry.body?.messages
65+
if (!messages) return false
66+
const entryText = messages.map((m) => messageContentText(m.content)).join("")
67+
if (excludeText && entryText.includes(excludeText)) return false
68+
return messages.some(
69+
(message) => message.role === "user" && messageContentText(message.content).includes(expectedText),
70+
)
71+
})
72+
73+
// Waits for a matching request to appear in the aimock journal and returns its journal
74+
// timestamp, so callers can anchor post-test drains to the exact request this test created.
75+
const waitForAimockRequestContaining = async (
76+
expectedText: string,
77+
excludeText?: string,
78+
): Promise<number | undefined> => {
79+
let matchedAt: number | undefined
80+
5681
await waitFor(async () => {
57-
const response = await fetch(`${aimockUrl}/__aimock/journal`)
58-
const entries = (await response.json()) as AimockJournalEntry[]
59-
60-
return entries.some((entry) => {
61-
const messages = entry.body?.messages
62-
if (!messages) return false
63-
const entryText = messages.map((m) => messageContentText(m.content)).join("")
64-
if (excludeText && entryText.includes(excludeText)) return false
65-
return messages.some(
66-
(message) => message.role === "user" && messageContentText(message.content).includes(expectedText),
67-
)
68-
})
82+
matchedAt = findAimockRequest(await fetchAimockJournal(), expectedText, excludeText)?.timestamp
83+
return matchedAt !== undefined
6984
})
85+
86+
return matchedAt
87+
}
88+
89+
// Grace period after the delayed window for aimock to flush the stream's remaining chunks to
90+
// the dead socket. 500ms is an empirical margin for that flush plus socket teardown; if this
91+
// suite becomes flaky again on slow CI runners, widen this value first.
92+
const SUBTASK_API_HANG_DRAIN_GRACE_MS = 500
93+
94+
// aimock does not observe client disconnects: after the API-hang child request is cancelled,
95+
// the mock keeps the delayed stream pending server-side until the fixture's ttft has fully
96+
// elapsed, then flushes the remaining chunks to the dead socket. A streamed request opened by
97+
// the next test can interleave with that late flush, so wait out the remainder of the delayed
98+
// window before the next test runs. The deadline is anchored to the journal timestamp of the
99+
// request this test created (never earlier traffic), and bounded by one latency window plus
100+
// grace, so it cannot hide a genuine hang.
101+
const waitForDelayedSubtaskStreamDrain = async (delayedRequestStartedAt: number | undefined) => {
102+
if (delayedRequestStartedAt === undefined) {
103+
// The delayed request never reached the mock (the test failed before cancelling
104+
// an in-flight request), so there is no delayed stream to drain.
105+
return
106+
}
107+
108+
const drainDeadlineMs =
109+
delayedRequestStartedAt + SUBTASK_API_HANG_RESPONSE_LATENCY_MS + SUBTASK_API_HANG_DRAIN_GRACE_MS
110+
const remainingMs = drainDeadlineMs - Date.now()
111+
112+
if (remainingMs > 0) {
113+
await sleep(remainingMs)
114+
}
70115
}
71116

72117
suite("Roo Code Subtasks", function () {
@@ -482,6 +527,7 @@ suite("Roo Code Subtasks", function () {
482527
const api = globalThis.api
483528
const asks: Record<string, ClineMessage[]> = {}
484529
const says: Record<string, ClineMessage[]> = {}
530+
let delayedChildRequestStartedAt: number | undefined
485531

486532
const messageHandler = ({ taskId, message }: { taskId: string; message: ClineMessage }) => {
487533
if (message.type === "ask") {
@@ -519,7 +565,10 @@ suite("Roo Code Subtasks", function () {
519565
return false
520566
})
521567

522-
await waitForAimockRequestContaining(SUBTASK_API_HANG_CHILD_MARKER, SUBTASK_API_HANG_PARENT_MARKER)
568+
delayedChildRequestStartedAt = await waitForAimockRequestContaining(
569+
SUBTASK_API_HANG_CHILD_MARKER,
570+
SUBTASK_API_HANG_PARENT_MARKER,
571+
)
523572

524573
await api.cancelCurrentTask()
525574

@@ -580,6 +629,9 @@ suite("Roo Code Subtasks", function () {
580629
await api.clearCurrentTask()
581630
}
582631
await waitFor(() => api.getCurrentTaskStack().length === 0).catch(() => {})
632+
// Drain the cancelled delayed stream before the next test can open another
633+
// streamed request against the mock.
634+
await waitForDelayedSubtaskStreamDrain(delayedChildRequestStartedAt)
583635
}
584636
})
585637

0 commit comments

Comments
 (0)