diff --git a/web/sites/guides/scripts/verify-docs/lib/exec.mjs b/web/sites/guides/scripts/verify-docs/lib/exec.mjs index aa7e2a9c04..cc069d85d0 100644 --- a/web/sites/guides/scripts/verify-docs/lib/exec.mjs +++ b/web/sites/guides/scripts/verify-docs/lib/exec.mjs @@ -118,7 +118,34 @@ function killGroup(proc, signal) { * process still holds its output pipes. That leftover keeps running while the harness does (a block * may legitimately leave a server running, `wheels start`), and is stopped when the harness exits. */ -export function runExec(program, args = [], opts = {}) { +// Starts of `wheels` JVMs, one at a time: each waits until the previous one has had startGap() ms +// to boot. JVMs starting at the same moment in one CLI home race in Lucee's OSGi bundle cache +// ("Bundle symbolic name and version are not unique", then a null script engine) and fail or stall +// (#4450). Measured on 12 runs of four-way verify-docs: no gap failed 6, 250 ms and up failed none; +// 1 s leaves room for slower CI machines. Once started, commands still run in parallel. +let wheelsStartGate = Promise.resolve(); +export function startGap(env = process.env) { + const ms = Number(env.WHEELS_START_GAP_MS); + return Number.isFinite(ms) && ms >= 0 ? ms : 1_000; +} +function nextWheelsStart() { + const turn = wheelsStartGate; + let release; + wheelsStartGate = new Promise((r) => (release = r)); + return turn.then(() => () => setTimeout(release, startGap())); +} + +export async function runExec(program, args = [], opts = {}) { + const releaseStart = program === 'wheels' ? await nextWheelsStart() : null; + try { + return await runExecNow(program, args, opts, releaseStart); + } finally { + // If the spawn never happened (it threw), still hand over, so the next start isn't stuck. + releaseStart?.(); + } +} + +function runExecNow(program, args, opts, releaseStart) { const { cwd, env } = opts; const timeout = opts.timeout ?? defaultExecTimeout(); const spawnOpts = { @@ -143,6 +170,7 @@ export function runExec(program, args = [], opts = {}) { return new Promise((resolve) => { const proc = spawn(resolvedProgram, args, spawnOpts); + releaseStart?.(); running.add(proc); let stdout = ''; let stderr = ''; diff --git a/web/sites/guides/scripts/verify-docs/test/exec.test.mjs b/web/sites/guides/scripts/verify-docs/test/exec.test.mjs index af624206d1..f9e2db875c 100644 --- a/web/sites/guides/scripts/verify-docs/test/exec.test.mjs +++ b/web/sites/guides/scripts/verify-docs/test/exec.test.mjs @@ -130,3 +130,45 @@ test('a leftover from a command that exited is stopped when the harness exits', if (grandchild) try { process.kill(grandchild, 'SIGKILL'); } catch {} } }); + +test('wheels starts are staggered, so JVMs never start at the same moment', { timeout: 60_000 }, async () => { + // Simultaneous `wheels` JVM starts in one CLI home race in Lucee's OSGi bundle cache (#4450). + // A fake `wheels` prints when it started; three called at once must start at least the gap apart. + const { mkdtempSync, writeFileSync, chmodSync, rmSync } = await import('node:fs'); + const { tmpdir } = await import('node:os'); + const { join } = await import('node:path'); + const { spawn } = await import('node:child_process'); + const dir = mkdtempSync(join(tmpdir(), 'vd-gate-')); + try { + const fake = join(dir, 'wheels'); + writeFileSync(fake, `#!${process.execPath}\nconsole.log(Date.now()); setTimeout(() => {}, 300);\n`); + chmodSync(fake, 0o755); + const lib = new URL('../lib/exec.mjs', import.meta.url).href; + const harness = [ + `const { runExec } = await import(${JSON.stringify(lib)});`, + "const rs = await Promise.all([1, 2, 3].map(() => runExec('wheels', ['x'])));", + "console.log(JSON.stringify(rs.map((r) => Number(r.stdout.trim()))));", + ].join('\n'); + const env = { ...process.env, WHEELS_BIN: fake, WHEELS_START_GAP_MS: '1000' }; + const proc = spawn(NODE, ['--input-type=module', '-e', harness], { env, stdio: ['ignore', 'pipe', 'inherit'] }); + let out = ''; + proc.stdout.on('data', (d) => (out += d)); + await new Promise((resolve) => proc.once('exit', resolve)); + const starts = JSON.parse(out.trim().split('\n').pop()).sort((a, b) => a - b); + assert.equal(starts.length, 3); + for (let i = 1; i < starts.length; i++) { + // The fake records its start after its own Node boot, which varies; leave room for that. + assert.ok(starts[i] - starts[i - 1] >= 600, `starts ${starts[i - 1]} and ${starts[i]} are under the gap apart`); + } + } finally { + rmSync(dir, { recursive: true, force: true }); + } +}); + +test('the start gap comes from WHEELS_START_GAP_MS', async () => { + const { startGap } = await import('../lib/exec.mjs'); + assert.equal(startGap({ WHEELS_START_GAP_MS: '250' }), 250); + assert.equal(startGap({ WHEELS_START_GAP_MS: '0' }), 0); + assert.equal(startGap({}), 1000); + assert.equal(startGap({ WHEELS_START_GAP_MS: 'nope' }), 1000); +}); diff --git a/web/sites/guides/scripts/verify-docs/test/orchestrator.test.mjs b/web/sites/guides/scripts/verify-docs/test/orchestrator.test.mjs index bd5970d11d..a4144338af 100644 --- a/web/sites/guides/scripts/verify-docs/test/orchestrator.test.mjs +++ b/web/sites/guides/scripts/verify-docs/test/orchestrator.test.mjs @@ -27,24 +27,11 @@ function runEntry(args, env = {}) { }); } -test('verify-docs reports pass/fail counts', { timeout: 300_000 }, async (t) => { - // Several `wheels` JVMs starting at once in a fresh isolated home race in Lucee's OSGi bundle cache - // ("Bundle symbolic name and version are not unique") and fail or stall (#4450). The sample has two - // per-block examples, so run them one at a time. If it still fails, bound each command at 60 s so a - // stall surfaces quickly, show the child's output (which names the command), and skip on CI while - // #4450 is open. Locally a failure still fails. - const { code, stdout, stderr } = await runEntry([fixture], { - VERIFY_DOCS_CONCURRENCY: '1', - WHEELS_EXEC_TIMEOUT_MS: '60000', - }); - if (code !== 0) { - t.diagnostic(`verify-docs exited ${code}`); - for (const line of `--- stdout ---\n${stdout}\n--- stderr ---\n${stderr}`.split('\n')) t.diagnostic(line); - if (process.env.CI) { - t.skip('a wheels command stalls on CI (#4450); the output above names it'); - return; - } - } +test('verify-docs reports pass/fail counts', { timeout: 300_000 }, async () => { + // Runs the per-block examples four at a time, as a real run does: `wheels` JVM starts are staggered + // in runExec() because simultaneous starts in one CLI home race (#4450). Each command is bounded at + // 60 s so a stall surfaces quickly, and a failure shows the child's output. + const { code, stdout, stderr } = await runEntry([fixture], { WHEELS_EXEC_TIMEOUT_MS: '60000' }); // Phase 1 drivers: cli + tutorial + compile. Fixture has compile + cli + // tutorial; all three pass (compile falls back to bracket-check when // LuCLI PR #1 isn't installed, which still accepts the balanced sample).