diff --git a/tests/test_update_shape_messages.py b/tests/test_update_shape_messages.py index 9ee6606a..bde2077d 100644 --- a/tests/test_update_shape_messages.py +++ b/tests/test_update_shape_messages.py @@ -24,6 +24,7 @@ from __future__ import annotations import importlib.util +import io import re import shlex import shutil @@ -449,6 +450,46 @@ def test_the_bare_form_a_failed_push_prints_carries_the_words_too( assert LOCAL in body +class ClosedPipe(io.StringIO): + """A stdout whose reader has gone away, as under `... | true`: it takes + what is printed, and its flush raises, as the one + `tests/test_adopt_late_failure.py` gives `adopt-project.py`.""" + + def flush(self) -> None: + raise BrokenPipeError(32, "Broken pipe") + + +def test_a_refused_push_is_reported_on_stderr_whatever_stdout_is( + update_shape, repository, tmp_path, monkeypatch): + """A PUSH ORIGIN REFUSES, after the commit, and nobody reads stdout any + more (#1218). `landing_failed` flushed stdout bare before it said + anything, so the flush's `BrokenPipeError` went over its whole report: + stderr said neither which step failed nor that the commit stands. Both + reach stderr, and the run ends as a landing that is not complete. The + NEXT line is stdout's, handed to stdout whatever it does with it.""" + git("checkout", "-q", "-b", "shape/x", cwd=repository) + git("remote", "add", "origin", str(tmp_path / "no-such-remote.git"), + cwd=repository) + head = git("rev-parse", "HEAD", cwd=repository).stdout.strip() + stdout, stderr = ClosedPipe(), io.StringIO() + monkeypatch.setattr(sys, "stdout", stdout) + monkeypatch.setattr(sys, "stderr", stderr) + args = SimpleNamespace(branch="shape/x", push=True, pr=False) + + with pytest.raises(update_shape.LandingIncomplete): + update_shape.push_branch(repository, args, ["gh", "pr", "create"]) + + said = stderr.getvalue() + assert said.startswith( + "REFUSED pushing shape/x. THE EXACT COMMAND WAS:\n" + " git push -q -u -- origin refs/heads/shape/x:refs/heads/shape/x" + "\n"), said + assert (f"shape/x carries the re-pin at {head[:12]}, and origin does not " + "have it yet: that commit stands and nothing was rolled back." + ) in said, said + assert stdout.getvalue().startswith("\nNEXT git -C "), stdout.getvalue() + + # --- the words are true in every state (review of PR #558) ------------------- diff --git a/tests/test_update_shape_unreadable.py b/tests/test_update_shape_unreadable.py index c8282562..2c6fefde 100644 --- a/tests/test_update_shape_unreadable.py +++ b/tests/test_update_shape_unreadable.py @@ -663,13 +663,17 @@ def refusing(where, _kind): id="EIO-naming-no-path"), ] -#: What stderr says first when every byte `apply --at B` wrote went back: -#: the copy, then the pin and the manifest, in the order they were written. -ROLLED_BACK = ( - "ROLLED BACK: every byte this command wrote has been put back, and the " - "tree is exactly as it was:\n" - + "".join(f" restored {path}\n" - for path in (CHANGED, PIN, "project.yaml"))) +def rolled_back(*paths: str) -> str: + """What stderr says first when every byte `apply --at B` wrote went + back: each of `paths` restored, in the order they were written.""" + return ("ROLLED BACK: every byte this command wrote has been put back, " + "and the tree is exactly as it was:\n" + + "".join(f" restored {path}\n" for path in paths)) + + +#: ... once all of them were written: the copy, then the pin and the +#: manifest. +ROLLED_BACK = rolled_back(CHANGED, PIN, "project.yaml") @pytest.mark.parametrize("error", UNNAMED) @@ -697,35 +701,90 @@ def failing(where, _kind): assert_same_tree(before, snapshot(root, {})) -def test_a_stdout_nobody_reads_is_rolled_back_under_its_broken_pipe( - root, upstream_and_project): - """THE TOOL AS A PERSON RUNS IT, no stand-in (#1173): its stdout a pipe - whose reader is gone, as `apply --yes | head -1` leaves it once `head` - has its line. The flush before the root's validators raised over the - written tree. It still raises, over a tree as it was, and what went - back reaches stderr, above the traceback, though stdout will not take - the flush that comes first. `PYTHONUNBUFFERED` is blanked so stdout is - block-buffered whoever runs the test: unbuffered, the `copied` print - breaks the pipe first, and the refusal for it answers instead.""" - before = snapshot(root, {}) +def apply_b_into_a_closed_pipe(root: Path, project: dict, *, + unbuffered: bool + ) -> subprocess.CompletedProcess: + """THE TOOL AS A PERSON RUNS IT, no stand-in: `apply --at B --yes`, its + stdout a pipe whose reader is gone, as `apply --yes | head -1` leaves it + once `head` has its line, and its stderr read. `PYTHONUNBUFFERED` is set + or blanked, so stdout is unbuffered or block-buffered as the row says, + whoever runs the test.""" reader, writer = os.pipe() os.close(reader) try: - proc = subprocess.run( + return subprocess.run( [sys.executable, str(UPDATE), "apply", "--root", str(root), - "--yes", "--upstream", str(upstream_and_project["upstream"]), - "--at", upstream_and_project["b"]], + "--yes", "--upstream", str(project["upstream"]), + "--at", project["b"]], stdin=subprocess.DEVNULL, stdout=writer, stderr=subprocess.PIPE, text=True, check=False, - env={**os.environ, "LANES_LANE": "", "PYTHONUNBUFFERED": ""}) + env={**os.environ, "LANES_LANE": "", + "PYTHONUNBUFFERED": "1" if unbuffered else ""}) finally: os.close(writer) + + +def test_a_stdout_nobody_reads_is_rolled_back_under_its_broken_pipe( + root, upstream_and_project): + """A stdout nobody reads (#1173). The flush before the root's + validators raised over the written tree. It still raises, over a tree + as it was, and what went back reaches stderr, above the traceback, + though stdout will not take the flush that comes first. Block-buffered: + unbuffered, the `copied` print breaks the pipe first, which is + `test_a_broken_pipe_at_a_copied_line_is_not_a_failed_write`'s case.""" + before = snapshot(root, {}) + proc = apply_b_into_a_closed_pipe(root, upstream_and_project, + unbuffered=False) assert proc.returncode != 0, proc.stderr assert proc.stderr.startswith( ROLLED_BACK + "Traceback (most recent call last):\n"), proc.stderr assert_same_tree(before, snapshot(root, {})) +@needs_a_mode +def test_a_refusal_after_the_writes_reaches_stderr_when_stdout_is_unread( + root, upstream_and_project): + """A REFUSAL OVER A STDOUT NOBODY READS (#1218). A pin this user cannot + write is `update-write-failed` once the copy is written, and the + rollback flushed stdout before it said so. Into a pipe whose reader had + gone, that flush raised over the tree it had just put back: exit 120, + a traceback, and neither the REFUSED line nor the ROLLED BACK list on + stderr. The flush is let go, and stderr says both. The bytes stdout + never took are the interpreter's to report at exit, which it does.""" + (root / PIN).chmod(0o444) + before = snapshot(root, {}) + proc = apply_b_into_a_closed_pipe(root, upstream_and_project, + unbuffered=False) + assert proc.returncode != 0, proc.stderr + assert proc.stderr.startswith( + "REFUSED update-write-failed: re-pinning contracts/shape-pin.yaml " + f"and project.yaml failed at {PIN}: {DENIED}\n" + + rolled_back(CHANGED)), proc.stderr + assert_same_tree(before, snapshot(root, {})) + + +def test_a_broken_pipe_at_a_copied_line_is_not_a_failed_write( + root, upstream_and_project): + """UNBUFFERED, THE `copied` PRINT BREAKS THE PIPE (#1218), inside + `Rollback.writing`, which refused it as `update-write-failed: writing + the copies and the --add files failed: Broken pipe`, blaming the write + of a copy for an error of stdout's. It is raised as itself, through the + arm for an `OSError` no refusal can name (#1173): the one copy written + goes back, stderr says so above the traceback, and the traceback is the + broken pipe's.""" + before = snapshot(root, {}) + proc = apply_b_into_a_closed_pipe(root, upstream_and_project, + unbuffered=True) + assert proc.returncode != 0, proc.stderr + assert "update-write-failed" not in proc.stderr, proc.stderr + assert proc.stderr.startswith( + rolled_back(CHANGED) + "Traceback (most recent call last):\n"), \ + proc.stderr + assert proc.stderr.endswith( + "BrokenPipeError: [Errno 32] Broken pipe\n"), proc.stderr + assert_same_tree(before, snapshot(root, {})) + + def test_an_oserror_before_the_first_write_is_raised_and_says_nothing( update_shape, root, upstream_and_project, capsys, monkeypatch): """The other side: before the first write there is nothing to put diff --git a/update-shape.py b/update-shape.py index f78c242b..22c7c2b9 100755 --- a/update-shape.py +++ b/update-shape.py @@ -3223,12 +3223,24 @@ def writing(self, step: str) -> Iterator[None]: every byte back, and lists what it put back under this detail (`_rolled_back`), so the detail does not claim it as well. + A BROKEN PIPE IS STDOUT'S, NOT A WRITE'S (#1218). `_write_copies` + prints each `copied` line inside this block, and unbuffered + (`PYTHONUNBUFFERED`) into a pipe whose reader has gone, that print + raises `BrokenPipeError`. It was refused here as `update-write-failed: + writing the copies and the --add files failed: Broken pipe`, blaming + the write of a copy for an error of stdout's. Every write in this + block is to a file of the root's, never to a pipe, so the error is + let through as itself, to `cmd_apply`'s arm for an `OSError` no + refusal can name, which puts every byte back and raises it (#1173). + `step` is the refusal's own, not `self.step`, which names the git act a `CommandFailed` is reported under. """ try: yield except OSError as exc: + if isinstance(exc, BrokenPipeError): + raise name = exc.filename at = (f" at {self._name(Path(os.fsdecode(name)))}" if isinstance(name, (str, bytes, os.PathLike)) else "") @@ -5397,6 +5409,30 @@ def cmd_apply(args) -> int: upstream.close() +def _flush_stdout() -> None: + """Flush stdout before a failure is written to stderr, and let a flush + that fails go (#1218). + + THE FLUSH KEEPS A MERGED LOG IN ORDER. Piped, stdout is block-buffered + and stderr is not, so without it a log that merges the two (`> log + 2>&1`) shows the refusal above the `copied` and `committed` lines it is + about. + + A STDOUT NOBODY READS MUST NOT COST THE REPORT. Into a pipe whose reader + has gone, as `apply --yes | head -1` leaves it once `head` has its line, + the flush raises `BrokenPipeError`. Raised bare in `_rolled_back` it + went over the REFUSED line and the ROLLED BACK list, and in + `landing_failed` over the step that failed and the sentence that the + commit stands: the tree was put back, or the commit kept, and stderr + said neither. The error is let go, because the report on stderr is what + the person needs. The bytes stay buffered, and the interpreter tries + them once more at exit and says so itself, with its exit 120. + `adopt-project.py`'s `_flush_stdout` is the same guard, for the same + reason (#171).""" + with contextlib.suppress(OSError): + sys.stdout.flush() + + def _rolled_back(exc: Exception, ledger: Rollback) -> int: """`apply`'s one failure arm: undo what `ledger` holds, then refuse, saying which step failed and what was put back (#202). @@ -5418,8 +5454,9 @@ def _rolled_back(exc: Exception, ledger: Rollback) -> int: if undone is not None: # The `copied` / `re-pinned` lines first, then the refusal: a log that # merged the two streams would otherwise show the rollback before the - # writes it rolled back. - sys.stdout.flush() + # writes it rolled back. A stdout nobody reads takes nothing, and the + # refusal still reaches stderr (`_flush_stdout`, #1218). + _flush_stdout() if isinstance(exc, Refusal): if undone is None: raise exc @@ -5452,13 +5489,13 @@ def _roll_back_before_raising(ledger: Rollback) -> None: as it always was. STDOUT IS FLUSHED FIRST, for `_rolled_back`'s reason, and a flush that - fails is let go: the error this answers may be stdout's own, a pipe - nobody reads, and what was put back must still reach stderr.""" + fails is let go (`_flush_stdout`): the error this answers may be + stdout's own, a pipe nobody reads, and what was put back must still + reach stderr.""" undone = ledger.undo() if undone is None: return - with contextlib.suppress(OSError): - sys.stdout.flush() + _flush_stdout() print(undone, file=sys.stderr) @@ -5499,7 +5536,10 @@ def landing_failed(root: Path, args, exc: CommandFailed, act: str, branch origin lacks. STDOUT IS FLUSHED FIRST, so a combined log reads in the order things - happened: the commit and the push above the refusal, not below it. + happened: the commit and the push above the refusal, not below it. A + flush into a pipe nobody reads is let go (`_flush_stdout`, #1218), so + the step that failed and the commit that stands still reach stderr; the + NEXT line is stdout's, and goes wherever stdout goes. """ branch = args.branch head = (_git_answer(root, ["rev-parse", "HEAD"]) or "").strip() @@ -5507,7 +5547,7 @@ def landing_failed(root: Path, args, exc: CommandFailed, act: str, "--points-at", "HEAD", "refs/remotes/origin/"]) or "").splitlines() pushed = bool(head) and f"refs/remotes/origin/{branch}" in at_head - sys.stdout.flush() + _flush_stdout() print(exc.loudly(act), file=sys.stderr) left = ("its pull request: the NEXT line opens it" if pushed else "the push and the pull request: the NEXT line makes both")