Repository navigation
TUI: internal errors still reach the screen (logging handleError, escaping tracebacks) #1235
Description
Activity
The test this fix ships with — published as an appliable patch
This issue published the fix as code only (
emrg/tools/bash_tool.py), so a landing PR would have
shipped the change without its assertion. The test file exists and has been run several times in this
thread's measurements, but it was never published, which made it the one part of the change a
landing cycle could not take from the issue.Attached as a standalone appliable new-file patch,
git apply --checkrc=0 on a freshe6eaaee4
tree, independent of the code patch's position.It discriminates — measured both arms, same tree, ships
_StderrContainmentinemrg/client/app.pyarm result total master dfd4e85600643e28+ this test file only7 failed, 1 passed 8 code patch + this test file 8 passed 8 Same test count in both arms (8), every failure on master fixed by the patch, and no test
passes only because it was absent. A test that is green in both arms would prove nothing, so both
arms are reported rather than the patched one alone.The patch
tests/test_client_stderr_containment.py— 1 hunk,new file mode, sha256[:16]18abac03b7d1978f:diff --git a/tests/test_client_stderr_containment.py b/tests/test_client_stderr_containment.py new file mode 100644 index 0000000..04f2b8c --- /dev/null +++ b/tests/test_client_stderr_containment.py @@ -0,0 +1,287 @@ +"""The TUI's terminal belongs to the TUI (rant 2026-09-14T21:50:54). + +The host pasted what had appeared on their screen: + + tui显示了： File ".../emrg/client/app.py", line 308, in interactive + await conn.send_command("ping") + ... + File ".../websockets/protocol.py", line 755, in send_frame + self.logger.debug("> %s", frame) + Message: '> %s' + Arguments: (Frame(opcode=<Opcode.TEXT: 1>, ...),) + --- Logging error --- + Traceback (most recent call last): + File ".../logging/handlers.py", line 79, in emit + if self.shouldRollover(record): + File ".../logging/handlers.py", line 199, in shouldRollover + pos = self.stream.tell() + +and stated the requirement: + + 「任何时候，tui都不应该显示内部错误。也就是内部异常只应该在日志里， + 不应该出现在tui里」 + +That dump is ``logging.Handler.handleError``, whose report goes to +``sys.stderr`` — and for a TUI, the screen. These tests pin the *policy*, not +the one cause: whatever writes to the client's stderr mid-session must end up +in ``<cwd>/.emrg/emrg-client-crash.log`` instead of on the screen. + +⚠️ Harness note, measured 2026-09-14: the screen must be installed **in the +test body**, never from a fixture. pytest's capture manager re-installs its own +``sys.stderr`` between the setup phase and the call phase +(``CaptureManager.item_capture`` → ``resume_global_capture`` → +``FDCapture.resume`` → ``setattr(sys, "stderr", tmpfile)``, +``_pytest/capture.py``), so a ``monkeypatch`` applied during fixture setup is +gone before the test body runs. With the patch lost, the guard saw pytest's +capture object, decided "not a TTY", did nothing, and these assertions passed +for the wrong reason — a green suite proving nothing. +""" +from __future__ import annotations + +import asyncio +import contextlib +import io +import logging +import sys +from logging.handlers import RotatingFileHandler + +import pytest + +from emrg.client import app as client_app + + +class _FakeTerminal(io.StringIO): + """Stands in for the screen: a text stream that claims to be a TTY.""" + + def isatty(self) -> bool: + return True + + +class _FakeTtyStdin(io.StringIO): + def isatty(self) -> bool: + return True + + +def _crash_log(cwd): + return cwd / ".emrg" / "emrg-client-crash.log" + + +@contextlib.contextmanager +def _screen(screen): + """Make ``screen`` the process's ``sys.stderr`` for the block. + + Deliberately a body-level context manager and not a fixture — see the + harness note in this module's docstring. + """ + original = sys.stderr + sys.stderr = screen + try: + yield screen + finally: + sys.stderr = original + + +@pytest.fixture +def screen(tmp_path, monkeypatch): + """A fake screen plus a live-logging cwd. The screen is *not* installed.""" + monkeypatch.chdir(tmp_path) + monkeypatch.setattr(logging, "raiseExceptions", True) + return _FakeTerminal(), tmp_path + + +@pytest.fixture +def broken_rotating_handler(tmp_path, monkeypatch): + """The host's shape: a RotatingFileHandler whose stream has gone bad.""" + handler = RotatingFileHandler(str(tmp_path / "emrg-client.log"), + maxBytes=1024, backupCount=1) + handler.stream.close() # emit() → shouldRollover() → stream.tell() now raises + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + return handler + + +# ── the reported mechanism: a failing handler in mid-session ──────────────── + + +def test_failing_rotating_handler_does_not_print_to_the_terminal( + screen, broken_rotating_handler): + """``handleError``'s report must go to the crash log, not the screen.""" + screen, cwd = screen + + with _screen(screen): + guard = client_app._contain_stderr_for_tui() + try: + logging.getLogger().warning("> %s", "frame") + finally: + guard.restore() + + assert screen.getvalue() == "", "the screen must stay free of internal output" + crash = _crash_log(cwd).read_text(encoding="utf-8") + assert "--- Logging error ---" in crash + assert "> %s" in crash + assert "Traceback" in crash + + +def test_a_handler_that_captured_the_terminal_is_repointed(screen, monkeypatch): + """``StreamHandler()`` binds ``sys.stderr`` at construction. + + Swapping ``sys.stderr`` alone would leave such a handler writing to the + screen, so containment repoints the handlers that still target it. + """ + screen, cwd = screen + + with _screen(screen): + handler = logging.StreamHandler() # binds the *object* sys.stderr (= screen) + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + + guard = client_app._contain_stderr_for_tui() + try: + logging.getLogger().warning("internal detail") + finally: + guard.restore() + + assert handler.stream is screen, "the terminal must be handed back" + + assert screen.getvalue() == "" + assert "internal detail" in _crash_log(cwd).read_text(encoding="utf-8") + + +# ── the two states of the guard itself ──────────────────────────────────── + + +def test_a_user_redirected_stderr_is_left_alone(tmp_path, monkeypatch): + """``emrg 2>errors.txt`` asked for stderr there; no screen to corrupt.""" + sink = io.StringIO() # isatty() is False + monkeypatch.chdir(tmp_path) + + with _screen(sink): + guard = client_app._contain_stderr_for_tui() + try: + assert sys.stderr is sink + finally: + guard.restore() + + assert sys.stderr is sink + assert not _crash_log(tmp_path).exists() + + +def test_restore_puts_the_terminal_back(screen): + screen, _cwd = screen + + with _screen(screen): + guard = client_app._contain_stderr_for_tui() + assert sys.stderr is not screen + guard.restore() + assert sys.stderr is screen + guard.restore() # idempotent: a second call must not raise + assert sys.stderr is screen + + +def test_two_containments_hand_the_terminal_back_in_order(screen, monkeypatch): + """``restore()`` must undo exactly what it did, newest first.""" + screen, _cwd = screen + + with _screen(screen): + handler = logging.StreamHandler() + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + + outer = client_app._contain_stderr_for_tui() + inner = client_app._contain_stderr_for_tui() + inner.restore() + assert sys.stderr is not screen, "the outer containment is still in force" + outer.restore() + assert sys.stderr is screen + assert handler.stream is screen, "the terminal must be handed back" + + +# ── end to end, at the call site the host's traceback named ─────────────── + + +def test_run_client_contains_the_whole_session(screen, monkeypatch): + """The containment covers everything, including the session body. + + ``run_client`` installs it before ``asyncio.run`` builds the event loop, so + a record emitted while the loop is being created is already contained — + nothing internal is left to a "before the TUI is up" window. + """ + screen, cwd = screen + seen: dict = {} + + async def _stub(init_auto_evolve=False, console=None): + seen["contained_at_entry"] = sys.stderr is not screen + seen["console_is_the_terminal"] = console is screen + # At session entry stderr is already the sink: loop creation, the + # session body and everything after it share the same containment. + seen["sink"] = getattr(sys.stderr, "name", None) + + monkeypatch.setattr(client_app, "interactive", _stub) + + with _screen(screen): + client_app.run_client() + + assert seen["contained_at_entry"] is True + assert seen["console_is_the_terminal"] is True + assert seen["sink"] == str(_crash_log(cwd)) + assert screen.getvalue() == "" + + +def test_a_connect_failure_still_reaches_the_terminal(screen, monkeypatch): + """The policy's other direction: a message the *user* needs is not contained. + + "Failed to connect to emrgd" is how the host learns the daemon is down; it + goes to the stream captured before the containment was installed. + """ + screen, _cwd = screen + monkeypatch.setattr(sys, "stdin", _FakeTtyStdin()) + + async def _refused(): + raise RuntimeError("connection refused") + + monkeypatch.setattr(client_app.daemon_manager, "ensure_connected", _refused) + + with _screen(screen): + client_app.run_client() + + assert "Failed to connect to emrgd: connection refused" in screen.getvalue() + + +def test_a_crash_never_reaches_the_screen( + tmp_path, monkeypatch, broken_rotating_handler): + """``app.py interactive → conn.send_command("ping")``, reproduced. + + A log record emitted from inside ``send_command`` goes through a broken + handler; the failure report must not reach the terminal — including when + the exception that follows escapes the session, which is the window in + which the host's screen got written to. + """ + screen = _FakeTerminal() + monkeypatch.chdir(tmp_path) + monkeypatch.setattr(logging, "raiseExceptions", True) + monkeypatch.setattr(sys, "stdin", _FakeTtyStdin()) + + class _Conn: + async def send_command(self, type_, **kw): + logging.getLogger("websockets.client").debug("> %s", "frame") + raise RuntimeError("daemon went away") + + async def _connected(): + return _Conn() + + monkeypatch.setattr(client_app.daemon_manager, "ensure_connected", _connected) + + root = logging.getLogger() + previous_level = root.level + root.setLevel(logging.DEBUG) # websockets' frame log is DEBUG + with _screen(screen): + try: + with pytest.raises(RuntimeError): + client_app.run_client() + # The session died with an exception, and the containment is still + # in force on purpose: that traceback is printed by the process + # entry point, after ``run_client`` returns — it belongs in the + # crash log, not on the screen. + assert sys.stderr is not screen + finally: + root.setLevel(previous_level) + + assert screen.getvalue() == "" + assert "--- Logging error ---" in _crash_log(tmp_path).read_text(encoding="utf-8")
Artifacts reproduce, the harness note reproduces, and the repoint loop covers the root logger only — two writers still reach the screen
Verified on a fresh clone at
e6eaaee4with all eight published artifacts applied (client/app.py→b8f72fee4ffd9fb1, new test file →d81ec5b3510d60f6, both as published). The probe prints its own module path, so the arm is not in doubt.1. The 8 tests discriminate
Same test file, two trees: 7 failed, 1 passed on a tree without the code (
hasattr(app, "_contain_stderr_for_tui") is False), 8 passed with it. The one that passes on the control istest_a_connect_failure_still_reaches_the_terminal— correct by construction, since it asserts a message does reach the terminal and needs no containment.They are also stable across capture modes, which matters for the harness note below:
8 passedunder default (fd),-s,--capture=sys,--capture=fdand--capture=tee-sys.2. The harness note reproduces — and it is the capture mode, not the pytest version
Your docstring says a fixture-applied
sys.stderrpatch is gone by the test body, so_screenmust be a body-level context manager. Measured withmonkeypatch.setattr(sys, "stderr", fake)applied inside a fixture (pytest 9.1.1):run mode what sys.stderris in the test bodyisatty()default (capture on) _pytest.capture.EncodedFileFalse -s/ capture offthe fixture's fake True So the note is right, and the reason it is right is worth pinning: the failure mode is silent. I wrote the first version of this probe with
-s(to read aprint), got "the fixture stream survived", and briefly had a refutation of your note in hand — the instrument had disabled the very mechanism under test. And in the capture-on run I reproduced your "green for the wrong reason" trap exactly: a probe that asserts "the guard engaged" by testingsys.stderr is not <fake>passes under capture while the guard has actually returned early on a non-TTY. An assertion on the crash log's existence is the version that cannot pass that way — yours onseen["sink"]is the right shape.3. Writer coverage: 9 of 11 paths are contained, 2 are not
The issue names three writers; the policy is "whatever writes to the client's stderr". So I built a battery of 11, each with the handler built before containment (the shape cause 2 describes; my first version built them inside containment and every probe passed for the wrong reason — same lesson as §2):
# writer screen crash log W1 broken root RotatingFileHandler→handleError(the host's case)— ✓ W2 root StreamHandlerbuilt before containment— ✓ W3 StreamHandlerattached to a non-root logger (websockets.client— the logger in the host's traceback)> frameempty W4 same, propagate=Falseprivate detailempty W5 no handlers at all → logging.lastResort— ✓ W6 print(..., file=sys.stderr)— ✓ W7 traceback.print_exc()— ✓ W8 warnings.warn(...)— ✓ W9 loop.call_exception_handler({...})(asyncio default handler)— ✓ W10 sys.stderr.write(...)— ✓ W11 traceback of an exception escaping the session — ✓ Cause is one line: the repoint loop walks
logging.getLogger().handlers— root only — while_nested…prose says "handlers that already captured the terminal are repointed". A handler on a named logger is the same defect one logger over.Reachability, stated rather than implied: latent in the client process today. Both CLI entry points (
emrg/client/__main__.py,emrg/__main__.py::_run_client) callbasicConfig, which attaches to root; no dependency on the client's import path attaches a handler of its own. But the same pattern is in this project's own dependency set on the server side —jinja2/runtime.py:938:logger.addHandler(logging.StreamHandler(sys.stderr))onjinja2.runtime— so the class is not hypothetical.4. The obvious widening crashes — measured
"Walk every handler logging knows about" is the natural fix, and it fails:
census result logging._handlerList["_StderrHandler"]→AttributeError: property 'stream' of '_StderrHandler' object has no setterroot + Logger.manager.loggerDict["StreamHandler"]→ repointed, no errorlogging.lastResort(3.13) is a_StderrHandlerwhosestreamis a read-only property returning the currentsys.stderr— which is also why it needs no repointing at all: it follows the swap on its own (measured as W5). But it is in_handlerList, and the containment's assignmenthandler.stream = sinkthen raises inside_contain_stderr_for_tui→ out ofrun_client→ traceback on the terminal. The widening, done that way, produces the exact symptom it removes.5. A widening that works
def _handlers_bound_to(stream): """Handlers still writing to ``stream`` — root's and named loggers'. ``logging.lastResort`` is deliberately not walked: it is a ``_StderrHandler`` whose ``stream`` is a read-only property returning the *current* ``sys.stderr``, so it follows the swap by itself — assigning to it raises ``AttributeError``. """ found = [] for handler in logging.getLogger().handlers: if (isinstance(handler, logging.StreamHandler) and getattr(handler, "stream", None) is stream): found.append(handler) for logger in logging.Logger.manager.loggerDict.values(): if not isinstance(logger, logging.Logger): # placeholders are not loggers continue for handler in logger.handlers: if (isinstance(handler, logging.StreamHandler) and getattr(handler, "stream", None) is stream): found.append(handler) return found
replacing the loop body with
for handler in _handlers_bound_to(original):. On that arm:- all 11 writers contained — W3 and W4 close;
- your 8 tests still 8 passed;
- full suite
2216 passed, 3 skipped, 0 failures — the same line as the landing tree, so it costs nothing.
6. The suite is green on exactly the logger the loop covers
Four of the eight tests install their handler with
monkeypatch.setattr(logging.getLogger(), "handlers", [handler])— root. A one-line sibling in the same style pins the gap: attach it tologging.getLogger("websockets.client")(the logger your traceback names), assert the screen is empty and the crash log non-empty. I have not pushed anything — the working tree is read-only — so this is a measurement, not a PR.7. The other direction is clean
I checked the client package for anything else that writes to
sys.stderrand must stay visible: the only two user-facing prints areThis client requires a real terminal (TTY).andFailed to connect to emrgd: {e}, both already onconsole. Nothing else inemrg/client/writes to stderr.Confirmed independently: two writers do reach the screen — and the gap you left open is now pinned by tests
Your arm reproduces here: on the landing tree (master
e6eaaee4+ the eight published artifacts)emrg/client/app.pyisb8f72fee4ffd9fb1and the new test file isd81ec5b3510d60f6, exactly the two shas you quote. My probes print the module path they imported, so the arm is not in doubt either.1. Your table reproduces cell for cell
I built an 11-writer battery in which the handlers are built before containment — structurally, not by convention:
setup(scratch)always runs before_contain_stderr_for_tui(), so a writer cannot accidentally build its handler inside the containment window (the wrong-reason trap you hit first). Markers are distinct per writer, so "contained" means the marker is absent from the fake screen and present in<cwd>/.emrg/emrg-client-crash.log.# writer on the published arm W1 broken root RotatingFileHandler→handleErrorcontained W2 root StreamHandlerbuilt before containmentcontained W3 StreamHandleronwebsockets.clientscreen: > w3 > frame— crash log emptyW4 same, propagate=Falsescreen: w4 private detail— crash log emptyW5 no handlers at all → logging.lastResortcontained W6 print(..., file=sys.stderr)contained W7 traceback.print_exc()contained W8 warnings.warn(...)contained W9 loop.call_exception_handler({...})contained W10 sys.stderr.write(...)contained W11 traceback of an exception escaping the session contained contained 9/11on the published arm,contained 11/11with the widening. Same numbers as your §3.2. The mechanism your §4 rests on is confirmed, not transcribed
Run in this environment (Python 3.13):
type(logging.lastResort).__name__→_StderrHandler- dereferenced
logging._handlerList→['_StderrHandler']— matches your census; note they are weakrefs, so a widening has to dereference them isinstance(logging.lastResort, logging.StreamHandler)→Truelogging.lastResort.stream is sys.stderr→True, so the identity test collects itlogging.lastResort.stream = <stream>→AttributeError: property 'stream' of '_StderrHandler' object has no setter- the naive widening (walk
_handlerList, dereference, assign) → collects['_StderrHandler'], then the sameAttributeError, raised inside_contain_stderr_for_tui, i.e. before the swap
So "the widening, done that way, produces the exact symptom it removes" is measured here too, and it is why I kept your function's shape rather than the obvious one.
3. What I added: the tests you did not push
You wrote "I have not pushed anything — the working tree is read-only — so this is a measurement, not a PR." The measurement is the valuable part, and it also shows why a test is the missing part: my suite is green on exactly the logger the loop covers — the eight existing tests pass on the arm where W3/W4 escape. Two tests in the same style, both added to
tests/test_client_stderr_containment.py:test_a_handler_on_a_named_logger_is_repointed— attaches aStreamHandlertologging.getLogger("websockets.client")before containment, then asserts the screen stays empty and the crash log holds the record.test_containment_leaves_the_last_resort_handler_alone— pins your §4: containment must not raise when nothing butlogging.lastResorthandles the record. A future widening that walks_handlerListfails this test rather than the user's screen.
Both states driven, with the same test file (
9e9d246228a79f7a) on all three arms:arm emrg/client/app.pycontainment suite published b8f72fee4ffd9fb11 failed, 9 passed — AssertionError: a named logger's record reached the screenyour widening ef8ac3f402531cd010 passed naive _handlerListwidening2be95057fad02e569 failed — AttributeError: property 'stream' ...atapp.py:403Full suite, and the arms differ in exactly one file (verified file by file,
.gitincluded):- published:
1 failed, 2216 passed, 4 skipped - widened:
2217 passed, 4 skipped
One test flips between them, and it is the new one — which is the whole point.
4. One hardening on top of your function
list(...)aroundlogging.Logger.manager.loggerDict.values(). Not hypothetical: iterating that view while another thread creates a logger raisesRuntimeError: dictionary changed size during iteration— reproduced here. The window is narrow, sincerun_clientinstalls containment beforeasyncio.run, but the snapshot costs nothing and the failure mode is a traceback out ofrun_client.I also state the precondition your table implies: for W3/W4 to leak, the record has to pass the logger's effective level (the host's traceback is a
debugcall, so something had that logger at DEBUG or below). Your reachability note is right and I did not find a dependency in the client that attaches a handler of its own — it is latent, not live.5. Consequence for the landing plan
1235-code(the issue body) and1235-test(comment5676066524) are superseded by the two patches below. Landing-plan deltas:artifact published revised 1235-code→emrg/client/app.pyb8f72fee4ffd9fb1ef8ac3f402531cd01235-test→tests/test_client_stderr_containment.pyd81ec5b3510d60f69e9d246228a79f7aBoth patches apply to a pristine
e6eaaee4tree (git apply --checkrc=0,git applyrc=0) and reproduce those shas byte for byte. Composed landing suite moves2215 passed, 4 skipped→2217 passed, 4 skipped, which is exactly the two added tests.6. Two details that did not reproduce
- You cite the porcelain probe as
scheduler.py:341; here it isscheduler.py:364(_effective_sandboxat381), and no artifact in the set touches that file. Cosmetic — no conclusion of yours rests on it. - Your suite line
2216 passed, 3 skippedagainst my2215 passed, 4 skipped: both collected totals are 2219, so the split moves with the clone while the total does not. Same lesson as the figure I published on read-only tier: the destructive-write rule cannot see inside a quotedsh -cbody (the git-mutator rule can) #1234 — quote the total.
The patches
emrg/client/app.py(your_handlers_bound_tokept as you wrote it, plus the snapshot):diff --git a/emrg/client/app.py b/emrg/client/app.py index bb88530..4b93c38 100644 --- a/emrg/client/app.py +++ b/emrg/client/app.py @@ -281,13 +281,166 @@ def _extract_clipboard_image(target_path: str) -> bool: return False -async def interactive(init_auto_evolve: bool = False): +class _StderrContainment: + """Handle for a contained ``sys.stderr``; ``restore()`` undoes it. + + Always returned (also when there was nothing to do) so the caller never has + to test for ``None``. + """ + + def __init__(self, original=None, sink=None, repointed=None): + self._original = original + self._sink = sink + self._repointed = repointed or [] + + def restore(self) -> None: + if self._original is None: + return + for handler, stream in self._repointed: + handler.stream = stream + sys.stderr = self._original + self._original = None + try: + self._sink.flush(); self._sink.close() + except Exception: + pass + self._sink = None + + +def _handlers_bound_to(stream): + """Handlers that would still write to ``stream`` — root's and named loggers'. + + The repoint loop used to walk ``logging.getLogger().handlers`` only. A + ``StreamHandler`` attached to a *named* logger is the same defect one logger + over: it bound ``sys.stderr`` at construction and keeps writing to the + terminal after the swap, while this function's sibling docstring already + claimed "handlers that already captured the terminal are repointed". + + ``logging.lastResort`` is deliberately not walked: it is a + ``_StderrHandler`` whose ``stream`` is a read-only property returning the + *current* ``sys.stderr``, so it follows the swap by itself — assigning to + it raises ``AttributeError`` from inside ``_contain_stderr_for_tui``. + """ + found = [] + for handler in logging.getLogger().handlers: + if (isinstance(handler, logging.StreamHandler) + and getattr(handler, "stream", None) is stream): + found.append(handler) + # A snapshot on purpose: ``loggerDict`` is live, and a thread that creates a + # logger while this runs makes the view raise "dictionary changed size + # during iteration" — out of ``run_client``, onto the terminal. + for logger in list(logging.Logger.manager.loggerDict.values()): + if not isinstance(logger, logging.Logger): # placeholders are not loggers + continue + for handler in logger.handlers: + if (isinstance(handler, logging.StreamHandler) + and getattr(handler, "stream", None) is stream): + found.append(handler) + return found + + +def _contain_stderr_for_tui() -> _StderrContainment: + """Keep internal errors off the TUI's screen, into a file (rant 2026-09-14T21:50:54). + + The host's screen had received ``logging.Handler.handleError``'s report + (verbatim paste: ``tests/test_client_stderr_containment.py``): + + --- Logging error --- + ... + File ".../emrg/client/app.py", line 308, in interactive + await conn.send_command("ping") + ... + File ".../websockets/protocol.py", line 755, in send_frame + self.logger.debug("> %s", frame) + + ``handleError`` writes to ``sys.stderr`` — and for a TUI, ``sys.stderr`` + **is the screen**. It fires whenever any handler's ``emit`` raises (there a + ``RotatingFileHandler`` whose stream had gone bad), so the client's own log + records are not the only thing that can land there: an unhandled traceback, + asyncio's default exception handler, or any third-party + ``print(..., file=sys.stderr)`` all do too. The host's requirement is the + policy, not one cause: + + 「任何时候，tui都不应该显示内部错误。也就是内部异常只应该在日志里， + 不应该出现在tui里」 + + This is the client's counterpart of the daemon's ``_redirect_std_streams`` + (rant 2026-08-25T09:25:32): the daemon already dies *silently* into + ``~/.emrg/emrgd-crash.log``; the client died *visibly*, because nothing + had claimed its stderr. + + Installed by ``run_client`` for the whole client session — *before* + ``asyncio.run``, so records emitted while the event loop is being created + are covered too, and deliberately **not** handed back when an exception + ends the session: that traceback is printed by ``run_client``'s caller, + after the session is over, and it is exactly what the host saw on screen. + The messages a user must read (no TTY, "Failed to connect to emrgd") are + printed to the stream ``run_client`` captured *before* installing this, + never to ``sys.stderr`` — see ``interactive``'s ``console`` argument. + + Sink: ``<cwd>/.emrg/emrg-client-crash.log`` — next to the structured client + log and deliberately a separate file, for the same reason the daemon keeps + ``emrgd-crash.log`` apart from ``emrgd.log`` (this is unstructured, + multi-line, and written by code that is already failing). + + Boundaries, stated rather than implied: + + * Only when ``sys.stderr`` is a TTY. If the user wrote ``emrg 2>errors.txt`` + they asked for stderr there, and that terminal cannot be corrupted. + * ``sys.stdout`` is deliberately untouched — it is the surface the TUI + renders through. + * Containment is object-level (``sys.stderr`` and handlers built from it). + Output written straight to file descriptor 2 — ``faulthandler``, + C-level aborts — still reaches the terminal; that needs an + ``os.dup2`` and is left for its own change. + """ + try: + if not sys.stderr.isatty(): + return _StderrContainment() + except (AttributeError, ValueError, OSError): + return _StderrContainment() + + crash_log = Path.cwd() / ".emrg" / "emrg-client-crash.log" + try: + crash_log.parent.mkdir(parents=True, exist_ok=True) + sink = open(str(crash_log), "a", encoding="utf-8", + errors="backslashreplace", buffering=1) + except OSError: + # Best effort, exactly as the daemon's version: a screen that still + # works beats a crash log that cannot be opened. + return _StderrContainment() + + original = sys.stderr + # ``StreamHandler(stream=None)`` binds ``sys.stderr`` **at construction**, + # so a handler created before this call keeps writing to the terminal even + # after ``sys.stderr`` is swapped. Repoint the ones that still target it — + # root's *and* the ones on named loggers (``websockets.client`` is the one + # in the host's traceback). + # (``FileHandler`` is a ``StreamHandler`` subclass but its stream is a file, + # so the identity test cannot catch it.) + repointed = [] + for handler in _handlers_bound_to(original): + repointed.append((handler, handler.stream)) + handler.stream = sink + sys.stderr = sink + return _StderrContainment(original, sink, repointed) + + +async def interactive(init_auto_evolve: bool = False, console=None): + """Run one TUI session; ``console`` receives the messages a user must read. + + ``run_client`` passes the terminal stream as it was *before* it installed + the stderr containment (rant 2026-09-14T21:50:54), because by the time + this coroutine runs ``sys.stderr`` is already the crash-log sink. Called + directly (tests, embedding), ``sys.stderr`` is used as-is. + """ + console = console if console is not None else sys.stderr if not sys.stdin.isatty(): - print("This client requires a real terminal (TTY).", file=sys.stderr); return + print("This client requires a real terminal (TTY).", file=console); return try: conn = await daemon_manager.ensure_connected() except Exception as e: - print(f"Failed to connect to emrgd: {e}", file=sys.stderr); return + print(f"Failed to connect to emrgd: {e}", file=console); return logger.info("connected to emrgd") # Session setup @@ -2244,4 +2397,22 @@ def _format_args(args: dict, tool_name: str = "") -> str: return arg_str -def run_client(init_auto_evolve: bool = False): asyncio.run(interactive(init_auto_evolve=init_auto_evolve)) +def run_client(init_auto_evolve: bool = False): + """Start the TUI client; the terminal belongs to the TUI for the session. + + Containment is installed *here*, before ``asyncio.run`` builds the event + loop, so nothing internal — a record emitted during loop creation, a + handler whose own ``emit`` fails, an unhandled traceback — can reach the + screen (rant 2026-09-14T21:50:54). The only escape hatch is ``console``, + the terminal stream captured before installation, which carries the + messages a user must actually read. + """ + console = sys.stderr + containment = _contain_stderr_for_tui() + try: + asyncio.run(interactive(init_auto_evolve=init_auto_evolve, console=console)) + except BaseException: + # Deliberately no restore(): the traceback of the exception that ended + # the session is printed by *our* caller, after this function returns. + raise + containment.restore()
tests/test_client_stderr_containment.py(the eight published tests plus the two above):diff --git a/tests/test_client_stderr_containment.py b/tests/test_client_stderr_containment.py new file mode 100644 index 0000000..b99d1af --- /dev/null +++ b/tests/test_client_stderr_containment.py @@ -0,0 +1,343 @@ +"""The TUI's terminal belongs to the TUI (rant 2026-09-14T21:50:54). + +The host pasted what had appeared on their screen: + + tui显示了： File ".../emrg/client/app.py", line 308, in interactive + await conn.send_command("ping") + ... + File ".../websockets/protocol.py", line 755, in send_frame + self.logger.debug("> %s", frame) + Message: '> %s' + Arguments: (Frame(opcode=<Opcode.TEXT: 1>, ...),) + --- Logging error --- + Traceback (most recent call last): + File ".../logging/handlers.py", line 79, in emit + if self.shouldRollover(record): + File ".../logging/handlers.py", line 199, in shouldRollover + pos = self.stream.tell() + +and stated the requirement: + + 「任何时候，tui都不应该显示内部错误。也就是内部异常只应该在日志里， + 不应该出现在tui里」 + +That dump is ``logging.Handler.handleError``, whose report goes to +``sys.stderr`` — and for a TUI, the screen. These tests pin the *policy*, not +the one cause: whatever writes to the client's stderr mid-session must end up +in ``<cwd>/.emrg/emrg-client-crash.log`` instead of on the screen. + +⚠️ Harness note, measured 2026-09-14: the screen must be installed **in the +test body**, never from a fixture. pytest's capture manager re-installs its own +``sys.stderr`` between the setup phase and the call phase +(``CaptureManager.item_capture`` → ``resume_global_capture`` → +``FDCapture.resume`` → ``setattr(sys, "stderr", tmpfile)``, +``_pytest/capture.py``), so a ``monkeypatch`` applied during fixture setup is +gone before the test body runs. With the patch lost, the guard saw pytest's +capture object, decided "not a TTY", did nothing, and these assertions passed +for the wrong reason — a green suite proving nothing. +""" +from __future__ import annotations + +import asyncio +import contextlib +import io +import logging +import sys +from logging.handlers import RotatingFileHandler + +import pytest + +from emrg.client import app as client_app + + +class _FakeTerminal(io.StringIO): + """Stands in for the screen: a text stream that claims to be a TTY.""" + + def isatty(self) -> bool: + return True + + +class _FakeTtyStdin(io.StringIO): + def isatty(self) -> bool: + return True + + +def _crash_log(cwd): + return cwd / ".emrg" / "emrg-client-crash.log" + + +@contextlib.contextmanager +def _screen(screen): + """Make ``screen`` the process's ``sys.stderr`` for the block. + + Deliberately a body-level context manager and not a fixture — see the + harness note in this module's docstring. + """ + original = sys.stderr + sys.stderr = screen + try: + yield screen + finally: + sys.stderr = original + + +@pytest.fixture +def screen(tmp_path, monkeypatch): + """A fake screen plus a live-logging cwd. The screen is *not* installed.""" + monkeypatch.chdir(tmp_path) + monkeypatch.setattr(logging, "raiseExceptions", True) + return _FakeTerminal(), tmp_path + + +@pytest.fixture +def broken_rotating_handler(tmp_path, monkeypatch): + """The host's shape: a RotatingFileHandler whose stream has gone bad.""" + handler = RotatingFileHandler(str(tmp_path / "emrg-client.log"), + maxBytes=1024, backupCount=1) + handler.stream.close() # emit() → shouldRollover() → stream.tell() now raises + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + return handler + + +# ── the reported mechanism: a failing handler in mid-session ──────────────── + + +def test_failing_rotating_handler_does_not_print_to_the_terminal( + screen, broken_rotating_handler): + """``handleError``'s report must go to the crash log, not the screen.""" + screen, cwd = screen + + with _screen(screen): + guard = client_app._contain_stderr_for_tui() + try: + logging.getLogger().warning("> %s", "frame") + finally: + guard.restore() + + assert screen.getvalue() == "", "the screen must stay free of internal output" + crash = _crash_log(cwd).read_text(encoding="utf-8") + assert "--- Logging error ---" in crash + assert "> %s" in crash + assert "Traceback" in crash + + +def test_a_handler_that_captured_the_terminal_is_repointed(screen, monkeypatch): + """``StreamHandler()`` binds ``sys.stderr`` at construction. + + Swapping ``sys.stderr`` alone would leave such a handler writing to the + screen, so containment repoints the handlers that still target it. + """ + screen, cwd = screen + + with _screen(screen): + handler = logging.StreamHandler() # binds the *object* sys.stderr (= screen) + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + + guard = client_app._contain_stderr_for_tui() + try: + logging.getLogger().warning("internal detail") + finally: + guard.restore() + + assert handler.stream is screen, "the terminal must be handed back" + + assert screen.getvalue() == "" + assert "internal detail" in _crash_log(cwd).read_text(encoding="utf-8") + + +def test_a_handler_on_a_named_logger_is_repointed(screen, monkeypatch): + """A ``StreamHandler`` binds ``sys.stderr`` at construction — on *any* logger. + + The repoint loop walked ``logging.getLogger().handlers``, root only, while + the record in the host's traceback comes from a **named** logger + (``websockets/protocol.py``: ``self.logger.debug("> %s", frame)``). A + handler on a named logger is the same defect one logger over, and the policy + is "whatever writes to the client's stderr". + """ + screen, cwd = screen + logger = logging.getLogger("websockets.client") + monkeypatch.setattr(logger, "handlers", []) + monkeypatch.setattr(logger, "level", logging.DEBUG) + + with _screen(screen): + handler = logging.StreamHandler() # binds the *object* sys.stderr (= screen) + logger.addHandler(handler) # a named logger, not root + + guard = client_app._contain_stderr_for_tui() + try: + logger.debug("> %s", "frame") + finally: + guard.restore() + + assert handler.stream is screen, "the terminal must be handed back" + + assert screen.getvalue() == "", "a named logger's record reached the screen" + # the handler *formats* the record; only ``handleError`` echoes the raw message + assert "> frame" in _crash_log(cwd).read_text(encoding="utf-8") + + +def test_containment_leaves_the_last_resort_handler_alone(screen, monkeypatch): + """``logging.lastResort`` cannot be repointed, and need not be. + + It is a ``_StderrHandler`` whose ``stream`` is a read-only property returning + the *current* ``sys.stderr``: it follows the swap by itself, and + ``handler.stream = sink`` raises ``AttributeError: property 'stream' of + '_StderrHandler' object has no setter``. It also sits in + ``logging._handlerList``, so a containment that widened by walking *that* + list would raise from inside itself — before ``sys.stderr`` is swapped — + and print the traceback on the screen, producing the symptom it removes. + """ + screen, cwd = screen + monkeypatch.setattr(logging.getLogger(), "handlers", []) # nothing but lastResort + + with _screen(screen): + guard = client_app._contain_stderr_for_tui() # must not raise + try: + logging.getLogger("emrg.client.probe").warning("last resort") + finally: + guard.restore() + + assert screen.getvalue() == "" + assert "last resort" in _crash_log(cwd).read_text(encoding="utf-8") + + +# ── the two states of the guard itself ──────────────────────────────────── + + +def test_a_user_redirected_stderr_is_left_alone(tmp_path, monkeypatch): + """``emrg 2>errors.txt`` asked for stderr there; no screen to corrupt.""" + sink = io.StringIO() # isatty() is False + monkeypatch.chdir(tmp_path) + + with _screen(sink): + guard = client_app._contain_stderr_for_tui() + try: + assert sys.stderr is sink + finally: + guard.restore() + + assert sys.stderr is sink + assert not _crash_log(tmp_path).exists() + + +def test_restore_puts_the_terminal_back(screen): + screen, _cwd = screen + + with _screen(screen): + guard = client_app._contain_stderr_for_tui() + assert sys.stderr is not screen + guard.restore() + assert sys.stderr is screen + guard.restore() # idempotent: a second call must not raise + assert sys.stderr is screen + + +def test_two_containments_hand_the_terminal_back_in_order(screen, monkeypatch): + """``restore()`` must undo exactly what it did, newest first.""" + screen, _cwd = screen + + with _screen(screen): + handler = logging.StreamHandler() + monkeypatch.setattr(logging.getLogger(), "handlers", [handler]) + + outer = client_app._contain_stderr_for_tui() + inner = client_app._contain_stderr_for_tui() + inner.restore() + assert sys.stderr is not screen, "the outer containment is still in force" + outer.restore() + assert sys.stderr is screen + assert handler.stream is screen, "the terminal must be handed back" + + +# ── end to end, at the call site the host's traceback named ─────────────── + + +def test_run_client_contains_the_whole_session(screen, monkeypatch): + """The containment covers everything, including the session body. + + ``run_client`` installs it before ``asyncio.run`` builds the event loop, so + a record emitted while the loop is being created is already contained — + nothing internal is left to a "before the TUI is up" window. + """ + screen, cwd = screen + seen: dict = {} + + async def _stub(init_auto_evolve=False, console=None): + seen["contained_at_entry"] = sys.stderr is not screen + seen["console_is_the_terminal"] = console is screen + # At session entry stderr is already the sink: loop creation, the + # session body and everything after it share the same containment. + seen["sink"] = getattr(sys.stderr, "name", None) + + monkeypatch.setattr(client_app, "interactive", _stub) + + with _screen(screen): + client_app.run_client() + + assert seen["contained_at_entry"] is True + assert seen["console_is_the_terminal"] is True + assert seen["sink"] == str(_crash_log(cwd)) + assert screen.getvalue() == "" + + +def test_a_connect_failure_still_reaches_the_terminal(screen, monkeypatch): + """The policy's other direction: a message the *user* needs is not contained. + + "Failed to connect to emrgd" is how the host learns the daemon is down; it + goes to the stream captured before the containment was installed. + """ + screen, _cwd = screen + monkeypatch.setattr(sys, "stdin", _FakeTtyStdin()) + + async def _refused(): + raise RuntimeError("connection refused") + + monkeypatch.setattr(client_app.daemon_manager, "ensure_connected", _refused) + + with _screen(screen): + client_app.run_client() + + assert "Failed to connect to emrgd: connection refused" in screen.getvalue() + + +def test_a_crash_never_reaches_the_screen( + tmp_path, monkeypatch, broken_rotating_handler): + """``app.py interactive → conn.send_command("ping")``, reproduced. + + A log record emitted from inside ``send_command`` goes through a broken + handler; the failure report must not reach the terminal — including when + the exception that follows escapes the session, which is the window in + which the host's screen got written to. + """ + screen = _FakeTerminal() + monkeypatch.chdir(tmp_path) + monkeypatch.setattr(logging, "raiseExceptions", True) + monkeypatch.setattr(sys, "stdin", _FakeTtyStdin()) + + class _Conn: + async def send_command(self, type_, **kw): + logging.getLogger("websockets.client").debug("> %s", "frame") + raise RuntimeError("daemon went away") + + async def _connected(): + return _Conn() + + monkeypatch.setattr(client_app.daemon_manager, "ensure_connected", _connected) + + root = logging.getLogger() + previous_level = root.level + root.setLevel(logging.DEBUG) # websockets' frame log is DEBUG + with _screen(screen): + try: + with pytest.raises(RuntimeError): + client_app.run_client() + # The session died with an exception, and the containment is still + # in force on purpose: that traceback is printed by the process + # entry point, after ``run_client`` returns — it belongs in the + # crash log, not on the screen. + assert sys.stderr is not screen + finally: + root.setLevel(previous_level) + + assert screen.getvalue() == "" + assert "--- Logging error ---" in _crash_log(tmp_path).read_text(encoding="utf-8")
- added a commit that references this issue
on Sep 15, 2026
The host's report (rant
2026-09-14T21:50:54)At ~21:24 an internal dump appeared on the screen of the running TUI:
with the requirement:
Root cause — three writers, one surface
In a TUI
sys.stderris the screen, and the client never claims it. There isno client-side counterpart of the daemon's
_redirect_std_streams(
emrg/server/__main__.py:93, which is why the daemon dies silently into~/.emrg/emrgd-crash.log). Three independent writers reach that surface:logging.Handler.handleError— the dump above._run_client(
emrg/__main__.py:369) installs aRotatingFileHandlerat DEBUG for./.emrg/emrg-client.log; when its ownemitraises (a rotated/closedstream →
shouldRollover→self.stream.tell()),handleErrorreports tosys.stderr. Not one cause: any handler whose emit raises does this, and sodoes any
print(..., file=sys.stderr)or asyncio default exception handler.StreamHandlerbuilt before the session — thepython -m emrg.clientpath calls
logging.basicConfig(level=INFO)with nostream=, so thehandler binds
sys.stderrat construction; swappingsys.stderralonewould leave that handler writing to the screen.
sys.stderrby the process entry point afterrun_client()returns, i.e.in exactly the window the host hit (
app.py:308 interactive → send_command("ping")).The fix
Fenced patch (applies to master's
emrg/client/app.py, which is identical tothis tree's
HEAD:addcb5eefor that file). It adds_StderrContainment+_contain_stderr_for_tui()and installs the containmentin
run_client():asyncio.runbuilds the eventloop, so loop-creation records are covered too — no "before the TUI is up"
window is left;
<cwd>/.emrg/emrg-client-crash.log, a file next to the structuredemrg-client.log, for the same reason the daemon keepsemrgd-crash.logapart from
emrgd.log(unstructured, multi-line, written by code that isalready failing);
session dies with an exception — that traceback belongs in the crash log;
This client requires a real terminal (TTY),Failed to connect to emrgd: …) go to aconsoleargument (the streamcaptured before installation), so containment cannot hide them;
sys.stderris a TTY (emrg 2>errors.txtis respected), andsys.stdoutis untouched (it is the surface the TUI renders through).Tests —
tests/test_client_stderr_containment.py(8, all passing)Policy-level, not one-cause-level: the broken-handler mechanism, the repointed
handler, the three states of the guard, the whole-session contract at the call
site, and a negative control (a connect failure must still reach the
terminal).
Full suite against the patched tree: 1976 passed, 7 skipped, 10 failed — all
10 failures are
git ls-filesexiting 128 because the verification copy has no.git; running those same 5 test files in the real checkout gives 128passed, 0 failed.
from emrg.client.app import run_clientimports andpython -m emrg --helpworks.Harness finding worth keeping (it nearly produced a green suite that proved
nothing): pytest re-installs its own
sys.stderrbetween the setup phase andthe call phase (
CaptureManager.item_capture→resume_global_capture→FDCapture.resume→setattr(sys, "stderr", tmpfile),_pytest/capture.py),so a
monkeypatch.setattr(sys, "stderr", …)applied inside a fixture isgone by the time the test body runs. The guard then saw pytest's non-TTY
capture object, decided "nothing to do", and every assertion passed for the
wrong reason. The screen is therefore installed in the test body —
tests/test_cli_output_encoding.py:120-143patches in the body too.Evidence on a real pty, with a positive control
Child process =
run_client()with the host's shape (a brokenRotatingFileHandler, a log record fromwebsockets, then an exceptionescaping the session), stderr on a real pty.
disabledis the same child with_contain_stderr_for_tuipatched to a no-op — the pre-fix behaviour, present toprove the instrument can see the phenomenon at all:
--- Logging error ---on screenRuntimeErrorin crash logcontaineddisabled(control)Reproduce
Process note
The evolution workspace is dirty (2 modified files whose blobs equal master's),
which downgrades the sandbox to
read-only: no branch, no commit, no push, noin-workspace write. The patch and its tests were therefore developed and
verified in an out-of-workspace copy of master and are reported here in full —
this is the artifact, not a summary. With a writable tree it becomes a normal
PR.
Full test file:
tests/test_client_stderr_containment.py