From d94c943b92af00b564d9dd9ef5bc4dada3ba0dca Mon Sep 17 00:00:00 2001 From: awss Date: Thu, 24 Sep 2026 04:48:01 +0100 Subject: [PATCH] fix(mcp): report download_job_log timeouts instead of empty logs download_job_log bounded its request with a 30 s AbortController, but @octokit/request reads a successful text body with response.text().catch(() => ""). Once the 302 to blob storage has returned headers, the abort only interrupts that read, Octokit turns it into "", and downloadJobLog() wrote an empty job-.log and reported size_bytes: 0 as a success. The 30 s also covered the whole transfer, so a large log still arriving after 30 s came back empty the same way. Request the raw body stream (parseSuccessResponseBody: false) and read it chunk by chunk, so the abort reaches the tool as an error. The single deadline becomes a 30 s idle timeout, restarted whenever data arrives, plus a 5 minute total timeout for a download that trickles in without ever going idle. TextDecoder drops a leading BOM as response.text() did, so successful downloads write the same bytes as before. The tests now drive a real Octokit client against a local Bun.serve instead of a stubbed client: a stall before the headers, a stall mid-body, a stall after a 302, a slow download that keeps receiving data, and a trickle past the total timeout. --- src/mcp/github-actions-server.ts | 52 +++++++-- test/github-actions-server.test.ts | 168 ++++++++++++++++++++--------- 2 files changed, 159 insertions(+), 61 deletions(-) diff --git a/src/mcp/github-actions-server.ts b/src/mcp/github-actions-server.ts index e7421e193..224a2c28a 100644 --- a/src/mcp/github-actions-server.ts +++ b/src/mcp/github-actions-server.ts @@ -18,9 +18,11 @@ const GITHUB_TOKEN = process.env.GITHUB_TOKEN; const RUNNER_TEMP = process.env.RUNNER_TEMP || "/tmp"; // Job logs are fetched by ID from GitHub-hosted storage; bound the request so a -// stalled fetch can't hang this MCP call forever. Mirrors the timeout added to -// fetchImage() in src/github/utils/image-downloader.ts (#1625). -const DOWNLOAD_JOB_LOG_TIMEOUT_MS = 30_000; +// stalled fetch can't hang this MCP call forever. The idle timeout restarts +// whenever data arrives, so a large log on a slow link still finishes; the +// total timeout stops a download that trickles in without ever going idle. +const DOWNLOAD_JOB_LOG_IDLE_TIMEOUT_MS = 30_000; +const DOWNLOAD_JOB_LOG_TOTAL_TIMEOUT_MS = 5 * 60_000; if (import.meta.main) { if (!REPO_OWNER || !REPO_NAME || !PR_NUMBER || !GITHUB_TOKEN) { @@ -216,20 +218,53 @@ export async function downloadJobLog( client: Octokit, params: { owner: string; repo: string; job_id: number }, runnerTemp: string, - timeoutMs: number = DOWNLOAD_JOB_LOG_TIMEOUT_MS, + idleTimeoutMs: number = DOWNLOAD_JOB_LOG_IDLE_TIMEOUT_MS, + totalTimeoutMs: number = DOWNLOAD_JOB_LOG_TOTAL_TIMEOUT_MS, ): Promise<{ path: string; size_bytes: number }> { const controller = new AbortController(); - const timeoutHandle = setTimeout(() => controller.abort(), timeoutMs); + const idleHandle = setTimeout( + () => + controller.abort( + new Error( + `Job log download timed out after ${idleTimeoutMs}ms without receiving data`, + ), + ), + idleTimeoutMs, + ); + const totalHandle = setTimeout( + () => + controller.abort( + new Error( + `Job log download timed out after ${totalTimeoutMs}ms before it finished`, + ), + ), + totalTimeoutMs, + ); try { + // Octokit's own body parsing turns a failed read, including this abort, + // into an empty string, so read the raw stream instead. const response = await client.actions.downloadJobLogsForWorkflowRun({ owner: params.owner, repo: params.repo, job_id: params.job_id, - request: { signal: controller.signal }, + request: { signal: controller.signal, parseSuccessResponseBody: false }, }); - const logsText = response.data as unknown as string; + const chunks: Uint8Array[] = []; + const body = response.data as unknown as ReadableStream | null; + if (body) { + const reader = body.getReader(); + for (;;) { + idleHandle.refresh(); + const { done, value } = await reader.read(); + if (done) break; + chunks.push(value); + } + } + + // TextDecoder drops a leading BOM, as Octokit's response.text() did. + const logsText = new TextDecoder().decode(Buffer.concat(chunks)); const logsDir = `${runnerTemp}/github-ci-logs`; await mkdir(logsDir, { recursive: true }); @@ -242,7 +277,8 @@ export async function downloadJobLog( size_bytes: Buffer.byteLength(logsText, "utf-8"), }; } finally { - clearTimeout(timeoutHandle); + clearTimeout(idleHandle); + clearTimeout(totalHandle); } } diff --git a/test/github-actions-server.test.ts b/test/github-actions-server.test.ts index 953db1059..b77065821 100644 --- a/test/github-actions-server.test.ts +++ b/test/github-actions-server.test.ts @@ -2,11 +2,15 @@ import { describe, test, expect, afterEach } from "bun:test"; import { readFile, rm } from "fs/promises"; import os from "os"; import path from "path"; +import { Octokit } from "@octokit/rest"; import { downloadJobLog } from "../src/mcp/github-actions-server"; -import type { Octokit } from "@octokit/rest"; + +const JOB = { owner: "owner", repo: "repo", job_id: 123 }; +const IDLE_TIMEOUT_MS = 250; describe("downloadJobLog", () => { const tmpDirs: string[] = []; + const servers: ReturnType[] = []; const makeRunnerTemp = () => { const dir = path.join( @@ -17,78 +21,136 @@ describe("downloadJobLog", () => { return dir; }; + // A real Octokit client against a local server, so each case goes through + // Octokit's own fetch and body handling. + const serve = ( + handler: (req: Request) => Response | Promise, + ): Octokit => { + const server = Bun.serve({ port: 0, fetch: handler }); + servers.push(server); + return new Octokit({ baseUrl: server.url.origin }); + }; + + // Sends each chunk after pauseMs, then ends the body or leaves it open. + const logResponse = ( + chunks: string[], + pauseMs: number, + { stall = false } = {}, + ) => + new Response( + new ReadableStream({ + async start(controller) { + for (const chunk of chunks) { + await Bun.sleep(pauseMs); + controller.enqueue(new TextEncoder().encode(chunk)); + } + if (!stall) controller.close(); + }, + }), + { headers: { "content-type": "text/plain" } }, + ); + afterEach(async () => { + while (servers.length) { + servers.pop()!.stop(true); + } while (tmpDirs.length) { const dir = tmpDirs.pop()!; await rm(dir, { recursive: true, force: true }); } }); - const createStallingClient = (): { - client: Octokit; - getSignal: () => AbortSignal | undefined; - } => { - let signal: AbortSignal | undefined; - const client = { - actions: { - downloadJobLogsForWorkflowRun: (params: { - request?: { signal?: AbortSignal }; - }) => { - signal = params.request?.signal; - return new Promise((_resolve, reject) => { - signal?.addEventListener("abort", () => { - reject(new Error("This operation was aborted")); - }); - // Otherwise never settles, simulating a stalled fetch. - }); - }, - }, - } as unknown as Octokit; - return { client, getSignal: () => signal }; - }; + test("writes the log to disk when the download succeeds", async () => { + const client = serve(() => + logResponse(["log line 1\n", "log line 2\n"], 0), + ); + const runnerTemp = makeRunnerTemp(); + + const result = await downloadJobLog(client, JOB, runnerTemp); + + expect(result.path).toBe(`${runnerTemp}/github-ci-logs/job-123.log`); + expect(result.size_bytes).toBe( + Buffer.byteLength("log line 1\nlog line 2\n", "utf-8"), + ); + expect(await readFile(result.path, "utf-8")).toBe( + "log line 1\nlog line 2\n", + ); + }); + + test("rejects when no response arrives within the idle timeout", async () => { + const client = serve(() => new Promise(() => {})); + + await expect( + downloadJobLog(client, JOB, makeRunnerTemp(), IDLE_TIMEOUT_MS), + ).rejects.toThrow("timed out"); + }); - test("rejects with a timeout instead of hanging when the download stalls", async () => { - const { client, getSignal } = createStallingClient(); + test("rejects instead of writing an empty log when the body stalls", async () => { + const client = serve(() => + logResponse(["log line 1\n"], 0, { stall: true }), + ); const runnerTemp = makeRunnerTemp(); await expect( - downloadJobLog( - client, - { owner: "owner", repo: "repo", job_id: 123 }, - runnerTemp, - 5, - ), - ).rejects.toThrow(); + downloadJobLog(client, JOB, runnerTemp, IDLE_TIMEOUT_MS), + ).rejects.toThrow("timed out"); + expect( + await Bun.file(`${runnerTemp}/github-ci-logs/job-123.log`).exists(), + ).toBe(false); + }); - expect(getSignal()?.aborted).toBe(true); + test("rejects when the redirected log download stalls", async () => { + // GitHub answers with a 302 to blob storage, which serves the log body. + const client = serve((req) => + new URL(req.url).pathname === "/blob" + ? logResponse(["log line 1\n"], 0, { stall: true }) + : Response.redirect(new URL("/blob", req.url).toString(), 302), + ); + + await expect( + downloadJobLog(client, JOB, makeRunnerTemp(), IDLE_TIMEOUT_MS), + ).rejects.toThrow("timed out"); }); - test("writes the log to disk and clears the timeout when the download succeeds", async () => { - const runnerTemp = makeRunnerTemp(); - const client = { - actions: { - downloadJobLogsForWorkflowRun: async (params: { - request?: { signal?: AbortSignal }; - }) => { - expect(params.request?.signal?.aborted).toBe(false); - return { data: "log line 1\nlog line 2\n" }; - }, - }, - } as unknown as Octokit; + test("completes a slow download that keeps receiving data", async () => { + // 20 chunks 25 ms apart: about twice the idle timeout in total, but never + // idle for longer than a tenth of it. + const lines = Array.from({ length: 20 }, (_, i) => `log line ${i}\n`); + const client = serve(() => logResponse(lines, 25)); const result = await downloadJobLog( client, - { owner: "owner", repo: "repo", job_id: 456 }, - runnerTemp, - 30_000, + JOB, + makeRunnerTemp(), + IDLE_TIMEOUT_MS, ); - expect(result.path).toBe(`${runnerTemp}/github-ci-logs/job-456.log`); - expect(result.size_bytes).toBe( - Buffer.byteLength("log line 1\nlog line 2\n", "utf-8"), + expect(await readFile(result.path, "utf-8")).toBe(lines.join("")); + }); + + test("rejects a download that trickles in past the total timeout", async () => { + // One byte every 25 ms, forever: never idle, never finished. + const client = serve( + () => + new Response( + new ReadableStream({ + async pull(controller) { + await Bun.sleep(25); + controller.enqueue(new TextEncoder().encode("x")); + }, + }), + { headers: { "content-type": "text/plain" } }, + ), ); - const written = await readFile(result.path, "utf-8"); - expect(written).toBe("log line 1\nlog line 2\n"); + await expect( + downloadJobLog( + client, + JOB, + makeRunnerTemp(), + IDLE_TIMEOUT_MS, + 2 * IDLE_TIMEOUT_MS, + ), + ).rejects.toThrow("before it finished"); }); });