diff --git a/apps/vscode-e2e/AGENTS.md b/apps/vscode-e2e/AGENTS.md index 8d9a4defac..ccd4c4910e 100644 --- a/apps/vscode-e2e/AGENTS.md +++ b/apps/vscode-e2e/AGENTS.md @@ -121,6 +121,17 @@ Example: The `model` field can be added to either match when a test targets a specific model. +## Delaying a fixture response (simulating a slow or hung provider) + +Use `streamingProfile: { ttft: }` on a fixture, not a flat `latency: `, when a test needs +to simulate a slow or hung provider (e.g. to cancel an in-flight request mid-stream). `ttft` delays +only the first SSE chunk, so the pending window is exactly the configured value. Flat `latency` +delays _every_ chunk, and aimock never observes client disconnects — after a test cancels the +request, a flat-latency stream keeps flushing chunks server-side for `chunks × latency` before +reaching the dead socket, which can interleave with the next test's request against the same mock +server. See `SUBTASK_API_HANG_RESPONSE_LATENCY_MS` in `fixtures/subtasks.ts` for an example, +including the bounded post-test drain the calling suite uses to wait out that window. + ## 404 errors in logs are expected 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. diff --git a/apps/vscode-e2e/src/fixtures/subtasks.ts b/apps/vscode-e2e/src/fixtures/subtasks.ts index f5dfc813df..30d3852b0a 100644 --- a/apps/vscode-e2e/src/fixtures/subtasks.ts +++ b/apps/vscode-e2e/src/fixtures/subtasks.ts @@ -33,6 +33,12 @@ export const SUBTASK_API_HANG_RESUME_MESSAGE = "Continue after provider hang." export const SUBTASK_API_HANG_CHILD_RESULT = "Hung child completed" export const SUBTASK_API_HANG_PARENT_RESULT = "API hang parent resumed" +// How long the API-hang child's first mocked response stays pending before its first SSE +// chunk. Shared with the subtask suite so its post-test drain waits exactly one window. +// Correctness depends on no flat `latency` (fixture or LLMock default) being set on that +// fixture — a flat latency would apply to every chunk after the first, not just the ttft. +export const SUBTASK_API_HANG_RESPONSE_LATENCY_MS = 15_000 + // Abandon-subtask scenario (#559) — separate markers to avoid sequenceIndex collisions with the // interrupted-child-resumes tests above, which exhaust the sequence count for INTERRUPT markers. const SUBTASK_ABANDON_PARENT_MARKER = "SUBTASK_PARENT_ABANDON_SEVER" @@ -261,8 +267,14 @@ export function addSubtaskFixtures(mock: InstanceType) { userMessage: apiHangChildMatch, sequenceIndex: 0, }, - // Keep the first child response pending long enough for the e2e test to cancel an in-flight API request. - latency: 15_000, + // Keep the first child response pending long enough for the e2e test to cancel an in-flight + // API request. Delay only the first chunk (ttft) rather than using flat `latency`: aimock + // applies `latency` to EVERY chunk and never observes client disconnects, so after the test + // cancels, a flat-latency stream would stay pending server-side for chunks × latency before + // flushing to the dead socket. With ttft the pending window is exactly + // SUBTASK_API_HANG_RESPONSE_LATENCY_MS (see its doc comment for the no-flat-latency + // invariant this relies on), which is what the suite's post-test drain waits out. + streamingProfile: { ttft: SUBTASK_API_HANG_RESPONSE_LATENCY_MS }, response: { toolCalls: [ { diff --git a/apps/vscode-e2e/src/suite/subtasks.test.ts b/apps/vscode-e2e/src/suite/subtasks.test.ts index 9e1d0e83cb..0c0d410f90 100644 --- a/apps/vscode-e2e/src/suite/subtasks.test.ts +++ b/apps/vscode-e2e/src/suite/subtasks.test.ts @@ -16,6 +16,7 @@ import { SUBTASK_API_HANG_PARENT_MARKER, SUBTASK_API_HANG_PARENT_PROMPT, SUBTASK_API_HANG_PARENT_RESULT, + SUBTASK_API_HANG_RESPONSE_LATENCY_MS, SUBTASK_API_HANG_RESUME_MESSAGE, SUBTASK_CHILD_FOLLOWUP_ANSWER, SUBTASK_FAST_CHILD_RESULT, @@ -33,6 +34,7 @@ import { type AimockMessageContent = string | Array<{ type?: string; text?: string }> type AimockJournalEntry = { + timestamp?: number body?: { messages?: Array<{ role?: string @@ -49,24 +51,67 @@ const messageContentText = (content?: AimockMessageContent) => { return content?.map((part) => part.text ?? "").join("") ?? "" } -const waitForAimockRequestContaining = async (expectedText: string, excludeText?: string) => { +const fetchAimockJournal = async () => { const aimockUrl = process.env.AIMOCK_URL assert.ok(aimockUrl, "AIMOCK_URL must be set for aimock journal assertions") + const response = await fetch(`${aimockUrl}/__aimock/journal`) + return (await response.json()) as AimockJournalEntry[] +} + +const findAimockRequest = (entries: AimockJournalEntry[], expectedText: string, excludeText?: string) => + entries.find((entry) => { + const messages = entry.body?.messages + if (!messages) return false + const entryText = messages.map((m) => messageContentText(m.content)).join("") + if (excludeText && entryText.includes(excludeText)) return false + return messages.some( + (message) => message.role === "user" && messageContentText(message.content).includes(expectedText), + ) + }) + +// Waits for a matching request to appear in the aimock journal and returns its journal +// timestamp, so callers can anchor post-test drains to the exact request this test created. +const waitForAimockRequestContaining = async ( + expectedText: string, + excludeText?: string, +): Promise => { + let matchedAt: number | undefined + await waitFor(async () => { - const response = await fetch(`${aimockUrl}/__aimock/journal`) - const entries = (await response.json()) as AimockJournalEntry[] - - return entries.some((entry) => { - const messages = entry.body?.messages - if (!messages) return false - const entryText = messages.map((m) => messageContentText(m.content)).join("") - if (excludeText && entryText.includes(excludeText)) return false - return messages.some( - (message) => message.role === "user" && messageContentText(message.content).includes(expectedText), - ) - }) + matchedAt = findAimockRequest(await fetchAimockJournal(), expectedText, excludeText)?.timestamp + return matchedAt !== undefined }) + + return matchedAt +} + +// Grace period after the delayed window for aimock to flush the stream's remaining chunks to +// the dead socket. 500ms is an empirical margin for that flush plus socket teardown; if this +// suite becomes flaky again on slow CI runners, widen this value first. +const SUBTASK_API_HANG_DRAIN_GRACE_MS = 500 + +// aimock does not observe client disconnects: after the API-hang child request is cancelled, +// the mock keeps the delayed stream pending server-side until the fixture's ttft has fully +// elapsed, then flushes the remaining chunks to the dead socket. A streamed request opened by +// the next test can interleave with that late flush, so wait out the remainder of the delayed +// window before the next test runs. The deadline is anchored to the journal timestamp of the +// request this test created (never earlier traffic), and bounded by one latency window plus +// grace, so it cannot hide a genuine hang. +const waitForDelayedSubtaskStreamDrain = async (delayedRequestStartedAt: number | undefined) => { + if (delayedRequestStartedAt === undefined) { + // The delayed request never reached the mock (the test failed before cancelling + // an in-flight request), so there is no delayed stream to drain. + return + } + + const drainDeadlineMs = + delayedRequestStartedAt + SUBTASK_API_HANG_RESPONSE_LATENCY_MS + SUBTASK_API_HANG_DRAIN_GRACE_MS + const remainingMs = drainDeadlineMs - Date.now() + + if (remainingMs > 0) { + await sleep(remainingMs) + } } suite("Roo Code Subtasks", function () { @@ -482,6 +527,7 @@ suite("Roo Code Subtasks", function () { const api = globalThis.api const asks: Record = {} const says: Record = {} + let delayedChildRequestStartedAt: number | undefined const messageHandler = ({ taskId, message }: { taskId: string; message: ClineMessage }) => { if (message.type === "ask") { @@ -519,7 +565,10 @@ suite("Roo Code Subtasks", function () { return false }) - await waitForAimockRequestContaining(SUBTASK_API_HANG_CHILD_MARKER, SUBTASK_API_HANG_PARENT_MARKER) + delayedChildRequestStartedAt = await waitForAimockRequestContaining( + SUBTASK_API_HANG_CHILD_MARKER, + SUBTASK_API_HANG_PARENT_MARKER, + ) await api.cancelCurrentTask() @@ -580,6 +629,9 @@ suite("Roo Code Subtasks", function () { await api.clearCurrentTask() } await waitFor(() => api.getCurrentTaskStack().length === 0).catch(() => {}) + // Drain the cancelled delayed stream before the next test can open another + // streamed request against the mock. + await waitForDelayedSubtaskStreamDrain(delayedChildRequestStartedAt) } })