test: stop the faulthandler segfault class in CI (3.11 and 3.12)

.github/workflows/test.yml

@@ -20,7 +20,7 @@ concurrency:
 jobs:
   test:
     runs-on: ubuntu-latest
-    timeout-minutes: 25
+    timeout-minutes: 30
     strategy:
       matrix:
         python-version: ["3.10", "3.11", "3.12"]

pyproject.toml

@@ -114,7 +114,7 @@ dev = [
     "pytest-cov>=4.0",
     "pytest-mock>=3.0",
     # Consiliency/pmcp#200: without this the `timeout` ini option below is
-    # inert and a stuck await is a 25-minute silent job cancel.
+    # inert and a stuck await is a silent job-cap cancel.
     "pytest-timeout>=2.3",
     "ruff>=0.8.0",
     "mypy>=1.0",
@@ -151,39 +151,54 @@ addopts = "-m 'not live and not slow'"
 # `test (3.x)` jobs in the week to 2026-09-01 stalled and were killed by the
 # job's `timeout-minutes: 25`; GitHub reports a timed-out job as *cancelled*,
 # so none of them produced a red X, a traceback, or one line of evidence about
-# which await was stuck. These two settings turn that into a fast, loud
-# failure. They do not fix the hang -- the root cause is still unknown.
+# which await was stuck. These settings turn that into a fast, loud failure.
+# They do not fix the hang -- the root cause is still unknown.
 #
-# Both numbers derive from `pytest tests/ --durations=25` on 2026-09-02 (see
-# `.consiliency/evidence/hang-diagnostics-200.md`). The slowest non-`live`
-# tests are `test_progressive_disclosure.py::TestScenario8_LibraryConcepts
-# ::test_invoke_query_docs_conceptual` at 60.25 s and its Scenario7 sibling at
-# 60.22 s. (Both land on almost exactly 60 s, which looks like an internal
-# timeout rather than real work -- noted, not in scope here.)
+# `timeout = 700` derives from `pytest tests/ --durations=25` on 2026-09-02
+# (see `.consiliency/evidence/hang-diagnostics-200.md`): >=10x the slowest
+# non-`live` test, `test_progressive_disclosure.py::TestScenario8_LibraryConcepts
+# ::test_invoke_query_docs_conceptual` at 60.25 s (10 x 60.25 = 602.5, so 600
+# would have been 9.96x and short of the bar).
 #
-#   faulthandler_timeout = 120  -- 2x the slowest test. Zero-risk half: it
-#     kills nothing, it dumps every thread's stack and lets the run continue.
-#   timeout              = 700  -- >=10x the slowest test (10 x 60.25 = 602.5,
-#     so 600 would have been 9.96x and short of the bar). The fail-fast half,
-#     via pytest-timeout. The dump therefore lands ~9.7 minutes before the
-#     kill, and both sit well inside the `test` job's `timeout-minutes: 25`.
+#   timeout = 700 (pytest-timeout, signal method) -- the FIRST thread dump and
+#     the kill. Its SIGALRM handler runs in the main thread under the GIL, so
+#     the dump reads frames that are not moving; the item fails and the run
+#     continues. This is what any slow-but-running or Python-level hang hits.
+#   faulthandler_timeout = 720, faulthandler_exit_on_timeout = true -- the
+#     LAST RESORT, above the kill on purpose. faulthandler's C watchdog dumps
+#     every thread WITHOUT the GIL while the main thread keeps running, and that
+#     walk of a moving frame chain segfaulted CI: on 2026-10-01 four jobs on
+#     3.11 and 3.12 died with exit 139, the dump cut off mid-line, when a slow
+#     test crossed the old 120 s threshold, which sat below the kill. Above
+#     the kill it only fires when pytest-timeout's handler never got to run --
+#     a thread wedged in C or holding the GIL, whose frames are not moving --
+#     and then it dumps and EXITS the process, so even that hang is a red X
+#     with a stack rather than a silent job-cap cancel. Fail closed.
 #
-# Neither of these can see a *suspended coroutine*: its frames live in Task
+# Neither thread dump can see a *suspended coroutine*: its frames live in Task
 # objects, not on any thread stack, so both bottom out in `epoll.poll()` and
 # name nothing. `tests/runtime/_hang_watchdog.py` closes that at 60 s by
-# dumping the pending tasks and walking the await chain. Full order, each
-# strictly below the next:
+# dumping the pending tasks and walking the await chain (in Python, under the
+# GIL). Per-test order, each strictly below the next:
 #
-#   60 s -> async stacks | 120 s -> thread stacks | 700 s -> kill | 25 min -> job cap
+#   60 s -> async stacks | 700 s -> thread stacks + kill item
+#        | 720 s -> C dump + exit process
+#
+# The `test` job's `timeout-minutes: 30` is a different scale: it caps the
+# WHOLE job, not one test. A hang that starts later than (cap - 720 s) into the
+# job is cancelled before any dump, so the cap must exceed the slowest job's
+# runtime plus 720 s (3.11 ran ~15 min on 2026-10-01; 30 leaves ~3 min spare
+# beyond that margin), and `scripts/check_workflows.py` caps it at 30.
 #
 # Set here rather than on the CI command line so a local run behaves like CI.
 # `timeout_method` is not the platform default by accident: it is the value
 # that `tests/runtime/test_hang_diagnostics.py` empirically proves also covers
 # *fixture teardown*, which is where the likeliest hang site is -- pytest
 # prints `PASSED` when the test function returns, before teardown runs.
-faulthandler_timeout = 120
 timeout = 700
 timeout_method = "signal"
+faulthandler_timeout = 720
+faulthandler_exit_on_timeout = true
 markers = [
     "live: opt-in live integration tests (require network and package managers)",
     "slow: opt-in long-running tests (the full redaction differential and timing sweep; run with -m slow)",

tests/conftest.py

@@ -270,6 +270,42 @@ def approve(path: Path, home: Path | None = None) -> None:
     return approve
 
 
+@pytest.fixture(autouse=True)
+def _restore_root_logger() -> Iterator[None]:
+    """Undo whatever a test adds to the root logger. **Autouse.**
+
+    ``pmcp.cli.setup_logging`` adds a ``StreamHandler`` and a
+    ``RotatingFileHandler`` to the root logger on every call, and
+    ``tests/test_cli.py`` drives it many times. Nothing removed them: after
+    ``test_cli.py`` and ``test_scoped_advisor_audit.py`` the root logger held 90
+    handlers, every later WARNING fanned out to all of them (stream handlers
+    bound to long-dead captured stderr printed ``--- Logging error ---``), and
+    the warning-heavy pin-precedence tests ran ~7x slower -- enough, with
+    coverage, to push one past ``faulthandler_timeout`` and segfault CI.
+
+    Only handlers that appeared during the test are removed (and closed, so the
+    file handlers release their descriptors). pytest's own capture handlers are
+    swapped per phase by its logging plugin, so they are left to it.
+    """
+    import logging
+
+    root = logging.getLogger()
+    before_handlers = list(root.handlers)
+    before_level = root.level
+    yield
+    for handler in list(root.handlers):
+        if handler in before_handlers:
+            continue
+        if type(handler).__module__.startswith("_pytest"):
+            continue
+        root.removeHandler(handler)
+        try:
+            handler.close()
+        except Exception:
+            pass
+    root.setLevel(before_level)
+
+
 @pytest.fixture(autouse=True)
 def _reset_dotenv_provenance() -> Iterator[None]:
     """Keep the dotenv provenance registry from leaking between tests.

tests/runtime/_hang_watchdog.py

@@ -14,19 +14,29 @@
     E   Failed: Timeout (>3.0s) from pytest-timeout.
 
 `epoll.poll` — the stuck await is invisible. Without this module #200's
-diagnostics would turn a 25-minute silent cancel into a 700-second failure
+diagnostics would turn a silent job-cap cancel into a 700-second failure
 that still could not tell `_tap()` from `connect_server()` from
 `disconnect_all()`, which is the entire question the change exists to answer.
 
 So: a watchdog thread that, when the current test item has been running too
 long, dumps every pending `asyncio.Task` on that item's event loop.
 
-Three ordered thresholds, each strictly below the next:
+Ordered per-test thresholds, each strictly below the next:
 
     60 s   this watchdog        -> async stacks, names the awaiting coroutine
-    120 s  faulthandler_timeout -> every thread's stack, the run continues
-    700 s  pytest-timeout       -> the item fails and the run moves on
-    25 min the job's cap        -> what used to happen instead of all of this
+    700 s  pytest-timeout       -> thread stacks (under the GIL); the item
+                                   fails and the run moves on
+    720 s  faulthandler_timeout -> last resort for a thread the kill could not
+                                   reach: C-level stacks, then the process exits
+
+The `test` job's `timeout-minutes` (30) caps the whole job, not one test, so a
+hang that starts within 720 s of the cap is cancelled with no dump; the cap is
+set to exceed the slowest job plus that margin (see pyproject.toml).
+
+faulthandler sits ABOVE the kill on purpose: its C watchdog walks a running
+thread's frames without the GIL, and below the kill that walk segfaulted CI
+(exit 139) whenever a slow test crossed it. This watchdog does not share that
+hazard -- it is a Python thread and renders under the GIL.
 
 60 s is the threshold because the slowest item in `tests/runtime` is 26.16 s
 (`--durations=25`, 2026-09-02), so this has >2x headroom over anything here

tests/runtime/test_hang_diagnostics.py

@@ -24,8 +24,11 @@
     the whole point: pytest prints `PASSED` when the test function returns,
     *before* teardown, so the likeliest hang site is after the last `PASSED`
     line in those five logs.
-  * a subprocess run proving `faulthandler_timeout` dumps a stack and lets the
-    session continue, and that the dump is scheduled strictly before the kill.
+  * two subprocess runs proving the ordering of the thread-stack dumps: a slow
+    test that is still running Python is failed by pytest-timeout (under the
+    GIL) before faulthandler fires, and a wedge pytest-timeout cannot reach is
+    dumped by faulthandler, which then ends the process. faulthandler sits
+    ABOVE the kill because its GIL-free dump of a running thread segfaulted CI.
   * an **async** hang — the shape the real one is believed to have — proving the
     watchdog in `_hang_watchdog.py` names the awaiting coroutine. Both
     `faulthandler` and `pytest-timeout` dump the *thread* stack, and a suspended
@@ -202,15 +205,36 @@ def test_passes_then_hangs_in_teardown(blocks_on_the_way_out):
     assert True
 """
 
-_FAULTHANDLER_MODULE = """
+# A slow test that is still RUNNING Python: pytest-timeout's handler can run,
+# so it must fail the item before faulthandler's GIL-free dump ever fires.
+_SLOW_TEST_MODULE = """
 import time
 
 
-def test_blocks_long_enough_to_be_dumped():
-    time.sleep(5)
+def test_runs_past_the_kill_timeout():
+    deadline = time.monotonic() + 8
+    while time.monotonic() < deadline:
+        sum(range(1000))
 
 
-def test_sentinel_still_runs_after_the_dump():
+def test_sentinel_still_runs_after_the_kill():
+    assert True
+"""
+
+# A wedge pytest-timeout cannot reach: SIGALRM is blocked, so its handler never
+# runs -- the stand-in for a thread stuck in C or holding the GIL. Only the
+# faulthandler last resort can report this one, and it must end the process.
+_WEDGED_MODULE = """
+import signal
+import time
+
+
+def test_wedged_where_the_signal_cannot_land():
+    signal.pthread_sigmask(signal.SIG_BLOCK, {signal.SIGALRM})
+    time.sleep(30)
+
+
+def test_sentinel_must_not_run_after_the_exit():
     assert True
 """
 
@@ -295,15 +319,10 @@ def test_a_teardown_hang_is_not_caught_without_the_plugin(tmp_path: Path) -> Non
         process.communicate()
 
 
-def test_faulthandler_dumps_a_stack_and_the_run_continues(tmp_path: Path) -> None:
-    """The zero-risk half: it kills nothing, it only prints the stacks.
-
-    Reading the ini value cannot prove either the dump or the continuation, so
-    this induces both: a blocking item under a 2 s `faulthandler_timeout`, then
-    a sentinel item that must still run, with the session exiting normally.
-    """
-    module = _write_module(tmp_path, _FAULTHANDLER_MODULE)
-    result = subprocess.run(
+def _run_ladder(tmp_path: Path, body: str) -> subprocess.CompletedProcess[str]:
+    """The committed ladder, scaled down: kill at 2 s, last-resort dump at 4 s."""
+    module = _write_module(tmp_path, body)
+    return subprocess.run(
         [
             sys.executable,
             "-m",
@@ -312,41 +331,97 @@ def test_faulthandler_dumps_a_stack_and_the_run_continues(tmp_path: Path) -> Non
             "-p",
             "no:cacheprovider",
             "-o",
-            "faulthandler_timeout=2",
+            "timeout=2",
+            "-o",
+            "timeout_method=signal",
+            "-o",
+            "faulthandler_timeout=4",
             "-o",
-            "timeout=30",
+            "faulthandler_exit_on_timeout=true",
             "-q",
         ],
         capture_output=True,
         text=True,
         timeout=90,
         cwd=tmp_path,
     )
+
+
+def test_a_slow_running_test_is_killed_cleanly_before_faulthandler_fires(
+    tmp_path: Path,
+) -> None:
+    """A test still running Python is failed by pytest-timeout, under the GIL.
+
+    faulthandler's watchdog walks a running thread's frames without the GIL;
+    on 2026-10-01 that walk segfaulted four CI jobs (exit 139) when a slow test
+    crossed a faulthandler threshold that sat BELOW the kill. With the dump
+    above the kill, a slow test must instead fail as an ordinary item, the
+    faulthandler timer must be cancelled, and the session must carry on.
+    """
+    result = _run_ladder(tmp_path, _SLOW_TEST_MODULE)
     output = result.stdout + result.stderr
 
-    assert "Thread 0x" in output, output
-    assert "Timeout (0:00:02)" in output, output
-    assert "2 passed" in output, output
-    assert result.returncode == 0, output
+    assert "Timeout" in output and "1 failed, 1 passed" in output, output
+    assert "Timeout (0:00:04)" not in output, output  # faulthandler never fired
+    assert result.returncode == 1, output
 
 
-def test_faulthandler_timeout_is_below_the_kill_timeout(
+def test_a_wedge_the_kill_cannot_reach_is_dumped_and_ends_the_run(
+    tmp_path: Path,
+) -> None:
+    """Fail closed: a hang pytest-timeout cannot interrupt still ends red.
+
+    Without `faulthandler_exit_on_timeout` this would dump and then sit until
+    the job's cap -- the silent cancel Consiliency/pmcp#200 exists to
+    replace. With it, the stacks are printed and the process exits non-zero,
+    so the sentinel after the wedge never runs.
+    """
+    result = _run_ladder(tmp_path, _WEDGED_MODULE)
+    output = result.stdout + result.stderr
+
+    assert "Timeout (0:00:04)!" in output, output
+    assert "Thread 0x" in output or "Current thread 0x" in output, output
+    assert "test_wedged_where_the_signal_cannot_land" in output, output
+    assert "passed" not in output, output
+    assert result.returncode != 0, output
+
+
+def _test_job_timeout_minutes(workflow_text: str) -> int:
+    """The `test` job's `timeout-minutes` in .github/workflows/test.yml."""
+    import yaml
+
+    jobs = yaml.safe_load(workflow_text)["jobs"]
+    value = jobs["test"]["timeout-minutes"]
+    assert isinstance(value, int) and not isinstance(value, bool)
+    return value
+
+
+def test_faulthandler_is_a_last_resort_above_the_kill_timeout(
     pytestconfig: pytest.Config,
 ) -> None:
-    """So the stack dump always lands before the process-level kill.
+    """The committed ordering: kill first, GIL-free dump only after it.
+
+    `faulthandler_timeout` below `timeout` is the configuration that segfaulted
+    CI: any slow-but-running test crossing it got a GIL-free walk of a moving
+    frame chain. Above the kill, pytest-timeout fails the item first (and its
+    failure cancels the faulthandler timer), so faulthandler only fires for a
+    thread the kill could not reach -- and then it must exit, not continue.
 
     Compared numerically: `getini` hands back a float for one and a string for
-    the other (`[tool.pytest.ini_options]` scalars load as strings), so an
-    `isinstance(..., int)` check would be invalid either way.
+    the other (`[tool.pytest.ini_options]` scalars load as strings).
     """
     faulthandler_timeout = float(pytestconfig.getini("faulthandler_timeout"))
     kill_timeout = float(pytestconfig.getini("timeout"))
 
-    assert faulthandler_timeout > 0
-    assert faulthandler_timeout < kill_timeout
-    # Both must fit inside the `test` job's `timeout-minutes: 25`, or the
-    # 25-minute silent cancel this change exists to replace happens anyway.
-    assert kill_timeout < 25 * 60
+    assert pytestconfig.getini("timeout_method") == "signal"
+    assert 0 < kill_timeout < faulthandler_timeout
+    assert pytestconfig.getini("faulthandler_exit_on_timeout") is True
+    # Both must fit inside the `test` job's cap, or the silent job-cap cancel
+    # this change exists to replace happens anyway. Read the real cap rather
+    # than restating it, so the two cannot drift apart.
+    workflow = Path(__file__).resolve().parents[2] / ".github/workflows/test.yml"
+    cap = _test_job_timeout_minutes(workflow.read_text())
+    assert faulthandler_timeout < cap * 60
 
 
 # The shape the real hang is believed to have: a coroutine suspended on an