fix(mcp): report download_job_log timeouts instead of empty logs

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<Uint8Array> | 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);
   }
 }
 

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<typeof Bun.serve>[] = [];
 
   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<Response>,
+  ): 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<Response>(() => {}));
+
+    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");
   });
 });