diff --git a/dev-packages/node-integration-tests/suites/tracing/tedious/docker-compose.yml b/dev-packages/node-integration-tests/suites/tracing/tedious/docker-compose.yml index ef4db33b7357..f85441012119 100644 --- a/dev-packages/node-integration-tests/suites/tracing/tedious/docker-compose.yml +++ b/dev-packages/node-integration-tests/suites/tracing/tedious/docker-compose.yml @@ -14,4 +14,4 @@ services: interval: 2s timeout: 3s retries: 30 - start_period: 20s + start_period: 60s diff --git a/dev-packages/node-integration-tests/utils/runner/describeWithDockerCompose.ts b/dev-packages/node-integration-tests/utils/runner/describeWithDockerCompose.ts index 07a19489ee1a..0ab245e48cb9 100644 --- a/dev-packages/node-integration-tests/utils/runner/describeWithDockerCompose.ts +++ b/dev-packages/node-integration-tests/utils/runner/describeWithDockerCompose.ts @@ -6,6 +6,8 @@ import { afterAll, beforeAll, describe } from 'vitest'; type DefineTests = () => void; +const SLOW_START_MS = 60_000; + interface DockerOptions { /** * The working directory to run docker compose in @@ -94,9 +96,28 @@ async function runDockerCompose(options: DockerOptions): Promise { }); }; + const output = (result: ReturnType): string => + `${result.stderr?.toString() ?? ''}${result.stdout?.toString() ?? ''}`; + // Surface container logs to make healthcheck failures easier to diagnose in CI + const containerLogs = (): string => spawnSync('docker', composeArgs('logs'), { cwd }).stdout?.toString() ?? ''; + // ensure we're starting fresh close(); + // Pull on its own, so a slow image pull on a runner without cached images can be told apart from + // a slow container start. + const pullStartedAt = Date.now(); + const pull = spawnSync('docker', composeArgs('pull', '--policy', 'missing', '--quiet'), { + cwd, + stdio: process.env.DEBUG ? 'inherit' : 'pipe', + }); + const pullMs = Date.now() - pullStartedAt; + if (pull.status !== 0) { + // `up` pulls missing images too, so only report this + // eslint-disable-next-line no-console + console.warn(`[docker compose] pull failed after ${pullMs}ms (exit ${pull.status}) in ${cwd}\n${output(pull)}`); + } + const composeUp = (): ReturnType => spawnSync('docker', composeArgs('up', '-d', '--wait'), { cwd, @@ -108,22 +129,33 @@ async function runDockerCompose(options: DockerOptions): Promise { // found" right after the network was created). A clean teardown plus retry // clears these, while genuine healthcheck failures stay red on every attempt. const maxAttempts = 3; + const upStartedAt = Date.now(); + let attemptStartedAt = upStartedAt; let result = composeUp(); for (let attempt = 1; attempt < maxAttempts && result.status !== 0; attempt++) { + // eslint-disable-next-line no-console + console.warn( + `[docker compose] up --wait attempt ${attempt} failed after ${Date.now() - attemptStartedAt}ms ` + + `(exit ${result.status}) in ${cwd}\n${output(result)}\n--- container logs ---\n${containerLogs()}`, + ); close(); + attemptStartedAt = Date.now(); result = composeUp(); } + const upMs = Date.now() - upStartedAt; if (result.status !== 0) { - const stderr = result.stderr?.toString() ?? ''; - const stdout = result.stdout?.toString() ?? ''; - // Surface container logs to make healthcheck failures easier to diagnose in CI - const logs = spawnSync('docker', composeArgs('logs'), { cwd }).stdout?.toString() ?? ''; + const logs = containerLogs(); close(); throw new Error( - `docker compose up --wait failed (exit ${result.status})\n${stderr}${stdout}\n--- container logs ---\n${logs}`, + `docker compose up --wait failed (exit ${result.status})\n${output(result)}\n--- container logs ---\n${logs}`, ); } + if (pullMs + upMs > SLOW_START_MS) { + // eslint-disable-next-line no-console + console.warn(`[docker compose] slow start in ${cwd}: pull ${pullMs}ms, up --wait ${upMs}ms`); + } + return close; }