ci(windows): fail a hung engine-cli test step at its deadline and name the stuck process (#6100)

* ci(windows): fail a hung test step at its deadline and name the process that hung

* ci(windows): upload the test step log even when the step is killed

.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

packages/cli/src/warmCheck.process.test.ts

@@ -62,10 +62,11 @@ function run(args: string[], env: Record<string, string>) {
   });
   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<number | null>((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<string, string>, 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);
 

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