Files
hermes-agent/tests/test_desktop_update_windows_pipe_drain.py
T
brooklyn! 2b1bff624e fix(update): Windows Desktop updates finish instead of parking on "Updating Hermes" (#90937)
* fix(update): bound the Windows update hand-off's step pipe drain

Invoke-HermesStep collected each step's output with ReadToEndAsync().Result.
That task does not complete when the step exits; it completes when the pipe
reaches EOF. On Windows the write end of a redirected pipe goes to the child as
an inheritable handle, so every descendant spawned without its own redirection
holds a duplicate and EOF waits for the last of them to close it. hermes update
deliberately runs its build steps with stdout inherited, so the tree under a
step is arbitrarily deep and not something this script can enumerate. When one
of those descendants is a resident gateway, the pipe stays open for the life of
the gateway and the hand-off blocks forever.

Everything the hand-off owes the Desktop is downstream of that call:
.hermes-update-result.json is never written, .hermes-update-in-progress is never
cleared, and the Desktop is never relaunched. The app sits on "Updating Hermes"
until the user kills the gateway by hand, and the stale marker then refuses the
next update too.

Read both pipes in chunks into a StringBuilder and bound the drain once the step
process itself has exited. The bound cannot truncate a slow step: the clock only
starts after the process is gone, at which point everything it wrote is already
in the pipe buffer waiting to be read, so the grace only has to cover the final
drain. Chunked reads are what make abandoning safe at all, since .Result cannot
hand back a partial read.

Also switch to the bounded WaitForExit overload. The argument-less one waits on
redirected streams as well, which is the same unbounded wait by another name.

An abandoned drain logs one line to logs/desktop-update-handoff.log naming the
cause, so a truncated step log is never mistaken for a step that printed
nothing.

Measured on Windows 11 / PowerShell 5.1 against a step whose grandchild
inherits its stdout and outlives it by 45s: 47.4s before, 4.3s after, with the
step's exit code and output preserved in both.

Fixes #90455

* test(update): prove the hand-off survives a step that leaks its pipe

Four source-level guards on Invoke-HermesStep, scoped to that function so the
legitimate WaitForExit and .Result uses elsewhere in the script cannot mask a
regression: no ReadToEndAsync, a drain bound keyed on the step having exited,
no argument-less WaitForExit, and a log line when a drain is abandoned. All
four fail against the previous drain. They are source-level for the same
reason the sibling python-handoff guard is: Linux CI cannot execute the
PowerShell hand-off.

Source-level is not enough for a deadlock, though, so the script also grows a
-SelfTestPipeDrain fixture alongside the existing -SelfTestUi one. It needs no
checkout, no install and no update: it starts a step that spawns a grandchild
with UseShellExecute = $false and no redirection, which is exactly the shape
that makes the grandchild inherit the step's stdout and stderr, then exits 7
while the grandchild sleeps on. The fixture asserts the grandchild was still
alive when Invoke-HermesStep returned, so a pass cannot be a timing
coincidence, and that the exit code and the step's output both survived the
abandonment. A windows_only test drives it, so the OS lane runs the real
drain rather than a text match.

Measured on Windows 11 / PowerShell 5.1: 4.3s with the fix, 47.4s (the
grandchild's full lifetime) with the previous drain restored.

The python-handoff guard now reads the script with its -SelfTest* blocks
removed. Those blocks exercise the machinery deliberately and exit before any
marker, venv or desktop work, so the "every step drives python.exe, never the
hermes.exe shim" rule does not apply to them. Scoping the source that way
rather than allow-listing a target keeps that rule absolute for every real
step.

Refs #90455

* fix(update): don't meter the step drain that #90455's bound introduced

Chunked reads make the bounded drain possible, but the loop idled 150ms
after every chunk it consumed, so a step's output moved at one 16 KiB
buffer per tick (~107 KB/s). The pipe then backs up, which is
backpressure on the *running* step rather than a slow read: a chatty
step blocks on write() waiting for the reader.

`hermes update` is exactly that shape -- the Electron/vite build alone
is megabytes -- so the layer that fixed "the hand-off waits forever"
would have shipped "the hand-off is slow" in its place.

Idle only when both pipes came up empty, and idle on the reads
themselves (WaitAny with the same 150ms cap) rather than on the clock:
a freshly issued ReadAsync is rarely complete by the very next pass, so
a bare `if (-not $moved)` still sleeps between chunks. WaitAny expires
on its own, so a silent step keeps the marquee animating and keeps the
abandon deadline advancing.

Measured against the drain as submitted, same harness, one variable:

  4 MiB of step stdout      38.99s -> 0.07s
  1 MiB stdout + 1 MiB err  18.22s -> 0.27s
  leaked grandchild (20s)    3.24s -> 3.20s, exit code + output kept
  quiet step, exits at 4s    4.29s -> 4.04s, 29 passes (not spinning)

* test(update): make the pipe-drain fixture cover metering, not just deadlock

The fixture proved the drain returns while a descendant holds the pipe.
It could not have caught the opposite failure -- a drain slow enough to
backpressure the step it is reading -- and that is the regression the
first version of this fix shipped.

Add a flood arm: a step that writes megabytes and holds nothing, with a
wall-clock budget far under what a sleep-per-chunk drain needs. The two
arms bracket the contract from both sides: bounded when a descendant
holds the pipe open, never slower than the step can write.

Few large lines rather than many small ones, deliberately --
Write-HandoffLog is one Add-Content per line and runs inside the
measured window, so line-heavy output would time the logger.

Also drops the four source-grep guards. Reading windows.ps1's text to
assert it contains `$abandonAt` tests the shape of the source, not its
behavior: it passes on a drain that is wired wrong but spelled right,
fails on a correct refactor, and blocks the extraction it should
survive. AGENTS.md bans the pattern outright, and all four pass on the
metered drain. The executable arms cover the same contract and actually
run the code -- the Windows lane is where this is verified either way.

---------

Co-authored-by: Jack Lau <72348727+jackulau@users.noreply.github.com>
2026-08-20 12:41:17 -05:00

127 lines
5.5 KiB
Python

"""Regression: the Windows Desktop update hand-off must not meter its step pipes.
``scripts/desktop-update/windows.ps1`` runs each update step through
``Invoke-HermesStep``, which starts the step with ``RedirectStandardOutput`` /
``RedirectStandardError``. Reading those pipes back has two failure modes, and
this fixture covers both because they pull in opposite directions.
**Waiting for EOF (#90455).** The drain used to collect output with
``ReadToEndAsync().Result``. That task does not return when the *step* exits --
it returns when the *pipe* reaches EOF. On Windows the write end of a redirected
pipe is handed to the child as an inheritable handle, so every descendant
spawned without its own redirection holds a duplicate, and EOF waits for the
last of them to close it. ``hermes update`` deliberately runs build steps with
stdout inherited (the tee-stderr runner in ``hermes_cli/main.py``), so the
process tree under a step is arbitrarily deep and not something the hand-off can
enumerate. When one of those descendants is a resident gateway, the pipe never
closes and ``Invoke-HermesStep`` blocks for the life of the gateway.
Everything the hand-off owes the Desktop is downstream of that call:
``.hermes-update-result.json`` is never written, ``.hermes-update-in-progress``
is never cleared, and the Desktop is never relaunched -- so the app sits on
"Updating Hermes" until the user kills the gateway by hand, and the stale marker
then refuses the next update too.
**Trickling toward EOF.** The fix reads in chunks so an abandoned pipe still
yields what arrived. But a chunked drain that idles after every chunk it reads
is metered at one buffer per tick (16 KiB / 150ms ~ 107 KB/s), and because the
pipe then backs up that is backpressure on the *running* step, not just a slow
read -- a chatty step blocks on ``write()`` waiting for the reader. Measured on
this fixture's own flood arm: 4 MiB took 39.1s metered vs 0.09s unmetered, and a
step writing to both pipes took 18.3s vs 0.29s. ``hermes update`` is exactly this
shape; the Electron/vite build alone is megabytes.
So the contract is: bounded when a descendant holds the pipe open, and never
slower than the step can write. Both arms live in the script's own
``-SelfTestPipeDrain`` fixture, which is ``windows_only`` because Linux CI
cannot execute the PowerShell hand-off.
"""
from __future__ import annotations
import os
import subprocess
from pathlib import Path
import pytest
REPO_ROOT = Path(__file__).resolve().parent.parent
WINDOWS_PS1 = REPO_ROOT / "scripts" / "desktop-update" / "windows.ps1"
@pytest.mark.windows_only
def test_pipe_drain_survives_a_leak_without_metering_a_chatty_step(
tmp_path: Path,
) -> None:
"""Execute the real drain against both shapes of step.
``-SelfTestPipeDrain`` runs two steps through the real
``Invoke-HermesStep``:
*leak* -- a step that spawns a grandchild with ``UseShellExecute = $false``
and no redirection (the shape that makes the grandchild inherit the step's
stdout/stderr), then exits 7 while the grandchild sleeps on. The fixture
asserts the grandchild was **still alive** when ``Invoke-HermesStep``
returned, so a pass cannot be a timing coincidence, and that the exit code
and the step's output both survived the abandonment.
*flood* -- a step that writes megabytes and holds nothing, exiting 5. It
must complete in wall-clock far under what a sleep-per-chunk drain would
take, and every byte must arrive.
Measured on Windows 11 / PowerShell 5.1: leak 4.3s (vs 47.4s waiting out the
grandchild), flood 8 MiB in ~1s (vs ~76s metered).
"""
system_root = Path(os.environ.get("SystemRoot", r"C:\Windows"))
powershell = (
system_root / "System32" / "WindowsPowerShell" / "v1.0" / "powershell.exe"
)
if not powershell.is_file():
pytest.skip(f"Windows PowerShell not found at {powershell}")
env = {
**os.environ,
# The fixture writes its child scripts, pid file and hand-off log under
# TEMP; point that at tmp_path so the test leaves nothing behind.
"TEMP": str(tmp_path),
"TMP": str(tmp_path),
# Keep the test quick. The grace is what the fix bounds; the hold is
# how long the leaking grandchild lives. hold >> grace is what makes a
# regression measurable rather than lucky.
"HERMES_UPDATE_PIPE_DRAIN_SECONDS": "3",
"HERMES_SELFTEST_HOLD_SECONDS": "45",
}
result = subprocess.run(
[
str(powershell),
"-NoProfile",
"-ExecutionPolicy",
"Bypass",
"-File",
str(WINDOWS_PS1),
"-SelfTestPipeDrain",
],
capture_output=True,
text=True,
# Comfortably past both arms' worst cases (the 45s hold, and a metered
# flood) so a regression fails with the fixture's own diagnosis instead
# of an opaque timeout.
timeout=300,
env=env,
cwd=str(REPO_ROOT),
)
assert "PIPE-DRAIN SELF-TEST: PASS" in result.stdout, (
"The Windows update hand-off's step drain regressed: it either waited "
"on a descendant holding the pipe open (the Desktop parks on 'Updating "
"Hermes' forever) or metered a chatty step (backpressure on the running "
f"update). Fixture diagnosis follows.\n--- stdout ---\n{result.stdout}\n"
f"--- stderr ---\n{result.stderr}"
)
assert result.returncode == 0, (
f"-SelfTestPipeDrain exited {result.returncode}.\n"
f"--- stdout ---\n{result.stdout}\n--- stderr ---\n{result.stderr}"
)