From ba3d327c22a888a95ec8b9cd34ba7da7e4645d86 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Davor=20Raci=C4=87?= Date: Tue, 21 Jul 2026 00:04:44 +0200 Subject: [PATCH] fix(adapters): pipe psmux pane logs through a positional sidecar sink (#217) psmux pipe-pane strips every dash-flag token from the piped command, so the pwsh -EncodedCommand sink died on spawn; and the CopyTo sink parked bytes in a 4 KB buffer with unreliable pipe EOF, so run logs stayed empty. Write the sink source to a sidecar .sink.ps1 and invoke it positionally with a chunked read/write loop that flushes per chunk, so the live-tailed log receives pane bytes incrementally and byte-exact. --- src/bmad_loop/adapters/psmux_backend.py | 54 +++++++++++++++++-------- tests/test_psmux_backend.py | 33 ++++++++++++--- 2 files changed, 65 insertions(+), 22 deletions(-) diff --git a/src/bmad_loop/adapters/psmux_backend.py b/src/bmad_loop/adapters/psmux_backend.py index ba437fbb..db17227f 100644 --- a/src/bmad_loop/adapters/psmux_backend.py +++ b/src/bmad_loop/adapters/psmux_backend.py @@ -7,9 +7,11 @@ hooks, plus the handful of behaviors where psmux diverges from tmux: window-level ``-e`` is accepted but silently dropped, an attaching ``new-session`` is refused by a nesting guard when run from inside a psmux -pane, ``kill-session`` ignores the ``=name`` exact-match form, and a quoted +pane, ``kill-session`` ignores the ``=name`` exact-match form, a quoted command string does not survive psmux's outer re-parse (so shell source -travels as ``pwsh -EncodedCommand``). ``available()`` additionally gates on +travels as ``pwsh -EncodedCommand``), and ``pipe-pane`` strips every +dash-flag token from the piped command (so the log sink travels as a +positional sidecar ``.ps1``). ``available()`` additionally gates on the reported version: psmux releases up to 3.3.6 kill recycled PIDs during pane/session teardown without a process-identity check, which can take down an unrelated long-lived process mid-run. See :mod:`.multiplexer` for the @@ -170,24 +172,44 @@ def kill_session(self, name: str) -> None: pass def pipe_pane(self, window_id: str, log_file: Path) -> None: - # The base's POSIX `cat >>` sink assumes a POSIX host shell; psmux runs - # the pipe command on the host shell, so ship a pwsh append sink instead. - # A raw stream copy is byte-exact like `cat >>`: no console decode of the - # pane bytes, no Add-Content re-encode, no CRLF normalization. + # The base's POSIX `cat >>` sink assumes a POSIX host shell, and psmux + # strips every dash-flag token from the piped command before spawning it + # (psmux/psmux#482) — any `pwsh -EncodedCommand` transport dies on launch + # — so the sink source lives in a sidecar .ps1 invoked positionally. The + # sink is byte-exact like `cat >>` (raw stream copy: no console decode of + # the pane bytes, no re-encode, no CRLF normalization) and flushes per + # chunk: the run log is live-tailed for activity detection, and a + # buffered copy never surfaces bytes — pipe EOF is unreliable on psmux. + # Known ceilings until upstream restores a flag transport: whether a + # spaced or $-bearing path survives psmux's quote re-parse is untested, + # an AllSigned/Restricted execution policy refuses the unsigned .ps1, + # and a spawn race that exits 0 still yields a silent empty log — the + # warning below covers surfaced failures only. + sink_file = log_file.with_name(log_file.name + ".sink.ps1") + if any(char in str(sink_file) for char in ("$", "`")): + print( + f"warning: pipe-pane log capture failed for {window_id}: " + "sidecar path contains PowerShell interpolation syntax", + file=sys.stderr, + ) + return sink = ( + "$in = [System.Console]::OpenStandardInput()\n" f"$out = [System.IO.File]::Open({_pwsh_quote(str(log_file))}, " - "'Append', 'Write', 'Read'); " - "[System.Console]::OpenStandardInput().CopyTo($out); $out.Dispose()" + "'Append', 'Write', 'Read')\n" + "$buf = New-Object byte[] 4096\n" + "while (($n = $in.Read($buf, 0, $buf.Length)) -gt 0) " + "{ $out.Write($buf, 0, $n); $out.Flush() }\n" + "$out.Dispose()\n" ) - wrapped = self._shell_wrap(sink) - # base64 has no quoting to lose, so a plain join survives psmux's re-parse - # — valid only while no wrapped arg contains a space. - assert all(" " not in part for part in wrapped) try: - self._tmux("pipe-pane", "-t", window_id, "-o", " ".join(wrapped)) - except TmuxError as exc: - # Best-effort, as the base: a window that died on launch is not a - # setup failure — but say so, or an empty run log is unexplainable. + sink_file.write_text(sink, encoding="utf-8") + self._tmux("pipe-pane", "-t", window_id, "-o", f'pwsh "{sink_file}"') + except (TmuxError, OSError, UnicodeEncodeError) as exc: + # Best-effort, as the base: a window that died on launch (or psmux's + # first-pipe-after-new-window spawn race, noted in psmux/psmux#482) + # is not a setup failure — but say so, or an empty run log is + # unexplainable. print( f"warning: pipe-pane log capture failed for {window_id}: {exc}", file=sys.stderr, diff --git a/tests/test_psmux_backend.py b/tests/test_psmux_backend.py index 0cfb5926..1f2cb7e2 100644 --- a/tests/test_psmux_backend.py +++ b/tests/test_psmux_backend.py @@ -275,18 +275,22 @@ def test_new_parked_window_composes_pwsh_source(rec, tmp_path): # ------------------------------------------------------------------ pipe_pane -def test_pipe_pane_ships_pwsh_sink(rec, tmp_path): +def test_pipe_pane_ships_positional_sidecar_sink(rec, tmp_path): log = tmp_path / "win's.log" PsmuxMultiplexer().pipe_pane("@1", log) assert rec.argv[:5] == ["psmux", "pipe-pane", "-t", "@1", "-o"] - launch = rec.argv[5].split(" ") - assert launch[:3] == ["pwsh", "-NoProfile", "-EncodedCommand"] - sink = _decode(launch[3]) - # byte-exact raw stream copy (no console decode / re-encode / CRLF mangling) + # psmux strips every dash-flag token from the piped command, so the sink + # must be a purely positional launch of a sidecar script + sidecar = tmp_path / "win's.log.sink.ps1" + assert rec.argv[5] == f'pwsh "{sidecar}"' + sink = sidecar.read_text(encoding="utf-8") + # byte-exact raw stream copy (no console decode / re-encode / CRLF mangling), + # flushed per chunk so the live tail sees bytes incrementally quoted = str(log).replace(chr(39), chr(39) * 2) assert f"[System.IO.File]::Open('{quoted}', 'Append', 'Write', 'Read')" in sink - assert "OpenStandardInput().CopyTo($out)" in sink + assert "$in.Read($buf, 0, $buf.Length)" in sink + assert "$out.Flush()" in sink def test_pipe_pane_swallows_failure_with_warning(monkeypatch, capsys, tmp_path): @@ -295,6 +299,23 @@ def test_pipe_pane_swallows_failure_with_warning(monkeypatch, capsys, tmp_path): assert "pipe-pane log capture failed" in capsys.readouterr().err +def test_pipe_pane_sidecar_write_failure_warns_without_spawning(rec, capsys, tmp_path): + # An unwritable sidecar path (missing log dir) must warn and skip the psmux + # call — never raise + assert PsmuxMultiplexer().pipe_pane("@1", tmp_path / "absent" / "log") is None + assert rec.calls == [] + assert "pipe-pane log capture failed" in capsys.readouterr().err + + +@pytest.mark.parametrize("syntax", ["$name", "`name"]) +def test_pipe_pane_rejects_interpolating_sidecar_path(rec, capsys, tmp_path, syntax): + log = tmp_path / f"{syntax}.log" + assert PsmuxMultiplexer().pipe_pane("@1", log) is None + assert rec.calls == [] + assert not log.with_name(log.name + ".sink.ps1").exists() + assert "PowerShell interpolation syntax" in capsys.readouterr().err + + # ------------------------------------------------------------------ selection