From 26f805aa216012f7eab4232510c3af655d0c69a3 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Fri, 7 Aug 2026 09:20:46 +0000 Subject: [PATCH] fix: stream compose logs during post cleanup Co-authored-by: neilime <314088+neilime@users.noreply.github.com> --- dist/index.js | 53 +++++++++--- dist/post.js | 81 +++++++++++++----- src/post-runner.test.ts | 41 +++++++-- src/post-runner.ts | 28 +++--- src/post.test.ts | 6 +- src/services/docker-compose.service.test.ts | 95 ++++++++++++++++----- src/services/docker-compose.service.ts | 63 +++++++++++--- 7 files changed, 277 insertions(+), 90 deletions(-) diff --git a/dist/index.js b/dist/index.js index 98e923d..1518b8a 100644 --- a/dist/index.js +++ b/dist/index.js @@ -26549,7 +26549,7 @@ var require_dist2 = __commonJS({ return (0, exports.restartMany)([service], options); }; exports.restartOne = restartOne; - var logs2 = function(services, options = {}) { + var logs = function(services, options = {}) { const args = Array.isArray(services) ? services : [services]; if (options.follow) { args.unshift("--follow"); @@ -26559,7 +26559,7 @@ var require_dist2 = __commonJS({ } return (0, exports.execCompose)("logs", args, options); }; - exports.logs = logs2; + exports.logs = logs; var port = async function(service, containerPort, options) { const args = [service, containerPort]; try { @@ -31374,6 +31374,7 @@ function info(message) { // src/services/docker-compose.service.ts var import_docker_compose = __toESM(require_dist2(), 1); +import { spawn as spawn2 } from "node:child_process"; var DockerComposeService = class { async up({ upFlags, services, ...optionsInputs }) { const options = { @@ -31402,15 +31403,30 @@ var DockerComposeService = class { } } async logs({ services, ...optionsInputs }) { - const options = { - ...this.getCommonOptions(optionsInputs), - follow: false - }; - const { err, out } = await (0, import_docker_compose.logs)(services, options); - return { - error: err, - output: out - }; + const commandArgs = this.getDockerComposeCommandArgs("logs", { + dockerFlags: optionsInputs.dockerFlags, + composeFlags: optionsInputs.composeFlags, + composeFiles: optionsInputs.composeFiles, + commandArgs: services + }); + return await new Promise((resolve2, reject) => { + const childProcess = spawn2("docker", commandArgs, { + cwd: optionsInputs.cwd + }); + childProcess.on("error", reject); + childProcess.stdout.on("data", (chunk) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.stderr.on("data", (chunk) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.on("close", (exitCode) => { + resolve2({ + error: exitCode && exitCode !== 0 ? `Docker Compose logs command failed with exit code ${exitCode}` : "", + output: "" + }); + }); + }); } getCommonOptions({ dockerFlags, @@ -31430,6 +31446,21 @@ var DockerComposeService = class { } }; } + getDockerComposeCommandArgs(command, { + dockerFlags, + composeFlags, + composeFiles, + commandArgs + }) { + return [ + ...dockerFlags, + "compose", + ...composeFlags, + ...composeFiles.flatMap((composeFile) => ["-f", composeFile]), + command, + ...commandArgs + ]; + } /** * Formats docker-compose errors into proper Error objects with readable messages */ diff --git a/dist/post.js b/dist/post.js index 706f1df..b7e9341 100644 --- a/dist/post.js +++ b/dist/post.js @@ -26549,7 +26549,7 @@ var require_dist2 = __commonJS({ return (0, exports.restartMany)([service], options); }; exports.restartOne = restartOne; - var logs2 = function(services, options = {}) { + var logs = function(services, options = {}) { const args = Array.isArray(services) ? services : [services]; if (options.follow) { args.unshift("--follow"); @@ -26559,7 +26559,7 @@ var require_dist2 = __commonJS({ } return (0, exports.execCompose)("logs", args, options); }; - exports.logs = logs2; + exports.logs = logs; var port = async function(service, containerPort, options) { const args = [service, containerPort]; try { @@ -27111,6 +27111,7 @@ function info(message) { // src/services/docker-compose.service.ts var import_docker_compose = __toESM(require_dist2(), 1); +import { spawn } from "node:child_process"; var DockerComposeService = class { async up({ upFlags, services, ...optionsInputs }) { const options = { @@ -27139,15 +27140,30 @@ var DockerComposeService = class { } } async logs({ services, ...optionsInputs }) { - const options = { - ...this.getCommonOptions(optionsInputs), - follow: false - }; - const { err, out } = await (0, import_docker_compose.logs)(services, options); - return { - error: err, - output: out - }; + const commandArgs = this.getDockerComposeCommandArgs("logs", { + dockerFlags: optionsInputs.dockerFlags, + composeFlags: optionsInputs.composeFlags, + composeFiles: optionsInputs.composeFiles, + commandArgs: services + }); + return await new Promise((resolve, reject) => { + const childProcess = spawn("docker", commandArgs, { + cwd: optionsInputs.cwd + }); + childProcess.on("error", reject); + childProcess.stdout.on("data", (chunk) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.stderr.on("data", (chunk) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.on("close", (exitCode) => { + resolve({ + error: exitCode && exitCode !== 0 ? `Docker Compose logs command failed with exit code ${exitCode}` : "", + output: "" + }); + }); + }); } getCommonOptions({ dockerFlags, @@ -27167,6 +27183,21 @@ var DockerComposeService = class { } }; } + getDockerComposeCommandArgs(command, { + dockerFlags, + composeFlags, + composeFiles, + commandArgs + }) { + return [ + ...dockerFlags, + "compose", + ...composeFlags, + ...composeFiles.flatMap((composeFile) => ["-f", composeFile]), + command, + ...commandArgs + ]; + } /** * Formats docker-compose errors into proper Error objects with readable messages */ @@ -27335,20 +27366,24 @@ async function run() { const inputService = new InputService(); const dockerComposeService = new DockerComposeService(); const inputs = inputService.getInputs(); - const { error: error2, output } = await dockerComposeService.logs({ - dockerFlags: inputs.dockerFlags, - composeFiles: inputs.composeFiles, - composeFlags: inputs.composeFlags, - cwd: inputs.cwd, - services: inputs.services, - serviceLogger: loggerService.getServiceLogger(inputs.serviceLogLevel) - }); - if (error2) { - loggerService.debug(`docker compose error: + try { + const { error: error2 } = await dockerComposeService.logs({ + dockerFlags: inputs.dockerFlags, + composeFiles: inputs.composeFiles, + composeFlags: inputs.composeFlags, + cwd: inputs.cwd, + services: inputs.services, + serviceLogger: loggerService.getServiceLogger(inputs.serviceLogLevel) + }); + if (error2) { + loggerService.debug(`docker compose error: ${error2}`); + } + } catch (error2) { + loggerService.warn( + `Unable to collect docker compose logs before cleanup: ${error2 instanceof Error ? error2.message : JSON.stringify(error2)}` + ); } - loggerService.debug(`docker compose logs: -${output}`); await dockerComposeService.down({ dockerFlags: inputs.dockerFlags, composeFiles: inputs.composeFiles, diff --git a/src/post-runner.test.ts b/src/post-runner.test.ts index df7fafa..0ec6538 100644 --- a/src/post-runner.test.ts +++ b/src/post-runner.test.ts @@ -42,6 +42,7 @@ const { DockerComposeService } = await import( describe("run", () => { let infoMock: ReturnType; let debugMock: ReturnType; + let warnMock: ReturnType; let getInputsMock: ReturnType; let serviceDownMock: ReturnType; let serviceLogsMock: ReturnType; @@ -55,12 +56,15 @@ describe("run", () => { debugMock = vi .spyOn(LoggerService.prototype, "debug") .mockImplementation(() => {}); + warnMock = vi + .spyOn(LoggerService.prototype, "warn") + .mockImplementation(() => {}); getInputsMock = vi.spyOn(InputService.prototype, "getInputs"); serviceDownMock = vi.spyOn(DockerComposeService.prototype, "down"); serviceLogsMock = vi.spyOn(DockerComposeService.prototype, "logs"); }); - it("should bring down docker compose service(s) and log output", async () => { + it("should bring down docker compose service(s)", async () => { // Arrange getInputsMock.mockImplementation(() => ({ dockerFlags: [], @@ -75,7 +79,7 @@ describe("run", () => { serviceLogLevel: LogLevel.Debug, })); - serviceLogsMock.mockResolvedValue({ error: "", output: "test logs" }); + serviceLogsMock.mockResolvedValue({ error: "", output: "" }); serviceDownMock.mockResolvedValue(); // Act @@ -100,12 +104,11 @@ describe("run", () => { serviceLogger: debugMock, }); - expect(debugMock).toHaveBeenCalledWith("docker compose logs:\ntest logs"); expect(infoMock).toHaveBeenCalledWith("docker compose is down"); expect(setFailedMock).not.toHaveBeenCalled(); }); - it("should log docker composer errors if any", async () => { + it("should log docker compose command errors if any", async () => { // Arrange getInputsMock.mockImplementation(() => ({ dockerFlags: [], @@ -134,12 +137,36 @@ describe("run", () => { expect(debugMock).toHaveBeenCalledWith( "docker compose error:\ntest logs error", ); - expect(debugMock).toHaveBeenCalledWith( - "docker compose logs:\ntest logs output", - ); expect(infoMock).toHaveBeenCalledWith("docker compose is down"); }); + it("should continue cleanup when collecting logs fails", async () => { + getInputsMock.mockImplementation(() => ({ + dockerFlags: [], + composeFiles: ["docker-compose.yml"], + services: [], + composeFlags: [], + upFlags: [], + downFlags: [], + cwd: "/current/working/dir", + composeVersion: null, + githubToken: null, + serviceLogLevel: LogLevel.Debug, + })); + + serviceLogsMock.mockRejectedValue(new Error("Test logs error")); + serviceDownMock.mockResolvedValue(); + + await run(); + + expect(warnMock).toHaveBeenCalledWith( + "Unable to collect docker compose logs before cleanup: Test logs error", + ); + expect(serviceDownMock).toHaveBeenCalled(); + expect(infoMock).toHaveBeenCalledWith("docker compose is down"); + expect(setFailedMock).not.toHaveBeenCalled(); + }); + it("should set failed when an error occurs", async () => { // Arrange getInputsMock.mockImplementation(() => { diff --git a/src/post-runner.ts b/src/post-runner.ts index 67adb42..b34fee4 100644 --- a/src/post-runner.ts +++ b/src/post-runner.ts @@ -15,21 +15,25 @@ export async function run(): Promise { const inputs = inputService.getInputs(); - const { error, output } = await dockerComposeService.logs({ - dockerFlags: inputs.dockerFlags, - composeFiles: inputs.composeFiles, - composeFlags: inputs.composeFlags, - cwd: inputs.cwd, - services: inputs.services, - serviceLogger: loggerService.getServiceLogger(inputs.serviceLogLevel), - }); + try { + const { error } = await dockerComposeService.logs({ + dockerFlags: inputs.dockerFlags, + composeFiles: inputs.composeFiles, + composeFlags: inputs.composeFlags, + cwd: inputs.cwd, + services: inputs.services, + serviceLogger: loggerService.getServiceLogger(inputs.serviceLogLevel), + }); - if (error) { - loggerService.debug(`docker compose error:\n${error}`); + if (error) { + loggerService.debug(`docker compose error:\n${error}`); + } + } catch (error) { + loggerService.warn( + `Unable to collect docker compose logs before cleanup: ${error instanceof Error ? error.message : JSON.stringify(error)}`, + ); } - loggerService.debug(`docker compose logs:\n${output}`); - await dockerComposeService.down({ dockerFlags: inputs.dockerFlags, composeFiles: inputs.composeFiles, diff --git a/src/post.test.ts b/src/post.test.ts index fa71db1..a9a618b 100644 --- a/src/post.test.ts +++ b/src/post.test.ts @@ -73,7 +73,7 @@ describe("post", () => { serviceLogLevel: LogLevel.Debug, })); - serviceLogsMock.mockResolvedValue({ error: "", output: "test logs" }); + serviceLogsMock.mockResolvedValue({ error: "", output: "" }); serviceDownMock.mockResolvedValueOnce(); await import("./post.js"); @@ -97,10 +97,6 @@ describe("post", () => { serviceLogger: debugMock, }); - expect(debugMock).toHaveBeenNthCalledWith( - 1, - "docker compose logs:\ntest logs", - ); expect(infoMock).toHaveBeenNthCalledWith(1, "docker compose is down"); expect(setFailedMock).not.toHaveBeenCalled(); diff --git a/src/services/docker-compose.service.test.ts b/src/services/docker-compose.service.test.ts index f94582c..ecc82d5 100644 --- a/src/services/docker-compose.service.test.ts +++ b/src/services/docker-compose.service.test.ts @@ -1,8 +1,8 @@ import type { - IDockerComposeLogOptions, IDockerComposeOptions, IDockerComposeResult, } from "docker-compose"; +import { EventEmitter } from "node:events"; import { beforeEach, describe, expect, it, vi } from "vitest"; // Mock docker-compose before importing the module under test @@ -17,19 +17,16 @@ const upManyMock = >(); const downMock = vi.fn<(options: IDockerComposeOptions) => Promise>(); -const logsMock = - vi.fn< - ( - services: string[], - options: IDockerComposeLogOptions, - ) => Promise - >(); +const spawnMock = vi.fn(); vi.doMock("docker-compose", () => ({ upAll: upAllMock, upMany: upManyMock, down: downMock, - logs: logsMock, +})); + +vi.doMock("node:child_process", () => ({ + spawn: spawnMock, })); // Dynamic import after mock setup @@ -360,7 +357,7 @@ describe("DockerComposeService", () => { }); describe("logs", () => { - it("should call logs with correct options", async () => { + it("should stream logs with correct command arguments", async () => { const debugMock = vi.fn(); const logsInputs = { dockerFlags: [] as string[], @@ -371,20 +368,76 @@ describe("DockerComposeService", () => { serviceLogger: debugMock, }; - logsMock.mockResolvedValue({ exitCode: 0, err: "", out: "logs" }); + const stdout = new EventEmitter(); + const stderr = new EventEmitter(); + const childProcess = new EventEmitter() as EventEmitter & { + stdout: EventEmitter; + stderr: EventEmitter; + }; + childProcess.stdout = stdout; + childProcess.stderr = stderr; + spawnMock.mockReturnValue(childProcess); - await service.logs(logsInputs); + const logsPromise = service.logs(logsInputs); - expect(logsMock).toHaveBeenCalledWith(["helloworld2", "helloworld3"], { - composeOptions: [], - config: ["docker-compose.yml"], + expect(spawnMock).toHaveBeenCalledWith("docker", [ + "compose", + "-f", + "docker-compose.yml", + "logs", + "helloworld2", + "helloworld3", + ], { cwd: "/current/working/dir", - executable: { - executablePath: "docker", - options: [], - }, - follow: false, - callback: expect.any(Function), + }); + + stdout.emit("data", Buffer.from("logs")); + stderr.emit("data", Buffer.from("error logs")); + childProcess.emit("close", 0); + + await expect(logsPromise).resolves.toEqual({ error: "", output: "" }); + expect(debugMock).toHaveBeenNthCalledWith(1, "logs"); + expect(debugMock).toHaveBeenNthCalledWith(2, "error logs"); + }); + + it("should return a non-fatal error message when logs command fails", async () => { + const logsInputs = { + dockerFlags: ["--context", "dev"] as string[], + composeFiles: ["docker-compose.yml"] as string[], + services: [] as string[], + composeFlags: ["--profile", "ci"] as string[], + cwd: "/current/working/dir", + serviceLogger: vi.fn(), + }; + + const childProcess = new EventEmitter() as EventEmitter & { + stdout: EventEmitter; + stderr: EventEmitter; + }; + childProcess.stdout = new EventEmitter(); + childProcess.stderr = new EventEmitter(); + spawnMock.mockReturnValue(childProcess); + + const logsPromise = service.logs(logsInputs); + + expect(spawnMock).toHaveBeenCalledWith("docker", [ + "--context", + "dev", + "compose", + "--profile", + "ci", + "-f", + "docker-compose.yml", + "logs", + ], { + cwd: "/current/working/dir", + }); + + childProcess.emit("close", 1); + + await expect(logsPromise).resolves.toEqual({ + error: "Docker Compose logs command failed with exit code 1", + output: "", }); }); }); diff --git a/src/services/docker-compose.service.ts b/src/services/docker-compose.service.ts index e38b0f4..d5686e5 100644 --- a/src/services/docker-compose.service.ts +++ b/src/services/docker-compose.service.ts @@ -1,9 +1,8 @@ +import { spawn } from "node:child_process"; import { down, - type IDockerComposeLogOptions, type IDockerComposeOptions, type IDockerComposeResult, - logs, upAll, upMany, } from "docker-compose"; @@ -60,17 +59,35 @@ export class DockerComposeService { error: string; output: string; }> { - const options: IDockerComposeLogOptions = { - ...this.getCommonOptions(optionsInputs), - follow: false, - }; + const commandArgs = this.getDockerComposeCommandArgs("logs", { + dockerFlags: optionsInputs.dockerFlags, + composeFlags: optionsInputs.composeFlags, + composeFiles: optionsInputs.composeFiles, + commandArgs: services, + }); - const { err, out } = await logs(services, options); + return await new Promise((resolve, reject) => { + const childProcess = spawn("docker", commandArgs, { + cwd: optionsInputs.cwd, + }); - return { - error: err, - output: out, - }; + childProcess.on("error", reject); + childProcess.stdout.on("data", (chunk: Buffer) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.stderr.on("data", (chunk: Buffer) => { + optionsInputs.serviceLogger(chunk.toString()); + }); + childProcess.on("close", (exitCode) => { + resolve({ + error: + exitCode && exitCode !== 0 + ? `Docker Compose logs command failed with exit code ${exitCode}` + : "", + output: "", + }); + }); + }); } private getCommonOptions({ @@ -92,6 +109,30 @@ export class DockerComposeService { }; } + private getDockerComposeCommandArgs( + command: string, + { + dockerFlags, + composeFlags, + composeFiles, + commandArgs, + }: { + dockerFlags: string[]; + composeFlags: string[]; + composeFiles: string[]; + commandArgs: string[]; + }, + ): string[] { + return [ + ...dockerFlags, + "compose", + ...composeFlags, + ...composeFiles.flatMap((composeFile) => ["-f", composeFile]), + command, + ...commandArgs, + ]; + } + /** * Formats docker-compose errors into proper Error objects with readable messages */