From 65fada0945eda8ce366bffa7c4cb9c2bc1abc2cf Mon Sep 17 00:00:00 2001 From: Jack Lau <72348727+jackulau@users.noreply.github.com> Date: Sun, 16 Aug 2026 08:41:19 -0500 Subject: [PATCH] fix(update): bound the cua-driver installer drain after a failed kill On Windows, `hermes update` can hang past its own 660s cua-driver timeout until the user kills an orphaned PowerShell by hand. The timeout ceiling is not the problem; the code that runs after it is. `_run_cua_driver_installer` handles `TimeoutExpired` by killing the process tree and then draining the pipes with a bare `proc.communicate()`. The kill is best-effort by construction: every `psutil.Error` in `_kill_installer_tree` is logged at debug level and stepped over, on the reasoning that a partly killed tree beats none. That is the right call, but it means the drain has to survive a partial kill, and an unbounded drain does not. The concrete case is the one reported. `install.ps1` self-elevates through `Start-Process -Verb RunAs`, so the descendant runs at High integrity and a medium-integrity `child.kill()` raises `AccessDenied`. The per-child handler logs it and continues. That survivor is still holding the `stdout=PIPE` write handle it inherited, so the following `communicate()` waits for an EOF that arrives only when somebody kills that process manually. A bounded 660s wait becomes an unbounded one, after the warning has already printed. Bound the drain instead. A kill that landed closes the pipe immediately, so this costs nothing on the normal path; a kill that did not costs 15s rather than forever. The original `TimeoutExpired` is re-raised either way, so the existing manual re-run hint still prints and the update unwinds. Losing the tail of a timed-out installer's log is the cheaper half of that trade, and it is only lost in the case where the run already failed. The drain deliberately does not close the pipe handles. `communicate()`'s reader threads are still blocked on them and closing underneath them races; they are daemon threads, so abandoning them does not hold the interpreter open. Both timeout handlers (streaming and captured) now go through one helper. The streaming child inherits the console rather than a pipe, so it is much harder to stall there, but the two branches should not drift on a rule this small. Tests: 5, in a new `TestInstallerTimeoutDrainIsBounded`. Two fail without the fix, including the reported scenario end to end (a child kill refused with `psutil.AccessDenied`, asserting the drain still carries a deadline). The deadline is asserted as a kwarg rather than by timing, because a test that proved the hang by hanging would be the same defect wearing a test's name. Scope note: this does not touch the `stdin` inheritance that lets `install.ps1`'s `Read-Host` block in the first place. That is #79684 and open PR #79871 already carries the one-line `stdin=DEVNULL` fix; the two are independent and neither subsumes the other, since `DEVNULL` cannot unblock a UAC elevation dialog. Fixes #87703 --- hermes_cli/tools_config.py | 53 +++++- tests/hermes_cli/test_install_cua_driver.py | 183 ++++++++++++++++++++ 2 files changed, 232 insertions(+), 4 deletions(-) diff --git a/hermes_cli/tools_config.py b/hermes_cli/tools_config.py index 792552adfa..9a92fe77f4 100644 --- a/hermes_cli/tools_config.py +++ b/hermes_cli/tools_config.py @@ -1291,6 +1291,15 @@ def install_cua_driver( # headroom for the actual download/swap. _CUA_INSTALLER_TIMEOUT = 660 +# Grace period for draining the installer's pipes after a timeout kill. The +# kill is best-effort (see _reap_after_timeout), so this drain has to be +# bounded: a descendant that survived the kill still holds the inherited +# stdout handle, and an unbounded read waits on an EOF that never comes, +# which turns the ceiling above into no ceiling at all (issue #87703). A +# successful kill closes the pipe immediately, so this costs nothing in the +# normal case; it only caps how long a failed one can stall the update. +_CUA_INSTALLER_DRAIN_GRACE = 15 + # Upstream installer's stale-lock threshold (LOCK_STALE_AFTER_SECONDS in # _install-rust.sh). Used by the pre-clear below to avoid yanking a lock # that a live-but-slow install still holds. @@ -1701,6 +1710,44 @@ def _run_cua_driver_installer( except (OSError, ProcessLookupError): proc.kill() + def _reap_after_timeout(proc): + """Kill the installer tree, then drain its pipes under a deadline. + + ``_kill_installer_tree`` is best-effort by construction: every + ``psutil.Error`` it can raise is logged at debug level and stepped + over, on the reasoning that a partly-killed tree beats none. The case + that matters is an ``install.ps1`` which self-elevated through + ``Start-Process -Verb RunAs``: that descendant runs at High integrity, + a medium-integrity kill gets ``AccessDenied``, and the survivor is + still holding the ``stdout=PIPE`` write handle it inherited. + + Draining with no deadline then blocks on an EOF that only arrives when + someone kills that process by hand, so the ``_CUA_INSTALLER_TIMEOUT`` + ceiling stops bounding anything and ``hermes update`` hangs past its + own timeout warning (#87703). Bound the drain instead: a kill that + landed closes the pipe at once, and one that did not costs + ``_CUA_INSTALLER_DRAIN_GRACE`` rather than forever. The caller + re-raises the original ``TimeoutExpired`` either way, so the manual + re-run hint still prints and the update unwinds. Losing the tail of a + timed-out installer's log is the cheaper half of that trade. + """ + _kill_installer_tree(proc) + try: + proc.communicate(timeout=_CUA_INSTALLER_DRAIN_GRACE) + except subprocess.TimeoutExpired: + # Deliberately not closing proc.stdout here. communicate()'s + # reader threads are still blocked on that handle and closing it + # underneath them races; they are daemon threads, so abandoning + # them does not keep the interpreter alive. + logger.debug( + "cua-driver installer pipes still open %ss after the kill — " + "abandoning the drain, a surviving descendant holds the " + "inherited handle", + _CUA_INSTALLER_DRAIN_GRACE, + ) + except (OSError, ValueError) as e: + logger.debug("cua-driver installer drain failed: %s", e) + try: # When not verbose (e.g. `hermes update`'s refresh), capture the # installer's chatty "Next steps" wall instead of dumping it to the @@ -1716,8 +1763,7 @@ def _run_cua_driver_installer( try: proc.communicate(timeout=_CUA_INSTALLER_TIMEOUT) except subprocess.TimeoutExpired: - _kill_installer_tree(proc) - proc.communicate() + _reap_after_timeout(proc) raise result = subprocess.CompletedProcess( install_cmd, proc.returncode, stdout=None, stderr=None @@ -1734,8 +1780,7 @@ def _run_cua_driver_installer( try: out, _ = proc.communicate(timeout=_CUA_INSTALLER_TIMEOUT) except subprocess.TimeoutExpired: - _kill_installer_tree(proc) - proc.communicate() + _reap_after_timeout(proc) raise result = subprocess.CompletedProcess( install_cmd, proc.returncode, stdout=out, stderr=None diff --git a/tests/hermes_cli/test_install_cua_driver.py b/tests/hermes_cli/test_install_cua_driver.py index 1d2b62e4ab..65b90dcd9e 100644 --- a/tests/hermes_cli/test_install_cua_driver.py +++ b/tests/hermes_cli/test_install_cua_driver.py @@ -1081,6 +1081,189 @@ class TestInstallerTimeoutKillsProcessGroup: assert fake_proc.communicate.call_count == 2 +class TestInstallerTimeoutDrainIsBounded: + """The drain that follows the timeout kill must carry its own deadline. + + ``_kill_installer_tree`` is best-effort: every ``psutil.Error`` it can hit + is logged at debug level and stepped over, so the tree it leaves behind + can still contain a live process — on Windows, most concretely, an + ``install.ps1`` that self-elevated through ``Start-Process -Verb RunAs`` + and cannot be killed from a medium-integrity parent. That survivor holds + the ``stdout=PIPE`` write handle it inherited, so reading to EOF is + reading for something that will not happen, and ``_CUA_INSTALLER_TIMEOUT`` + stops being a ceiling (#87703). + + Asserted through the ``timeout`` kwarg rather than by timing: a test that + proved the hang by hanging would be the same defect wearing a test's name. + """ + + def test_drain_grace_is_short_relative_to_the_run_ceiling(self): + from hermes_cli import tools_config + + # This is a grace period for a pipe that a live process is holding + # open, not a second budget for the install itself — the install is + # already over by the time it is used. + assert 0 < tools_config._CUA_INSTALLER_DRAIN_GRACE + assert ( + tools_config._CUA_INSTALLER_DRAIN_GRACE + < tools_config._CUA_INSTALLER_TIMEOUT / 10 + ) + + @pytest.mark.linux_only + def test_post_kill_drain_passes_a_deadline(self): + """``linux_only``: reaches the timeout handler through the real POSIX + ``killpg`` branch, so the drain under test is the one this lane runs. + """ + import subprocess + from unittest.mock import MagicMock + from hermes_cli import tools_config + + fake_proc = MagicMock() + fake_proc.pid = 12345 + fake_proc.communicate.side_effect = [ + subprocess.TimeoutExpired(cmd="x", timeout=1), + ("", None), + ] + + with patch("subprocess.run", return_value=MagicMock(returncode=0, stderr="")), \ + patch("subprocess.Popen", return_value=fake_proc), \ + patch.object(tools_config.os, "getpgid", return_value=99999, create=True), \ + patch.object(tools_config.os, "killpg", create=True), \ + patch.object(tools_config, "_clear_stale_cua_install_lock"), \ + patch.object(tools_config, "_print_warning"), \ + patch.object(tools_config, "_print_info"): + ok = tools_config._run_cua_driver_installer(label="Refreshing", verbose=False) + + assert ok is False + assert fake_proc.communicate.call_count == 2 + drain_timeout = fake_proc.communicate.call_args_list[1].kwargs.get("timeout") + assert drain_timeout is not None, ( + "the post-kill drain was issued without a deadline, so a survivor " + "of the kill can hold it open indefinitely" + ) + assert drain_timeout == tools_config._CUA_INSTALLER_DRAIN_GRACE + + @pytest.mark.linux_only + def test_verbose_path_drains_under_the_same_deadline(self): + """The streaming install has the same handler and had the same hole. + + Its child inherits the console rather than a pipe, so the stall is + harder to hit there, but the two branches should not be allowed to + drift on a rule this small. + """ + import subprocess + from unittest.mock import MagicMock + from hermes_cli import tools_config + + fake_proc = MagicMock() + fake_proc.pid = 12345 + fake_proc.communicate.side_effect = [ + subprocess.TimeoutExpired(cmd="x", timeout=1), + ("", None), + ] + + with patch("subprocess.run", return_value=MagicMock(returncode=0, stderr="")), \ + patch("subprocess.Popen", return_value=fake_proc), \ + patch.object(tools_config.os, "getpgid", return_value=99999, create=True), \ + patch.object(tools_config.os, "killpg", create=True), \ + patch.object(tools_config, "_clear_stale_cua_install_lock"), \ + patch.object(tools_config, "_print_warning"), \ + patch.object(tools_config, "_print_info"), \ + patch.object(tools_config, "_print_success"): + ok = tools_config._run_cua_driver_installer(label="Installing", verbose=True) + + assert ok is False + assert fake_proc.communicate.call_count == 2 + drain_timeout = fake_proc.communicate.call_args_list[1].kwargs.get("timeout") + assert drain_timeout is not None, ( + "the streaming path's drain was issued without a deadline" + ) + assert drain_timeout == tools_config._CUA_INSTALLER_DRAIN_GRACE + + @pytest.mark.windows_only + def test_unkillable_elevated_descendant_does_not_stall_the_drain(self): + """The reported scenario, with the kill refused exactly where it is. + + ``install.ps1`` self-elevates, so the descendant is High-IL and + ``child.kill()`` raises ``AccessDenied`` — which the tree-kill catches + and logs, by design. The survivor is then still holding the pipe, and + the drain is the only thing standing between that and an indefinite + hang. + """ + import psutil + import subprocess + from unittest.mock import MagicMock + from hermes_cli import tools_config + + child = MagicMock() + child.kill.side_effect = psutil.AccessDenied(pid=999) + parent = MagicMock() + parent.children.return_value = [child] + + fake_proc = MagicMock() + fake_proc.pid = 12345 + fake_proc.communicate.side_effect = [ + subprocess.TimeoutExpired(cmd="powershell", timeout=1), + ("", None), + ] + + with patch("subprocess.Popen", return_value=fake_proc), \ + patch("psutil.Process", return_value=parent), \ + patch.object(tools_config, "_clear_stale_cua_install_lock"), \ + patch.object(tools_config, "_print_warning"), \ + patch.object(tools_config, "_print_info"): + ok = tools_config._run_cua_driver_installer( + label="Refreshing", verbose=False + ) + + assert ok is False + # The refused child kill must not abort the rest of the sweep. + parent.kill.assert_called_once_with() + drain_timeout = fake_proc.communicate.call_args_list[1].kwargs.get("timeout") + assert drain_timeout is not None, ( + "a High-IL descendant survived the kill and the drain was issued " + "without a deadline, which is the reported hang" + ) + assert drain_timeout == tools_config._CUA_INSTALLER_DRAIN_GRACE + + @pytest.mark.windows_only + def test_drain_that_times_out_still_surfaces_the_run_timeout(self): + """A guardrail, not a regression test — it passes without the fix too. + + What it pins is that the drain's own ``TimeoutExpired`` must not be + the one that escapes: the caller has to see the original run timeout + so the existing manual re-run hint prints and ``hermes update`` + unwinds. That is the behaviour a future refactor of the drain is most + likely to break silently. + """ + import subprocess + from unittest.mock import MagicMock + from hermes_cli import tools_config + + parent = MagicMock() + parent.children.return_value = [] + + fake_proc = MagicMock() + fake_proc.pid = 12345 + fake_proc.communicate.side_effect = [ + subprocess.TimeoutExpired(cmd="powershell", timeout=660), + subprocess.TimeoutExpired(cmd="powershell", timeout=15), + ] + + with patch("subprocess.Popen", return_value=fake_proc), \ + patch("psutil.Process", return_value=parent), \ + patch.object(tools_config, "_clear_stale_cua_install_lock"), \ + patch.object(tools_config, "_print_warning") as warn, \ + patch.object(tools_config, "_print_info"): + ok = tools_config._run_cua_driver_installer( + label="Refreshing", verbose=False + ) + + assert ok is False + warned = " ".join(str(c.args[0]) for c in warn.call_args_list if c.args) + assert "timed out after" in warned + + @pytest.mark.linux_only class TestInstallerNoShell: """The POSIX installer path must not use shell=True or command