From f90e3e5a18581b8640151bdf42e0a1cb002e1c5e Mon Sep 17 00:00:00 2001 From: merge-check <140916359+agentHits@users.noreply.github.com> Date: Tue, 13 Oct 2026 13:46:25 -0400 Subject: [PATCH] test(ci): share shell shims between acme-delete tests, and print the build log when a real deploy test fails Two tests failed a PR check on a busy self-hosted macOS runner although the PR had not touched them. acme-delete suites macOS checks every new executable file on its first run. Measured: about 0.25 s on an idle machine, 0.9-1.4 s for some files on the runner, once per file. A copy of the same script counts as new; a symlink or a hard link to a file that has already run does not. The harness wrote its docker, jq, timeout and ls shims again for every test, so every test paid for that check several times. In the time-limit tests the first run of the new ls shim fell inside the fake "docker start", which has a 5 s limit: 256 ms of that call on an idle machine. A start that is cut short leaves Traefik unconfirmed, and the script reports traefik_not_restarted instead of stop_failed. Both CI failures of this group had exactly that result. The stall past 5 s itself was not reproduced: under synthetic CPU load the check stayed below 1.2 s. - Each shim is now written once per test file, run once outside any time limit, and linked into the bin directory of each test. The fake start takes 24 ms instead of 256 ms, and the nine suites need 225 s of test time instead of 319 s on an idle machine. - The two time-limit tests where only "inspect" hangs give stop and start a 30 s limit. Both answer at once there, so it costs no time. - Those two tests print the script output when the result is not the expected one. real deploy tests The nixpacks test failed after 49 s, and its cleanup removed the build log, so the CI output held no reason. Repeated by hand in the same runner path, the clone took 2 s and the build 3 s from cache. - A failed test prints the last 80 lines of its deployment log before the cleanup removes it. - The suite retries a failed test once: every test in it depends on GitHub and on an image registry. Co-Authored-By: Claude Opus 5.5 --- .../__test__/deploy/application.real.test.ts | 26 +++++++++-- .../domain-overview/acme-delete-harness.ts | 43 +++++++++++++++++-- .../acme-delete-signals.test.ts | 16 +++++-- 3 files changed, 74 insertions(+), 11 deletions(-) diff --git a/apps/dokploy/__test__/deploy/application.real.test.ts b/apps/dokploy/__test__/deploy/application.real.test.ts index cc2b31ce4e1..e9834a1aac2 100644 --- a/apps/dokploy/__test__/deploy/application.real.test.ts +++ b/apps/dokploy/__test__/deploy/application.real.test.ts @@ -1,6 +1,6 @@ import { execSync } from "node:child_process"; import { createHash } from "node:crypto"; -import { existsSync } from "node:fs"; +import { existsSync, readFileSync } from "node:fs"; import path from "node:path"; import type { ApplicationNested } from "@dokploy/server"; import { paths } from "@dokploy/server/constants"; @@ -198,6 +198,17 @@ async function cleanupFiles(appName: string) { } } +const printDeploymentLog = (logPath: string | undefined) => { + if (!logPath || !existsSync(logPath)) { + console.log("๐Ÿ“„ The failed test left no deployment log"); + return; + } + const lines = readFileSync(logPath, "utf8").trimEnd().split("\n"); + console.log( + `๐Ÿ“„ Last lines of the deployment log (${lines.length} in total):\n${lines.slice(-80).join("\n")}`, + ); +}; + // A deploy ends in a swarm service, so a running daemon alone is not enough. const hasSwarm = () => { try { @@ -213,8 +224,12 @@ const hasSwarm = () => { }; // CI never skips: a runner that lost Docker has to fail, not go quiet. +// These tests clone from GitHub and resolve base images at a registry, so one +// failed attempt is retried: it may be the network, and its build log is +// printed either way. describe.skipIf(!process.env.CI && !hasSwarm())( "deployApplication - REAL Execution Tests", + { timeout: REAL_TEST_TIMEOUT, retry: 1 }, () => { let currentAppName: string; let currentDeployment: any; @@ -251,7 +266,13 @@ describe.skipIf(!process.env.CI && !hasSwarm())( ); }); - afterEach(async () => { + afterEach(async ({ task }) => { + // The cleanup below removes the build log, the only place where a + // failed clone or build says why. + if (task.result?.state === "fail") { + printDeploymentLog(currentDeployment?.logPath); + } + // ALWAYS cleanup, even if test failed or passed console.log(`\n๐Ÿงน Cleaning up test: ${currentAppName}`); @@ -551,5 +572,4 @@ describe.skipIf(!process.env.CI && !hasSwarm())( REAL_TEST_TIMEOUT, ); }, - REAL_TEST_TIMEOUT, ); diff --git a/apps/dokploy/__test__/domain-overview/acme-delete-harness.ts b/apps/dokploy/__test__/domain-overview/acme-delete-harness.ts index 703f8707982..a3371ebd13d 100644 --- a/apps/dokploy/__test__/domain-overview/acme-delete-harness.ts +++ b/apps/dokploy/__test__/domain-overview/acme-delete-harness.ts @@ -21,7 +21,7 @@ import { buildAcmeDeleteScript, parseDeletionStatus, } from "@dokploy/server/utils/domain-overview/acme-delete"; -import { afterEach, beforeEach, expect, it } from "vitest"; +import { afterAll, afterEach, beforeEach, expect, it } from "vitest"; const found = new Map(); @@ -245,10 +245,45 @@ export let markerFile: string; export let backupDir: string; export let logDir: string; +// macOS checks a new executable file on its first run. That takes a quarter of +// a second on an idle machine and longer on a busy one, and a copy of the same +// script is a new file again. Written per test, the shims paid for that check +// several times in every test, and it could land inside a docker call with a +// time limit. So each shim exists once per test file, is run once here, +// outside any limit, and is only linked afterwards. +const SHEBANG = "#!/bin/sh\n"; +const WARM_UP = "ACME_DELETE_TEST_WARM_UP"; +const shimDir = mkdtempSync(path.join(tmpdir(), "acme-delete-shims-")); +const shims = new Map(); + +const shimFor = (content: string) => { + const known = shims.get(content); + if (known) { + return known; + } + const file = path.join(shimDir, String(shims.size)); + const warmable = content.startsWith(SHEBANG); + writeFileSync( + file, + warmable + ? `${SHEBANG}[ -z "$${WARM_UP}" ] || exit 0\n${content.slice(SHEBANG.length)}` + : content, + ); + chmodSync(file, 0o755); + if (warmable) { + spawnSync(file, { env: { ...process.env, [WARM_UP]: "1" } }); + } + shims.set(content, file); + return file; +}; + +afterAll(() => { + rmSync(shimDir, { recursive: true, force: true }); +}); + export const writeExecutable = (file: string, content: string) => { rmSync(file, { force: true }); - writeFileSync(file, content); - chmodSync(file, 0o755); + symlinkSync(shimFor(content), file); }; export const TIMEOUT_SHIM = `#!/bin/sh @@ -312,7 +347,7 @@ export const setupBin = (options: { writeFileSync(path.join(binDir, "setsid.py"), SETSID_SHIM); writeExecutable( path.join(binDir, "setsid"), - `#!/bin/sh\nexec ${which("python3")} ${path.join(binDir, "setsid.py")} "$@"\n`, + `#!/bin/sh\nexec ${which("python3")} "$(dirname "$0")/setsid.py" "$@"\n`, ); } rmSync(path.join(binDir, "ls"), { force: true }); diff --git a/apps/dokploy/__test__/domain-overview/acme-delete-signals.test.ts b/apps/dokploy/__test__/domain-overview/acme-delete-signals.test.ts index 012765cd759..cc86418b5a6 100644 --- a/apps/dokploy/__test__/domain-overview/acme-delete-signals.test.ts +++ b/apps/dokploy/__test__/domain-overview/acme-delete-signals.test.ts @@ -189,10 +189,18 @@ describe.skipIf(!REAL_JQ).each(PRIMARY)( timeout: 80_000, }); + // Where only "inspect" hangs, stop and start answer at once, so a wide + // limit for them costs no time. A narrow one turns a start that stalls + // on a busy runner into traefik_not_restarted. + const wideStopLimit = { stopSeconds: 30 }; + it("counts the wait for the stop in time, not in rounds", () => { - const result = exec({ waitSeconds: 1 }, { FAKE_STATE_HANG: "1" }); + const result = exec( + { waitSeconds: 1, ...wideStopLimit }, + { FAKE_STATE_HANG: "1" }, + ); - expect(resultOf(result.stdout)).toBe("stop_failed"); + expect(resultOf(result.stdout), result.stdout).toBe("stop_failed"); const calls = callsOf(); const stopAt = calls.findIndex((c) => c.startsWith("stop ")); const startAt = calls.findIndex((c) => c.startsWith("start ")); @@ -206,11 +214,11 @@ describe.skipIf(!REAL_JQ).each(PRIMARY)( const started = Date.now(); const result = exec( - { waitSeconds: 60, deadlineSeconds: 2 }, + { waitSeconds: 60, deadlineSeconds: 2, ...wideStopLimit }, { FAKE_STATE_HANG: "1" }, ); - expect(["stop_failed", "deadline_exceeded"]).toContain( + expect(["stop_failed", "deadline_exceeded"], result.stdout).toContain( resultOf(result.stdout), ); expect(Date.now() - started).toBeLessThan(20_000);