From 40fa6eea4ec0d01cffda6dac8a220a90241c2610 Mon Sep 17 00:00:00 2001 From: Kristof Siket Date: Tue, 6 Oct 2026 13:56:28 +0200 Subject: [PATCH] feat: stream the deploy output while it runs The deploy phase ran under spawnSync and printed its captured stdout only after the process exited, so a long deploy showed nothing in the job log until the end. Phases now run with spawn: each stdout chunk is written to the log as it arrives and also collected for the result parsing. Co-Authored-By: Claude Opus 5.5 --- main.mjs | 18 +++------ run.mjs | 31 +++++++++++++++ tests/run.test.mjs | 94 ++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 130 insertions(+), 13 deletions(-) create mode 100644 run.mjs create mode 100644 tests/run.test.mjs diff --git a/main.mjs b/main.mjs index 75a1b3d..a08ed3f 100644 --- a/main.mjs +++ b/main.mjs @@ -13,9 +13,10 @@ import { import { resolveCredential } from "./credentials.mjs"; import { deployedUrlsFromOutput } from "./deployment.mjs"; import { failurePatch, guardReport, makeReporter, mapPhase } from "./report.mjs"; +import { runCommand } from "./run.mjs"; -// Synchronous stdout keeps ::group:: markers ordered around child output: -// spawnSync blocks the event loop, so buffered async writes would flush late. +// Synchronous stdout keeps ::group:: markers ordered around child output, +// which reaches fd 1 directly or through runCommand's synchronous writes. const log = (line) => writeSync(1, `${line}\n`); const input = (name) => (process.env[`INPUT_${name.toUpperCase()}`] ?? "").trim(); @@ -83,16 +84,7 @@ async function runPhase(phase, command, args, capture = false) { // String commands come from the consuming repo's own workflow inputs and // run through a shell verbatim; argv arrays never touch a shell, so // event-controlled values like the stage name cannot inject. - const stdio = capture ? ["inherit", "pipe", "inherit"] : "inherit"; - // maxBuffer raised so a large but successful deploy is not misreported as a spawn failure. - const options = capture - ? { cwd: workdir, stdio, maxBuffer: 64 * 1024 * 1024 } - : { cwd: workdir, stdio }; - const result = args - ? spawnSync(command, args, options) - : spawnSync(command, { ...options, shell: true }); - const captured = capture && result.stdout ? result.stdout.toString() : ""; - if (captured) writeSync(1, captured); + const result = await runCommand(command, args, { cwd: workdir, capture }); log("::endgroup::"); if (result.status !== 0) { const error = @@ -102,7 +94,7 @@ async function runPhase(phase, command, args, capture = false) { : `${printable} exited with status ${result.status}`); await fail(phase, error); } - return captured; + return result.stdout; } const mode = input("mode") || "deploy"; diff --git a/run.mjs b/run.mjs new file mode 100644 index 0000000..c86d3b4 --- /dev/null +++ b/run.mjs @@ -0,0 +1,31 @@ +import { spawn } from "node:child_process"; +import { writeSync } from "node:fs"; + +/** + * Runs a command and resolves once it has exited. An argv array never + * touches a shell; a string command (args null) runs through one verbatim. + * + * With `capture`, stdout is piped: each chunk is written to the job log as it + * arrives and also collected, so the caller can parse the full output. stdin + * and stderr stay inherited, so the child writes them to the log directly. + * + * @returns {Promise<{ status?: number | null, signal?: string | null, error?: Error, stdout: string }>} + */ +export async function runCommand(command, args, { cwd, capture = false }) { + const options = { cwd, stdio: capture ? ["inherit", "pipe", "inherit"] : "inherit" }; + const child = args ? spawn(command, args, options) : spawn(command, { ...options, shell: true }); + const chunks = []; + child.stdout?.on("data", (chunk) => { + chunks.push(chunk); + writeSync(1, chunk); + }); + // A spawn failure emits "error" and then "close"; the first event wins. + const result = await new Promise((done) => { + child.on("error", (error) => done({ error })); + child.on("close", (status, signal) => done({ status, signal })); + }); + const stdout = Buffer.concat(chunks).toString(); + // Ends a partial last line so the next log line, such as ::endgroup::, starts on its own line. + if (stdout && !stdout.endsWith("\n")) writeSync(1, "\n"); + return { ...result, stdout }; +} diff --git a/tests/run.test.mjs b/tests/run.test.mjs new file mode 100644 index 0000000..afc52d3 --- /dev/null +++ b/tests/run.test.mjs @@ -0,0 +1,94 @@ +import assert from "node:assert/strict"; +import { spawn } from "node:child_process"; +import { test } from "node:test"; +import { deployedUrlsFromOutput } from "../deployment.mjs"; +import { runCommand } from "../run.mjs"; + +const RUN_MODULE = new URL("../run.mjs", import.meta.url).href; + +// Runs a fake command through runCommand in a separate Node process, so its +// fd 1 writes can be observed as they happen. Resolves with every stdout chunk +// the wrapper wrote, each stamped with its arrival time, and the result. +function runFake(fakeScript, { capture = true } = {}) { + const wrapper = ` + import { runCommand } from ${JSON.stringify(RUN_MODULE)}; + import { writeFileSync } from "node:fs"; + const result = await runCommand(process.execPath, ["-e", ${JSON.stringify(fakeScript)}], { cwd: process.cwd(), capture: ${capture} }); + writeFileSync(3, JSON.stringify({ ...result, error: result.error?.code })); + `; + const child = spawn(process.execPath, ["--input-type=module", "-e", wrapper], { + stdio: ["ignore", "pipe", "inherit", "pipe"], + }); + const writes = []; + let resultJson = ""; + child.stdout.on("data", (chunk) => writes.push({ at: Date.now(), text: chunk.toString() })); + child.stdio[3].on("data", (chunk) => { + resultJson += chunk; + }); + return new Promise((done) => { + child.on("close", () => done({ writes, result: JSON.parse(resultJson) })); + }); +} + +test("writes each stdout line to the log before the command exits", async () => { + const { writes, result } = await runFake( + 'console.log("first"); setTimeout(() => console.log("second"), 500);', + ); + const first = writes.find((w) => w.text.includes("first")); + const second = writes.find((w) => w.text.includes("second")); + assert.ok(first && second); + assert.ok(!first.text.includes("second"), "first and second arrived in one write"); + assert.ok(second.at - first.at >= 300, `second arrived ${second.at - first.at}ms after first`); + assert.equal(result.stdout, "first\nsecond\n"); + assert.equal(result.status, 0); +}); + +test("collects a result line split across writes and parses it as before", async () => { + const line = JSON.stringify({ + kind: "result", + envelope: { + commandId: "deploy", + result: { + summary: { + nodes: [{ address: "app", entities: [{ kind: "compute-service", url: "https://abc.ewr.prisma.build" }] }], + }, + }, + }, + }); + const half = Math.floor(line.length / 2); + const { writes, result } = await runFake( + `process.stdout.write(${JSON.stringify(`deploying\n${line.slice(0, half)}`)}); + setTimeout(() => process.stdout.write(${JSON.stringify(line.slice(half))}), 200);`, + ); + assert.equal(result.stdout, `deploying\n${line}`); + assert.deepEqual(deployedUrlsFromOutput(result.stdout), { + urls: { app: "https://abc.ewr.prisma.build" }, + url: "https://abc.ewr.prisma.build", + }); + // The partial last line is ended in the log, but not in the collected stdout. + assert.equal(writes.map((w) => w.text).join(""), `deploying\n${line}\n`); +}); + +test("returns the exit status of a failing command", async () => { + const { result } = await runFake('console.log("boom"); process.exit(3);'); + assert.equal(result.status, 3); + assert.equal(result.stdout, "boom\n"); +}); + +test("returns the signal of a killed command", async () => { + const { result } = await runFake('process.kill(process.pid, "SIGTERM");'); + assert.equal(result.status, null); + assert.equal(result.signal, "SIGTERM"); +}); + +test("returns no stdout when output is not captured", async () => { + const { writes, result } = await runFake('console.log("inherited");', { capture: false }); + assert.equal(result.stdout, ""); + assert.equal(writes.map((w) => w.text).join(""), "inherited\n"); +}); + +test("returns the spawn error for a missing command", async () => { + const result = await runCommand("no-such-command-for-run-test", [], { cwd: process.cwd(), capture: true }); + assert.equal(result.error?.code, "ENOENT"); + assert.equal(result.stdout, ""); +});