diff --git a/.github/workflows/windows-render.yml b/.github/workflows/windows-render.yml index d0ffd62978..4bd7e76486 100644 --- a/.github/workflows/windows-render.yml +++ b/.github/workflows/windows-render.yml @@ -518,10 +518,11 @@ jobs: - name: Run ${{ matrix.lane }} package tests if: matrix.packages shell: pwsh - timeout-minutes: 16 + timeout-minutes: 20 # Each package starts its own Vitest pool. Bound every pool so concurrent # package scripts cannot oversubscribe the hosted Windows runner. - run: bun run ${{ matrix.packages }} test -- --maxWorkers=2 --reporter=verbose + # timeout-minutes did not fire on a hung run, so the script enforces the 16 minutes itself. + run: ./scripts/ci/run-with-deadline.ps1 -Minutes 16 -Command 'bun run ${{ matrix.packages }} test -- --maxWorkers=2 --reporter=verbose' - name: Verify waveform cache writes on Windows if: matrix.lane == 'engine-cli' @@ -543,6 +544,15 @@ jobs: shell: pwsh run: bunx vitest run scripts/catalog/catalog-payload-assets.file-race.test.ts scripts/catalog/catalog-payload-assets.cache-race.test.ts --maxWorkers=2 + - name: Upload test step log + if: always() && matrix.packages + uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4 + with: + name: test-step-log-${{ matrix.lane }} + path: ${{ runner.temp }}/deadline-step.log + if-no-files-found: ignore + retention-days: 7 + - name: Run runtime contract test if: matrix.runtime_contract shell: pwsh diff --git a/packages/cli/src/warmCheck.process.test.ts b/packages/cli/src/warmCheck.process.test.ts index 023bac8449..43b3aae345 100644 --- a/packages/cli/src/warmCheck.process.test.ts +++ b/packages/cli/src/warmCheck.process.test.ts @@ -62,10 +62,11 @@ function run(args: string[], env: Record) { }); let stdout = ""; child.stdout.on("data", (data: Buffer) => (stdout += data.toString())); - child.stderr.on("data", () => {}); + let stderr = ""; + child.stderr.on("data", (data: Buffer) => (stderr += data.toString())); const done = new Promise((resolve) => child.once("close", resolve)); onTestFinished(() => stopTestProcesses(child, [])); - return { child, done, stdout: () => stdout }; + return { child, done, stdout: () => stdout, stderr: () => stderr }; } async function warmProcess(dir: string, env: Record, idleMs = 60_000) { @@ -141,7 +142,7 @@ it("serves a check that prints what a cold check prints, then exits with its Chr await waitForTestCondition(() => !testProcessIsAlive(warm.pid) && gone(chrome), 10_000); const cold = run([join(here, "cli.ts"), "check", dir, ...CHECK_ARGS], env); - expect(await cold.done).toBe(0); + expect(await cold.done, `${cold.stdout()}\n${cold.stderr()}`).toBe(0); expect(findings(served.stdout())).toEqual(findings(cold.stdout())); }, 120_000); diff --git a/scripts/ci/run-with-deadline.ps1 b/scripts/ci/run-with-deadline.ps1 new file mode 100644 index 0000000000..28e04b8f26 --- /dev/null +++ b/scripts/ci/run-with-deadline.ps1 @@ -0,0 +1,32 @@ +# Runs a command and, if it outlives the deadline, prints the process tree it left and kills it. +# GitHub's step timeout did not fire on a hung Windows test step and the log was lost with it. +param( + [Parameter(Mandatory)][int]$Minutes, + [Parameter(Mandatory)][string]$Command +) +$ErrorActionPreference = 'Stop' +$log = Join-Path $env:RUNNER_TEMP "deadline-step.log" +$null = New-Item $log -ItemType File +$child = Start-Process pwsh -ArgumentList '-NoProfile', '-Command', "$Command *>> '$log'" -PassThru -WindowStyle Hidden +$read = 0 +$stop = (Get-Date).AddMinutes($Minutes) +function Show-NewOutput { + $stream = [IO.File]::Open($log, 'Open', 'Read', 'ReadWrite') + try { + $null = $stream.Seek($script:read, 'Begin') + $text = (New-Object IO.StreamReader($stream)).ReadToEnd() + $script:read = $stream.Position + if ($text) { [Console]::Out.Write($text) } + } finally { $stream.Dispose() } +} +while (-not $child.HasExited -and (Get-Date) -lt $stop) { Show-NewOutput; Start-Sleep -Seconds 2 } +Show-NewOutput +if ($child.HasExited) { exit $child.ExitCode } +Write-Host "::error::'$Command' ran past $Minutes minutes; process tree at the deadline:" +$table = Get-CimInstance Win32_Process +$tree = @($child.Id) +for ($i = 0; $i -lt $tree.Count; $i++) { $tree += @($table | Where-Object ParentProcessId -eq $tree[$i] | ForEach-Object ProcessId) } +$table | Where-Object { $tree -contains $_.ProcessId } | + ForEach-Object { "{0} <- {1} {2} {3:N0}s old: {4}" -f $_.ProcessId, $_.ParentProcessId, $_.Name, ((Get-Date) - $_.CreationDate).TotalSeconds, $_.CommandLine } +taskkill /T /F /PID $child.Id | Out-Null +exit 124