fix: surface real task error in swarm convergence timeout

This commit is contained in:
detail-app[bot] 2026-09-07 16:53:43 +00:00 committed by GitHub
parent 3b065db8a0
commit 4698bdb8e1
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 659 additions and 4 deletions

View File

@ -0,0 +1,270 @@
import { execSync } from "node:child_process";
import { randomBytes } from "node:crypto";
import { mkdtempSync, rmSync, writeFileSync } from "node:fs";
import { tmpdir } from "node:os";
import { join } from "node:path";
import {
ServiceConvergenceError,
waitForSwarmServiceConvergence,
} from "@dokploy/server/utils/docker/utils";
import { afterEach, beforeAll, describe, expect, it } from "vitest";
// Real-Docker end-to-end test. Gate on Swarm manager availability so the
// suite is a no-op in environments without a local swarm (CI unit runners).
const isSwarmManager = () => {
try {
execSync("docker node ls", { stdio: "ignore" });
return true;
} catch {
return false;
}
};
const skip = !isSwarmManager();
const testImage = "busybox:latest";
const uniqueSuffix = () => randomBytes(4).toString("hex");
const createdServices: string[] = [];
const ensureImage = () => {
execSync(
`docker image inspect ${testImage} >/dev/null 2>&1 || docker pull ${testImage}`,
{
stdio: "ignore",
},
);
};
const createService = (
name: string,
command: string[],
extra: string[] = [],
): string => {
const args = [
"service",
"create",
"--name",
name,
"--detach",
"--stop-grace-period=1s",
...extra,
testImage,
...command,
];
execSync(`docker ${args.map((a) => `"${a}"`).join(" ")}`, {
stdio: "ignore",
});
createdServices.push(name);
return name;
};
const removeService = (name: string) => {
try {
execSync(`docker service rm ${name}`, { stdio: "ignore" });
} catch {
// ignore
}
};
const updateServiceCommand = (name: string, command: string) => {
execSync(`docker service update --args "${command}" --detach ${name}`, {
stdio: "ignore",
});
};
const servicePsErrors = (name: string): string => {
try {
return execSync(
`docker service ps ${name} --no-trunc --filter desired-state=shutdown --format '{{.Error}}'`,
{ stdio: ["ignore", "pipe", "ignore"] },
)
.toString()
.trim();
} catch {
return "";
}
};
describe.skipIf(skip)("waitForSwarmServiceConvergence (real swarm)", () => {
beforeAll(() => {
ensureImage();
});
afterEach(() => {
for (const name of createdServices.splice(0)) {
removeService(name);
}
});
it("hard failure surfaces the real container error after convergence timeout", async () => {
const name = `itest-conv-fail-${uniqueSuffix()}`;
// exit 127 pre-start: container never reaches "running".
createService(name, ["/nonexistent-cmd"], ["--label", "itest=true"]);
let thrown: ServiceConvergenceError | undefined;
try {
await waitForSwarmServiceConvergence(name, null, {
timeoutMs: 20_000,
intervalMs: 1_000,
});
} catch (error) {
if (error instanceof ServiceConvergenceError) thrown = error;
else throw error;
}
if (!thrown) {
throw new Error("expected ServiceConvergenceError to be thrown");
}
expect(thrown).toBeInstanceOf(ServiceConvergenceError);
expect(thrown.message).toContain("did not converge within 20000ms");
expect(thrown.message).toContain("0/1 tasks running");
// Real container error (no such file) must be surfaced, not a
// misleading replacement state such as "new" / "preparing" / "ready"
// / "unknown" (the symptom in the bug report).
expect(thrown.message).toMatch(
/no such file|executable file not found|not found/i,
);
expect(thrown.message).not.toMatch(
/last state: (unknown|new|preparing|ready)\)/i,
);
}, 60_000);
it("cross-check: surfaced error matches docker service ps --no-trunc", async () => {
const name = `itest-conv-xcheck-${uniqueSuffix()}`;
createService(name, ["/nonexistent-cmd"], ["--label", "itest=true"]);
let thrown: ServiceConvergenceError | undefined;
try {
await waitForSwarmServiceConvergence(name, null, {
timeoutMs: 20_000,
intervalMs: 1_000,
});
} catch (error) {
if (error instanceof ServiceConvergenceError) thrown = error;
else throw error;
}
if (!thrown)
throw new Error("expected ServiceConvergenceError to be thrown");
// Give swarm a moment to settle the failed task's Status.Err into ps.
await new Promise((r) => setTimeout(r, 1500));
const psErrors = servicePsErrors(name);
const errorLines = psErrors
.split("\n")
.map((l) => l.trim())
.filter(Boolean);
expect(errorLines.length).toBeGreaterThan(0);
// At least one real error phrase reported by `docker service ps` must
// also appear in the surfaced convergence message (both derive from the
// task's Status.Err). A distinctive shared token ("not found", "No such
// file", "executable") is sufficient.
const msg = thrown.message.toLowerCase();
const shared = errorLines.some((line) => {
const l = line.toLowerCase();
return (
(l.includes("not found") && msg.includes("not found")) ||
(l.includes("no such file") && msg.includes("no such file")) ||
(l.includes("executable") && msg.includes("executable")) ||
(line.length > 8 && msg.includes(l))
);
});
expect(
shared,
`surface message was:\n${thrown.message}\nps errors:\n${psErrors}`,
).toBe(true);
}, 60_000);
it("happy-path deploy returns success without throwing", async () => {
const name = `itest-conv-ok-${uniqueSuffix()}`;
createService(name, ["sleep", "3600"], ["--label", "itest=true"]);
await expect(
waitForSwarmServiceConvergence(name, null, {
timeoutMs: 30_000,
intervalMs: 1_000,
}),
).resolves.toBeUndefined();
}, 60_000);
it("transient recovery still converges within the timeout window", async () => {
// A service that fails until a host-side marker file appears, then runs.
// Models a transient failure (e.g. a dependency that becomes available).
// The convergence function must return success (not throw) once a task
// reaches "running", exercising the unchanged success short-circuit.
const name = `itest-conv-transient-${uniqueSuffix()}`;
const hostDir = mkdtempSync(join(tmpdir(), "itest-marker-"));
try {
createService(
name,
["sh", "-c", "if [ ! -f /data/ready ]; then exit 1; fi; sleep 3600"],
[
"--label",
"itest=true",
"--restart-condition",
"any",
"--restart-delay",
"2s",
"--restart-max-attempts",
"0",
"--mount",
`type=bind,source=${hostDir},target=/data`,
],
);
// Let the service fail a couple of times, then "recover" the
// dependency by creating the marker file.
await new Promise((r) => setTimeout(r, 4000));
writeFileSync(join(hostDir, "ready"), "1");
const start = Date.now();
await expect(
waitForSwarmServiceConvergence(name, null, {
timeoutMs: 45_000,
intervalMs: 1_000,
}),
).resolves.toBeUndefined();
const elapsed = Date.now() - start;
// Converges well before the 45s timeout once the marker appears.
expect(elapsed).toBeLessThan(45_000);
} finally {
removeService(name);
rmSync(hostDir, { recursive: true, force: true });
}
}, 90_000);
it("stale-failure isolation: a redeploy surfaces the new failure, not the old one", async () => {
// Create a service that fails with error A (command /bad-cmd-a), let
// failed tasks accumulate, then update the command to /bad-cmd-b so
// new tasks fail with error B. listTasks now carries both A and B
// failed tasks. The surfaced error must be from the most recent
// failure (B), not the stale A — the timestamp-sort refinement.
const name = `itest-conv-stale-${uniqueSuffix()}`;
try {
createService(name, ["/bad-cmd-a"], ["--label", "itest=true"]);
// Let a couple of A-failed tasks accumulate.
await new Promise((r) => setTimeout(r, 5_000));
updateServiceCommand(name, "/bad-cmd-b");
// Let B-failed tasks (more recent) accumulate.
await new Promise((r) => setTimeout(r, 5_000));
let thrown: ServiceConvergenceError | undefined;
try {
await waitForSwarmServiceConvergence(name, null, {
timeoutMs: 12_000,
intervalMs: 1_000,
});
} catch (error) {
if (error instanceof ServiceConvergenceError) thrown = error;
else throw error;
}
if (!thrown)
throw new Error("expected ServiceConvergenceError to be thrown");
expect(thrown).toBeInstanceOf(ServiceConvergenceError);
expect(thrown.message).toContain("bad-cmd-b");
expect(thrown.message).not.toContain("bad-cmd-a");
} finally {
removeService(name);
}
}, 90_000);
});

View File

@ -0,0 +1,356 @@
import {
ServiceConvergenceError,
waitForSwarmServiceConvergence,
} from "@dokploy/server/utils/docker/utils";
import { beforeEach, describe, expect, it, vi } from "vitest";
type SwarmTask = {
DesiredState: string;
CreatedAt?: string;
Status: {
State: string;
Err?: string | null;
Timestamp?: string;
ContainerStatus?: { ContainerID?: string };
};
};
const { inspectMock, listTasksMock, getServiceMock, getRemoteDockerMock } =
vi.hoisted(() => {
const inspect = vi.fn<() => Promise<unknown>>();
const getService = vi.fn(() => ({ inspect }));
const listTasks = vi.fn<(opts: unknown) => Promise<SwarmTask[]>>();
const getRemoteDocker = vi.fn(async () => ({
getService,
listTasks,
}));
return {
inspectMock: inspect,
listTasksMock: listTasks,
getServiceMock: getService,
getRemoteDockerMock: getRemoteDocker,
};
});
vi.mock("@dokploy/server/utils/servers/remote-docker", () => ({
getRemoteDocker: getRemoteDockerMock,
}));
const task = (opts: {
desiredState: string;
state: string;
err?: string;
timestamp?: string;
createdAt?: string;
}): SwarmTask => ({
DesiredState: opts.desiredState,
CreatedAt: opts.createdAt,
Status: {
State: opts.state,
Err: opts.err,
Timestamp: opts.timestamp,
},
});
const ONE_REPLICA = {
Spec: { Mode: { Replicated: { Replicas: 1 } } },
};
// Returns a listTasks implementation that pops snapshots in order and repeats
// the last snapshot forever afterwards (the convergence loop polls repeatedly).
const queueSnapshots = (snapshots: SwarmTask[][]) => {
let i = 0;
return () => {
const snapshot =
i < snapshots.length ? snapshots[i++] : snapshots[snapshots.length - 1];
return Promise.resolve(snapshot ?? []);
};
};
const converge = (
appName: string,
timeoutMs = 300,
intervalMs = 10,
): Promise<void> =>
waitForSwarmServiceConvergence(appName, "server-id", {
timeoutMs,
intervalMs,
});
const expectConvergenceFailure = async (
appName: string,
snapshots: SwarmTask[][],
timeoutMs = 300,
): Promise<ServiceConvergenceError> => {
listTasksMock.mockImplementation(queueSnapshots(snapshots));
let thrown: ServiceConvergenceError | undefined;
try {
await converge(appName, timeoutMs);
} catch (error) {
if (error instanceof ServiceConvergenceError) thrown = error;
else throw error;
}
if (!thrown)
throw new Error("expected waitForSwarmServiceConvergence to throw");
return thrown;
};
describe("waitForSwarmServiceConvergence", () => {
beforeEach(() => {
inspectMock.mockReset();
listTasksMock.mockReset();
getServiceMock.mockClear();
getRemoteDockerMock.mockClear();
inspectMock.mockResolvedValue(ONE_REPLICA);
getRemoteDockerMock.mockResolvedValue({
getService: getServiceMock,
listTasks: listTasksMock,
});
});
it("returns success once runningTasksCount reaches desiredTasksCount", async () => {
listTasksMock.mockImplementation(
queueSnapshots([[task({ desiredState: "running", state: "running" })]]),
);
await expect(converge("mysql-test-app")).resolves.toBeUndefined();
expect(listTasksMock).toHaveBeenCalledTimes(1);
});
it("surfaces the failed task's Status.Err in the convergence error", async () => {
// Hard failure: the failed task's DesiredState has already been flipped
// to "shutdown" by swarm's restart supervisor; a brand-new replacement
// (DesiredState "running", Status.State "new") exists alongside it.
const err = "container exited: command not found (exit code 127)";
const snapshots: SwarmTask[][] = [
[
task({
desiredState: "shutdown",
state: "failed",
err,
timestamp: "2026-09-07T12:00:00.000Z",
createdAt: "2026-09-07T12:00:00.000Z",
}),
task({
desiredState: "running",
state: "new",
timestamp: "2026-09-07T12:00:01.000Z",
createdAt: "2026-09-07T12:00:01.000Z",
}),
],
];
const error = await expectConvergenceFailure("mysql-test-app", snapshots);
expect(error).toBeInstanceOf(ServiceConvergenceError);
expect(error.message).toContain(err);
expect(error.message).toContain("0/1 tasks running");
expect(error.message).not.toContain("last state: new");
});
it("respects the timeout when no task ever reaches running (hard failure: bad command)", async () => {
const err = 'exec: "bad-cmd": executable file not found';
const snapshots: SwarmTask[][] = [
[
task({
desiredState: "shutdown",
state: "failed",
err,
timestamp: "2026-09-07T12:00:00.000Z",
createdAt: "2026-09-07T12:00:00.000Z",
}),
task({
desiredState: "running",
state: "new",
timestamp: "2026-09-07T12:00:01.000Z",
createdAt: "2026-09-07T12:00:01.000Z",
}),
],
];
const error = await expectConvergenceFailure(
"mysql-test-app",
snapshots,
400,
);
expect(error).toBeInstanceOf(ServiceConvergenceError);
expect(error.message).toContain(err);
expect(error.message).toContain("did not converge within 400ms");
});
it("does not regress transient recoveries (still returns within timeout)", async () => {
// Poll 1: a previous task has failed (shutdown) and a replacement is
// spinning up ("new"). Poll 2: the replacement reaches "running".
const snapshots: SwarmTask[][] = [
[
task({
desiredState: "shutdown",
state: "failed",
err: "previous transient error",
timestamp: "2026-09-07T11:59:58.000Z",
createdAt: "2026-09-07T11:59:58.000Z",
}),
task({
desiredState: "running",
state: "new",
timestamp: "2026-09-07T11:59:59.000Z",
createdAt: "2026-09-07T11:59:59.000Z",
}),
],
[
task({
desiredState: "running",
state: "running",
timestamp: "2026-09-07T12:00:00.000Z",
createdAt: "2026-09-07T12:00:00.000Z",
}),
],
];
listTasksMock.mockImplementation(queueSnapshots(snapshots));
const start = Date.now();
await expect(converge("mysql-test-app", 5000)).resolves.toBeUndefined();
const elapsed = Date.now() - start;
// Returns well before the 5s timeout — transient recovery is honored.
expect(elapsed).toBeLessThan(5000);
});
it("surfaces the most recent failed task's error when historical failures exist", async () => {
// A stale failed task from a prior deploy appears FIRST in the listTasks
// response; the current failed task (different error) appears second.
// The convergence error must surface the most recent failure, not the
// stale one that happens to be first in the array.
const staleErr = "bind: address already in use";
const currentErr = 'exec: "bad-cmd": executable file not found';
const snapshots: SwarmTask[][] = [
[
task({
desiredState: "shutdown",
state: "failed",
err: staleErr,
timestamp: "2026-08-31T00:00:00.000Z",
createdAt: "2026-08-31T00:00:00.000Z",
}),
task({
desiredState: "shutdown",
state: "failed",
err: currentErr,
timestamp: "2026-09-07T12:00:00.000Z",
createdAt: "2026-09-07T12:00:00.000Z",
}),
task({
desiredState: "running",
state: "new",
timestamp: "2026-09-07T12:00:01.000Z",
createdAt: "2026-09-07T12:00:01.000Z",
}),
],
];
const error = await expectConvergenceFailure("mysql-test-app", snapshots);
expect(error.message).toContain(currentErr);
expect(error.message).not.toContain(staleErr);
});
it("surfaces the most recent failed task regardless of array order", async () => {
const staleErr = "bind: address already in use";
const currentErr = 'exec: "bad-cmd": executable file not found';
const stale = task({
desiredState: "shutdown",
state: "failed",
err: staleErr,
timestamp: "2026-08-31T00:00:00.000Z",
createdAt: "2026-08-31T00:00:00.000Z",
});
const current = task({
desiredState: "shutdown",
state: "failed",
err: currentErr,
timestamp: "2026-09-07T12:00:00.000Z",
createdAt: "2026-09-07T12:00:00.000Z",
});
const replacement = task({
desiredState: "running",
state: "new",
timestamp: "2026-09-07T12:00:01.000Z",
createdAt: "2026-09-07T12:00:01.000Z",
});
// Stale-first ordering.
let error = await expectConvergenceFailure("mysql-test-app", [
[stale, current, replacement],
]);
expect(error.message).toContain(currentErr);
expect(error.message).not.toContain(staleErr);
// Current-first ordering — same expected result.
error = await expectConvergenceFailure("mysql-test-app", [
[current, stale, replacement],
]);
expect(error.message).toContain(currentErr);
expect(error.message).not.toContain(staleErr);
});
it("does not let a transitional poll overwrite a previously captured failure error", async () => {
// Reproduces the real-Swarm timing window: poll 1 observes a failed
// task (DesiredState "shutdown", Status.State "failed") carrying the
// real container error; poll 2 lands in a transitional window where
// the replacement task is at Status.State "starting" and no task has
// Status.State "failed" yet. The surfaced error must be the real
// container error captured on poll 1, not the transitional "starting"
// state observed on the final poll.
const realErr = 'exec: "/bad-cmd": executable file not found';
const failedTask: SwarmTask = {
DesiredState: "shutdown",
CreatedAt: "2026-09-07T12:00:00.000Z",
Status: {
State: "failed",
Err: realErr,
Timestamp: "2026-09-07T12:00:00.000Z",
},
};
const transitionalReplacement: SwarmTask = {
DesiredState: "running",
CreatedAt: "2026-09-07T12:00:02.000Z",
Status: {
State: "starting",
Timestamp: "2026-09-07T12:00:02.000Z",
},
};
const snapshots: SwarmTask[][] = [[failedTask], [transitionalReplacement]];
const error = await expectConvergenceFailure(
"mysql-test-app",
snapshots,
400,
);
expect(error).toBeInstanceOf(ServiceConvergenceError);
expect(error.message).toContain(realErr);
expect(error.message).not.toMatch(/last state: starting\)/i);
});
it("falls back to the transitional state when no failure was ever observed", async () => {
// Sanity check: if no failed task is ever seen, the convergence error
// still reports the last observed task state (no spurious "unknown"
// once a state was seen).
const snapshots: SwarmTask[][] = [
[
{
DesiredState: "running",
CreatedAt: "2026-09-07T12:00:00.000Z",
Status: { State: "preparing", Timestamp: "2026-09-07T12:00:00.000Z" },
},
],
];
const error = await expectConvergenceFailure(
"mysql-test-app",
snapshots,
300,
);
expect(error.message).toContain("last state: preparing)");
});
});

View File

@ -948,6 +948,14 @@ export const waitForSwarmServiceConvergence = async (
const deadline = Date.now() + timeoutMs;
let lastState = "unknown";
// Most recent failed task's error seen across poll iterations. Swarm's
// restart supervisor rewrites a failed task's DesiredState to "shutdown"
// and there are transitional windows (e.g. a replacement at Status.State
// "starting" before its own failure is recorded) where the current poll
// observes no task with Status.State "failed". Remembering the last
// failure prevents a transitional state from overwriting the real error
// that an earlier poll already captured.
let lastFailureErr: string | undefined;
while (true) {
const info = await service.inspect();
const desiredTasksCount = info.Spec?.Mode?.Replicated?.Replicas ?? 1;
@ -966,9 +974,25 @@ export const waitForSwarmServiceConvergence = async (
return;
}
const failedTask = currentTasks.find((task) =>
["failed", "rejected"].includes(task.Status?.State ?? ""),
);
// Search the unfiltered task list for failures. Swarm's restart
// supervisor rewrites a failed task's DesiredState to "shutdown"
// before setting Status.State to "failed", so filtering to
// DesiredState === "running" (currentTasks) hides the real failure.
// listTasks retains historical tasks (default --task-history-limit 5),
// so pick the most recent failure by Status.Timestamp (CreatedAt
// fallback) to avoid surfacing stale errors from prior deploys.
const failedTask = tasks
.filter((task) =>
["failed", "rejected"].includes(task.Status?.State ?? ""),
)
.sort(
(a, b) =>
new Date(b.Status?.Timestamp ?? b.CreatedAt ?? 0).getTime() -
new Date(a.Status?.Timestamp ?? a.CreatedAt ?? 0).getTime(),
)[0];
if (failedTask) {
lastFailureErr = failedTask.Status?.Err ?? failedTask.Status?.State;
}
lastState =
failedTask?.Status?.Err ??
failedTask?.Status?.State ??
@ -976,8 +1000,13 @@ export const waitForSwarmServiceConvergence = async (
lastState;
if (Date.now() >= deadline) {
// Prefer a real failure error captured on any poll over a
// transitional state ("new"/"preparing"/"starting") observed on
// the final poll, so the operator sees the container's actual
// error string rather than a misleading non-failure state.
const finalState = lastFailureErr ?? lastState;
throw new ServiceConvergenceError(
`Service ${appName} did not converge within ${timeoutMs}ms: ${runningTasksCount}/${desiredTasksCount} tasks running (last state: ${lastState})`,
`Service ${appName} did not converge within ${timeoutMs}ms: ${runningTasksCount}/${desiredTasksCount} tasks running (last state: ${finalState})`,
);
}