Make hook tracing unable to fail a hook call - #728
Conversation
baac0d0 to
893c2ef
Compare
Trace output stays str() based, because that is what makes it readable, but str() hides things a reader needs often enough to be worth fixing case by case: - an empty string is indistinguishable from no value at all, which is exactly wrong for a comparison trace showing left and right - a string carrying whitespace has no visible boundaries - an IntEnum prints as a bare number, losing the member name - a path prints as text, so a PosixPath and a py.path.local argument pointing at the same place look identical - a multi line value runs into column 0 and reads as a trace line of its own rather than as the value of its key So values that read unambiguously as themselves -- a non empty printable string without spaces, and every type whose repr adds nothing -- stay bare, and the rest gain quotes, their type, or a block. Multi line values are drawn as a box, each line prefixed with | and the last with \\, so the extent of the value is visible at a glance. Measured on a real pytest --debug run, this changes 45 of 1329 trace lines, against 216 for rendering every value with repr(). Every changed line carries information the previous rendering dropped. Builds on pytest-dev#728, which must land first. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
Trace output stays str() based, because that is what makes it readable, but str() hides things a reader needs often enough to be worth fixing case by case: - an empty string is indistinguishable from no value at all, which is exactly wrong for a comparison trace showing left and right - a string carrying whitespace has no visible boundaries - an IntEnum prints as a bare number, losing the member name - a path prints as text, so a PosixPath and a py.path.local argument pointing at the same place look identical - a multi line value runs into column 0 and reads as a trace line of its own rather than as the value of its key So values that read unambiguously as themselves -- a non empty printable string without spaces, and every type whose repr adds nothing -- stay bare, and the rest gain quotes, their type, or a block. Multi line values are drawn as a box, each line prefixed with | and the last with \\, so the extent of the value is visible at a glance. Measured on a real pytest --debug run, this changes 45 of 1329 trace lines, against 216 for rendering every value with repr(). Every changed line carries information the previous rendering dropped. Builds on pytest-dev#728, which must land first. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
dbf76de to
b7910c1
Compare
Trace output stays str() based, because that is what makes it readable, but str() hides things a reader needs often enough to be worth fixing case by case: - an empty string is indistinguishable from no value at all, which is exactly wrong for a comparison trace showing left and right - a string carrying whitespace has no visible boundaries - an IntEnum prints as a bare number, losing the member name - a path prints as text, so a PosixPath and a py.path.local argument pointing at the same place look identical - a multi line value runs into column 0 and reads as a trace line of its own rather than as the value of its key So values that read unambiguously as themselves -- a non empty printable string without spaces, and every type whose repr adds nothing -- stay bare, and the rest gain quotes, their type, or a block. Multi line values are drawn as a box, each line prefixed with | and the last with \\, so the extent of the value is visible at a glance. Measured on a real pytest --debug run, this changes 45 of 1329 trace lines, against 216 for rendering every value with repr(). Every changed line carries information the previous rendering dropped. Builds on pytest-dev#728, which must land first. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
Trace output stays str() based, because that is what makes it readable, but str() hides things a reader needs often enough to be worth fixing case by case: - an empty string is indistinguishable from no value at all, which is exactly wrong for a comparison trace showing left and right - a string carrying whitespace has no visible boundaries - an IntEnum prints as a bare number, losing the member name - a path prints as text, so a PosixPath and a py.path.local argument pointing at the same place look identical - a multi line value runs into column 0 and reads as a trace line of its own rather than as the value of its key So values that read unambiguously as themselves -- a non empty printable string without spaces, and every type whose repr adds nothing -- stay bare, and the rest gain quotes, their type, or a block. Multi line values are drawn as a box, each line prefixed with | and the last with \\, so the extent of the value is visible at a glance. Measured on a real pytest --debug run, this changes 45 of 1329 trace lines, against 216 for rendering every value with repr(). Every changed line carries information the previous rendering dropped. Builds on pytest-dev#728, which must land first. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
b7910c1 to
b4a9676
Compare
bluetech
left a comment
There was a problem hiding this comment.
Thanks, LGTM with some comments.
| except (KeyboardInterrupt, SystemExit): | ||
| raise | ||
| except BaseException: | ||
| return f'{type(obj).__name__}("{obj}")' |
There was a problem hiding this comment.
Does _format_str_exception catch exception because the "{obj}" can fail?
There was a problem hiding this comment.
people do fun stuff with outcome exceptions
There was a problem hiding this comment.
Written by Claude Opus 5.5 via Claude Code for the pluggy reviewers; I prompted it, it did the work, I read it.
Yes. _try_repr_or_str falls back to str(exc) through the f-string, and that can raise too. There is now a one-line comment saying so.
There was a problem hiding this comment.
Seems to me that the f'{type(obj).__name__}("{obj}")' part is a bit too much. A __repr__ raising is already and edge case, and we then add a fallback to __str__ and then another edge-case of it failing.
Seems to me we can just try the repr and if it fails go directly to raised in repr message.
b4a9676 to
0e935d9
Compare
Tracing could turn a working hook call into a failing one in two ways: an object whose __repr__/__str__ raises propagated that exception out of the hook call (pytest-dev#424), and a lone surrogate in a hook argument or return value produced a message the writer could not encode (pytest-dev#681). Both are now handled in one place. _safe_repr()/_safe_str() catch Exception from the conversion and render an unpresentable-object marker in the shape of pytest's saferepr, naming the exception, or only its type when the exception's own repr fails too, so no user code runs in the last fallback. Anything outside Exception -- KeyboardInterrupt, SystemExit, pytest's outcome exceptions -- propagates: a __str__ or __repr__ that raises one of those is a bug in that object, not something tracing should hide. Lone surrogates are escaped with backslashreplace afterwards, which also covers surrogates that come out of an object's own __repr__. Traced values -- hook kwargs and the hook result -- now use repr() so their type is visible in the log; structural labels such as the hook name and the finish/--> markers keep using str() and stay unquoted. Supersedes pytest-dev#627, pytest-dev#666, pytest-dev#684 and pytest-dev#716. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
The previous commit also switched traced values from str() to repr(), following the design distilled in pytest-dev#681. That is a user visible change to pytest's --debug output, and it makes that output worse to read. The worst case is a value that is meant to be read as a block. With enable_assertion_pass_hook, pytest passes the assertion explanation to pytest_assertion_pass as a multi line string. Under str() the trace shows it as written: expl: {'x': [0, 1, ...} == {'x': [0, 1, ...} Omitting 2 identical items, use -vv to show Use -v to get more diff Under repr() the same value becomes one escaped line: expl: "{'x': [0, 1, ...} == {'x': [0, 1, ...}\n \n Omitting 2 identical items, use -vv to show\n Use -v to get more diff" The rest is quieter but hits every run: of 439 traced kwarg values in a real pytest --debug run, 123 render differently, and 115 of those are nothing but quotes added around strings that were already readable -- every plugin registration line turns plugin_name: lfplugin into a quoted string. 105 of the 674 lines in the sampled trace change, so anything parsing that output breaks as well. The trace is pytest UX. A fix for a crash that nobody hits in normal use must not degrade the daily reading experience of everyone who does not hit it. The cases where repr() genuinely helps are real -- PosixPath vs py.path.local for two arguments that print the same path, ExitCode vs a bare int -- but they are 15 lines out of 674, and they do not pay for the other 115 plus the escaped blocks. The crash fixes never depended on repr(): _safe_str() guards the conversion and escapes lone surrogates just as well, so pytest-dev#424 and pytest-dev#681 stay fixed while pytest --debug output is byte for byte what it was before (verified: 674 trace lines, 0 differences). The type visibility idea is not rejected, only unbundled -- it can be argued on its own in Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
0e935d9 to
124b441
Compare
The guards around str() were only exercised for the simple case of a broken __str__. The exception explaining that failure can be just as broken, and Ctrl-C has to stay reliable at both levels, so cover: an exception whose repr fails, which falls back to its type name; an exception whose repr raises an exception that is itself unpresentable, which must not be rendered at all; and KeyboardInterrupt raised from the value and from the explanation. _tracing.py is at 100% statement and branch coverage. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
BrokenStr's __repr__ was never called -- _safe_str reaches for __str__, and the failure message is built from the type name -- so it only showed up as an uncovered line. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Co-Authored-By: Claude Code <noreply@anthropic.com>
124b441 to
c5e0e4a
Compare
|
@RonnyPfannschmidt did you see my two remaining comments? I can send a PR for it if you'd like. |
|
Yes resolved |
|
Oops, didn't notice. Thanks |
Closes #424. Closes #681. Supersedes #627, #666, #684, #716.
The two bugs
Tracing can turn a working hook call into a failing one:
__repr__/__str__raises propagates that exceptionout of the hook call (originally kedro-org/kedro#2630).
the writer cannot encode (originally pytest-dev/pytest#13750).
Against
main, with a writer that encodes to utf-8 the way pytest's--debugfile does:With this branch, both print
OK.The change
One helper in
_tracing.py, in the shape of pytest'ssaferepr(as #424 asked for),applied to both the positional labels and the keyword values:
_safe_str()—KeyboardInterruptandSystemExitstill propagate, anything elserenders as
<[RuntimeError('str is broken') raised in str()] BrokenStr object at 0x...>.BaseExceptionrather thanException, because pytest'sOutcomeException— and sopytest.fail()/skip()— sits outside theExceptionhierarchy, and a__repr__that fails a test while
--debugis on is exactly the reported scenario._escape_surrogates()afterwards —backslashreplace, which also covers surrogatesthat come out of an object's own
__repr__, a caserepr()alone does not fix. Itshort-circuits on ASCII text, which is nearly all of it.
pytest --debugoutput is unchanged: 674 trace lines on a sample run, byte for byteidentical to
mainonce addresses are normalised. Nothing is added, nothing is quoted,nothing is reformatted — the only difference is that the two inputs above no longer raise.
Why the trace output is left alone, despite #681
#681 and #627 also called for rendering traced values with
repr()so their type isvisible (
plugin_name: 'lfplugin',start_path: PosixPath('/x')). The first commit hereimplements that; the second backs it out. Both are kept so the decision is reviewable.
The reason is that the trace is pytest UX.
--debugoutput is read by a humanscanning for the hook that misbehaved, and a fix for a crash nobody hits in normal use
should not make that scan worse for everyone who does. I am not willing to take that
trade in pluggy — the fix has to be invisible to people who were not hitting the bug.
The worst case is a value meant to be read as a block. With
enable_assertion_pass_hook,pytest passes the assertion explanation to
pytest_assertion_passas a multi-line string.Under
str()the trace shows it as written:Under
repr()the same value becomes one escaped line:The measurement that settles it, taken on a real
pytest --debugrun — 439 traced kwargvalues, of which 123 render differently under
repr():lfplugin→'lfplugin')/tmp/x→PosixPath('/tmp/x')/local('/tmp/x'))1→<ExitCode.TESTS_FAILED: 1>)94% of the delta is quote noise on strings that were already readable. The genuine wins
are real —
pathandcollection_pathprinting the same text while being apy.path.localand aPosixPathis exactly the confusion a trace should resolve — butthey are 15 lines out of 674, and they are not worth the other 115.
None of that blocks the bug fixes: they never depended on
repr(). The guard and thesurrogate escaping live in
_safe_str, so #424 and #681 close either way. Surrogatesrender as
arg: \ud800rather thanarg: '\ud800'; both are legible, neither raises.So the type-visibility idea is not rejected, only unbundled. If it is still wanted it can
be argued on its own merits in #681 — as a deliberate output change, with its own
changelog entry and its own discussion about what pytest's debug log should look like —
rather than riding along with a crash fix that has to ship regardless.
The one thing
repr()would buy on such a value is keeping the log's one-line-per-valuestructure intact for a machine reading it. That is a parsing concern, and it does not
outweigh making the block unreadable for the person the log is written for.
Relation to the existing PRs
Each approach against the same matrix (all cells measured, not assumed):
main__repr__returns a surrogate__repr__pm.trace()callerpytest --debugoutput unchangedBaseExceptionrather thanException,and pytest's message format rather than a bespoke one. Its test is carried over. Thanks
@ShipItAndPray.
what keeps downstream
pm.trace()callers (pytest calls it directly) safe — and whatmakes the
_manager.pychange in Escape surrogate values in tracing output #684 unnecessary. Thanks @ltsyk.are carried over; its
repr()change is the part discussed above. Thanks @Himanshuagrawal4.Testing
uv run pytest— 180 passed.uv run pre-commit run -a— all hooks pass._tracing.pyat 100% statement and branch coverage.main, 2 pin the existing str rendering and the already-correcthandling of legible non-ASCII, and 4 cover the guards themselves — an exception whose
own repr fails, one whose repr and str both fail, and
KeyboardInterruptraised fromthe value and from the explanation.
pytest --debugoutput diffed againstmain: 0 differences.🤖 Generated with Claude Code