Stop a hung CI test run and keep evidence of where it hangs

.github/workflows/test.yml

@@ -23,8 +23,9 @@ concurrency:
 jobs:
   build:
     runs-on: macos-26
-    # A green run takes about 15 minutes; a slow runner has taken 2.5x that.
-    # Without this the default is 6 hours, so a stuck run had to be cancelled by hand.
+    # A green run takes 6 to 10 minutes, and a slow runner has taken 2.5 times as long. The test
+    # watchdog stops a hung test run sooner; this limit stops anything else that hangs. Without
+    # it the default is 6 hours, so a stuck run had to be cancelled by hand.
     timeout-minutes: 45
     permissions:
       contents: read
@@ -77,6 +78,17 @@ jobs:
             return "$status"
           }
 
+          # A hung test run prints nothing until the job timeout, and a cancelled job keeps no
+          # result bundle. After 10 minutes without test output, the watchdog samples the test
+          # processes into build/ci-logs/hang and interrupts xcodebuild. The step then fails,
+          # and the result bundle marks the running test as canceled.
+          python3 scripts/ci-test-watchdog.py \
+            --logs 'build/test-results/*.xcresult.log' \
+            --results "$GITHUB_WORKSPACE/build/test-results/" \
+            --products "$PROWL_DERIVED_DATA_PATH/Build/Products" \
+            --out build/ci-logs/hang &
+          pid_watchdog=$!
+
           run_task app-tests make test-app &
           pid_app=$!
           # SwiftPM serializes access to .build; keep its checks in one branch.
@@ -90,10 +102,14 @@ jobs:
           wait "$pid_app" || failed=1
           wait "$pid_cli" || failed=1
           wait "$pid_checks" || failed=1
+          kill "$pid_watchdog" 2>/dev/null || true
           {
             printf '## Build and test wall time\n\n| Task | Seconds | Exit status |\n| --- | ---: | ---: |\n'
             cat build/ci-logs/*.timing
             printf '\nTasks run in parallel; their times must not be added.\n\n'
+            if [ -d build/ci-logs/hang ]; then
+              printf '**The test output stopped.** The watchdog interrupted xcodebuild. The xcresult bundle names the canceled test, and ci-logs/hang in the logs artifact has the process samples.\n\n'
+            fi
             python3 scripts/summarize-xcode-build.py build/test-results/*.build.json build/test-results/*.action.json
           } >> "$GITHUB_STEP_SUMMARY"
           exit "$failed"
@@ -123,7 +139,8 @@ jobs:
           if-no-files-found: ignore
           retention-days: 7
       - name: Upload xcresult bundle (on failure)
-        if: failure()
+        # A job that reaches its timeout is cancelled, and its partial results are still useful.
+        if: failure() || cancelled()
         uses: actions/upload-artifact@v4
         with:
           name: xcresult-${{ github.run_id }}-${{ github.run_attempt }}

docs-ai/016-dev-build-and-ci-workflow/000-plan.md

@@ -102,3 +102,6 @@ Anchor wave, all landed 2026-04-04/05:
   CAS from the newest App incremental entry on a miss, save large caches only from main, and
   run the mirror client jobs only when they change (corrects 007's CAS note) — see
   [008-cas-fallback-and-cache-scope.md](008-cas-fallback-and-cache-scope.md)
+- Updated 2026-10-04: a watchdog samples the test processes and interrupts xcodebuild after 10
+  minutes without test output, so a hung run fails early and names the hung test — see
+  [009-test-hang-watchdog.md](009-test-hang-watchdog.md)

docs-ai/016-dev-build-and-ci-workflow/009-test-hang-watchdog.md

@@ -0,0 +1,46 @@
+# 016.009 — Test Hang Watchdog
+
+## Context
+
+In run 37164745593 (#851), the `build` job finished the App build with 93% compilation cache
+hits, then the first `make test-app` pass printed nothing for 39 minutes until the 45-minute
+job timeout cancelled it. The same code had passed one hour earlier. The run kept no evidence
+of the hung test:
+
+- xcodebuild sends test results in bursts, so a hang shows no test lines at all.
+  `NSUnbufferedIO=YES` does not change this: in a local comparison, the result lines arrived
+  at the same times with and without it.
+- The xcresult upload ran only on `failure()`, and a job that reaches its timeout is
+  cancelled.
+- Nothing sampled the processes while they hung.
+
+## Change
+
+- `scripts/ci-test-watchdog.py` runs beside the tasks in the `build` job. When an xcodebuild
+  that writes to `build/test-results/` runs and no `build/test-results/*.xcresult.log` has
+  changed for 10 minutes, it:
+  1. Prints a GitHub error annotation.
+  2. Writes the process table and a 5-second `sample` of xcodebuild, `xctest` and every
+     process started from `$PROWL_DERIVED_DATA_PATH/Build/Products` (the test host) to
+     `build/ci-logs/hang/` (it uses `sudo -n` when `sample` alone fails).
+  3. Sends SIGINT to xcodebuild, and SIGKILL if it has not stopped after 3 minutes.
+- An interrupted xcodebuild prints `** TEST INTERRUPTED **` and still writes the result
+  bundle. The bundle marks the running test as failed with "Testing was canceled", and
+  `print-xcresult-failures.sh` prints that test. `make test-app` stops at that pass, so the
+  step fails about 10 minutes after the last output, not at the job timeout.
+- The xcresult upload also runs when the job is cancelled. The step summary says when the
+  watchdog stopped the run.
+
+10 minutes is far above the normal gaps: the build prints continuously, and the gaps in
+test output are about 2 minutes on a slow runner.
+
+## Verification (local, iOS 27 simulator)
+
+A temporary test with `while true { sleep(1) }`, run under the watchdog with a 30-second
+limit: the watchdog sampled xcodebuild and the test host, whose stack contains
+`WatchdogHangProbeTests.testHangs()`. xcodebuild stopped about 30 seconds after SIGINT, and
+the result bundle reported `WatchdogHangProbeTests/testHangs()` with "Testing was canceled".
+
+## Refs
+
+PR #851 (the hang), this change.

docs-ai/README.md

@@ -98,7 +98,7 @@ keep the old paths. Use this table to find a file that an old entry names:
 | 013 | [prowl-cli](013-prowl-cli/000-plan.md) | 2026-03-30 | Contract-first `prowl` CLI: socket service, v1 commands, hardening, agents |
 | 014 | [terminal-layout-persistence](014-terminal-layout-persistence/000-plan.md) | 2026-03-31 | Layout snapshot save/restore; font-size persistence; launch races |
 | 015 | [repositories-feature-refactor](015-repositories-feature-refactor/000-plan.md) | 2026-04-03 | TCA decomposition of RepositoriesFeature and later code-health splits |
-| 016 | [dev-build-and-ci-workflow](016-dev-build-and-ci-workflow/000-plan.md) | 2026-04-04 | Build/test tooling, CI parallelism, Debug identity, incremental caching, Shared module boundary, CAS fallback and cache save scope |
+| 016 | [dev-build-and-ci-workflow](016-dev-build-and-ci-workflow/000-plan.md) | 2026-04-04 | Build/test tooling, CI parallelism, Debug identity, incremental caching, Shared module boundary, CAS fallback and cache save scope, test hang watchdog |
 | 017 | [upstream-sync-process](017-upstream-sync-process/000-plan.md) | 2026-04-08 | Upstream review discipline, baselines, batch decisions |
 | 018 | [archived-worktrees](018-archived-worktrees/000-plan.md) | 2026-04-09 | Archived worktree discoverability and auto-delete |
 | 019 | [worktree-creation-and-lifecycle](019-worktree-creation-and-lifecycle/000-plan.md) | 2026-04-12 | Creation/merge flows, safe deletion, Add-to-Prowl redesign |

scripts/ci-test-watchdog.py

@@ -0,0 +1,147 @@
+#!/usr/bin/env python3
+"""Stop a CI test run that hangs, and keep evidence of where it hangs.
+
+A hung `xcodebuild test` prints nothing until the job timeout, and a cancelled job keeps no
+result bundle. When the test logs get no output for `--silence` seconds while xcodebuild
+runs, this script samples xcodebuild and the test processes, then interrupts xcodebuild.
+An interrupted xcodebuild still writes the result bundle, which marks the running test as
+"Testing was canceled", and the step fails long before the job timeout.
+"""
+
+import argparse
+import glob
+import os
+from pathlib import Path
+import re
+import signal
+import subprocess
+import time
+
+XCODEBUILD = re.compile(r"^(?:\S*/)?xcodebuild(?:\s|$)")
+XCTEST = re.compile(r"^(?:\S*/)?xctest(?:\s|$)")
+
+
+def stalled(newest, now, silence):
+    return newest is not None and now - newest >= silence
+
+
+def newest_output(paths):
+    times = [os.path.getmtime(path) for path in paths if os.path.exists(path)]
+    return max(times, default=None)
+
+
+def parse_processes(output):
+    processes = []
+    for line in output.splitlines():
+        pid, _, args = line.strip().partition(" ")
+        if pid.isdigit():
+            processes.append((int(pid), args.strip()))
+    return processes
+
+
+def xcodebuild_pids(processes, results):
+    # The results folder keeps an unrelated xcodebuild (another checkout) out.
+    return [pid for pid, args in processes if XCODEBUILD.match(args) and results in args]
+
+
+def sample_targets(processes, results, products, own_pid):
+    builds = set(xcodebuild_pids(processes, results))
+    return [
+        (pid, args)
+        for pid, args in processes
+        if pid != own_pid
+        and (pid in builds or XCTEST.match(args) or any(path in args for path in products))
+    ]
+
+
+def list_processes():
+    output = subprocess.run(
+        ["ps", "-axo", "pid=,args="], capture_output=True, text=True, check=True
+    ).stdout
+    return parse_processes(output)
+
+
+def collect(processes, targets, out, log):
+    out.mkdir(parents=True, exist_ok=True)
+    table = subprocess.run(
+        ["ps", "-axo", "pid,ppid,etime,pcpu,state,args"], capture_output=True, text=True
+    ).stdout
+    (out / "processes.txt").write_text(table)
+    for pid, args in targets:
+        name = re.sub(r"[^A-Za-z0-9.-]+", "-", Path(args.split(" -")[0]).name)[:40]
+        file = out / f"sample-{pid}-{name}.txt"
+        command = ["sample", str(pid), "5", "-file", str(file)]
+        # The hosted runner allows sudo without a password; a local run may not need it.
+        if subprocess.run(command, capture_output=True).returncode != 0:
+            result = subprocess.run(["sudo", "-n", *command], capture_output=True, text=True)
+            if result.returncode != 0:
+                log(f"could not sample {pid} ({args[:80]}): {result.stderr.strip()}")
+
+
+def interrupt(pids, grace, log):
+    for pid in pids:
+        try:
+            os.kill(pid, signal.SIGINT)
+        except ProcessLookupError:
+            pass
+    deadline = time.time() + grace
+    while time.time() < deadline:
+        if not any(alive(pid) for pid in pids):
+            return
+        time.sleep(2)
+    for pid in pids:
+        if alive(pid):
+            log(f"xcodebuild {pid} did not stop after SIGINT; sending SIGKILL")
+            try:
+                os.kill(pid, signal.SIGKILL)
+            except ProcessLookupError:
+                pass
+
+
+def alive(pid):
+    try:
+        os.kill(pid, 0)
+    except ProcessLookupError:
+        return False
+    return True
+
+
+def main():
+    parser = argparse.ArgumentParser(description=__doc__)
+    parser.add_argument("--logs", action="append", required=True, help="glob of the test logs")
+    parser.add_argument("--results", required=True, help="result bundle folder in xcodebuild's arguments")
+    parser.add_argument("--products", action="append", default=[], help="path in the test processes' arguments")
+    parser.add_argument("--out", type=Path, required=True, help="folder for the process list and samples")
+    parser.add_argument("--silence", type=float, default=600)
+    parser.add_argument("--interval", type=float, default=30)
+    parser.add_argument("--grace", type=float, default=180)
+    options = parser.parse_args()
+
+    def log(message):
+        print(f"[watchdog] {message}", flush=True)
+
+    while True:
+        time.sleep(options.interval)
+        processes = list_processes()
+        builds = xcodebuild_pids(processes, options.results)
+        if not builds:
+            continue
+        logs = [path for pattern in options.logs for path in glob.glob(pattern)]
+        newest = newest_output(logs)
+        if not stalled(newest, time.time(), options.silence):
+            continue
+        silent = int(time.time() - newest)
+        print(
+            f"::error title=Test output stopped::No test output for {silent} s. "
+            f"Sampled the test processes into {options.out} and interrupted xcodebuild.",
+            flush=True,
+        )
+        targets = sample_targets(processes, options.results, options.products, os.getpid())
+        collect(processes, targets, options.out, log)
+        log(f"sampled {len(targets)} processes; interrupting xcodebuild {builds}")
+        interrupt(builds, options.grace, log)
+        return
+
+
+if __name__ == "__main__":
+    main()

scripts/test_ci_test_watchdog.py

@@ -0,0 +1,60 @@
+import importlib.util
+import os
+from pathlib import Path
+import tempfile
+import unittest
+
+
+spec = importlib.util.spec_from_file_location(
+    "ci_test_watchdog", Path(__file__).with_name("ci-test-watchdog.py")
+)
+module = importlib.util.module_from_spec(spec)
+
+RESULTS = "/work/Prowl/build/test-results/"
+PRODUCTS = "/work/Prowl/build/ci-derived-data/Build/Products"
+PS_OUTPUT = f"""\
+  101 /Applications/Xcode.app/Contents/Developer/usr/bin/xcodebuild test -workspace Prowl.xcworkspace -resultBundlePath {RESULTS}prowl-tests.xcresult
+  102 tee {RESULTS}prowl-tests.xcresult.log
+  103 /bin/sh -c set -euo pipefail; xcodebuild test -resultBundlePath {RESULTS}prowl-tests.xcresult
+  104 {PRODUCTS}/Debug/Prowl Debug.app/Contents/MacOS/Prowl Debug -NSTreatUnknownArgumentsAsOpen NO
+  105 /Applications/Xcode.app/Contents/Developer/usr/bin/xcodebuild test -project Other.xcodeproj
+  106 /Applications/Xcode.app/Contents/Developer/usr/bin/xctest /tmp/Other.xctest
+  107 python3 scripts/ci-test-watchdog.py --products {PRODUCTS}
+"""
+
+
+class WatchdogTests(unittest.TestCase):
+    @classmethod
+    def setUpClass(cls):
+        spec.loader.exec_module(module)
+
+    def test_output_is_stalled_only_after_the_silence_limit(self):
+        self.assertFalse(module.stalled(newest=1000, now=1599, silence=600))
+        self.assertTrue(module.stalled(newest=1000, now=1600, silence=600))
+
+    def test_no_output_yet_is_not_a_stall(self):
+        self.assertFalse(module.stalled(newest=None, now=5000, silence=600))
+
+    def test_newest_output_uses_the_latest_log(self):
+        with tempfile.TemporaryDirectory() as tmp:
+            old = Path(tmp, "a.xcresult.log")
+            new = Path(tmp, "b.xcresult.log")
+            old.write_text("old")
+            new.write_text("new")
+            os.utime(old, (100, 100))
+            os.utime(new, (200, 200))
+            self.assertEqual(module.newest_output([str(old), str(new)]), 200)
+            self.assertIsNone(module.newest_output([]))
+
+    def test_interrupts_only_xcodebuild_runs_that_write_to_the_results_folder(self):
+        processes = module.parse_processes(PS_OUTPUT)
+        self.assertEqual(module.xcodebuild_pids(processes, RESULTS), [101])
+
+    def test_samples_xcodebuild_and_the_test_processes_but_not_itself(self):
+        processes = module.parse_processes(PS_OUTPUT)
+        targets = module.sample_targets(processes, RESULTS, [PRODUCTS], own_pid=107)
+        self.assertEqual([pid for pid, _ in targets], [101, 104, 106])
+
+
+if __name__ == "__main__":
+    unittest.main()