diff --git a/changelog/805.bugfix.rst b/changelog/805.bugfix.rst new file mode 100644 index 00000000..123cef45 --- /dev/null +++ b/changelog/805.bugfix.rst @@ -0,0 +1 @@ +Hook tracing no longer turns a successful hook call into an error when a traced argument name or a trace channel contains a character that cannot be encoded, such as a lone surrogate, or a name whose ``str()`` raises; both are now rendered in the trace like the rest of the message instead of being raised out of the call (`#805 `_). diff --git a/src/pluggy/_tracing.py b/src/pluggy/_tracing.py index 03fafbce..e9653d10 100644 --- a/src/pluggy/_tracing.py +++ b/src/pluggy/_tracing.py @@ -101,17 +101,24 @@ def _format_message(self, tags: Sequence[str], args: Sequence[object]) -> str: content = " ".join(map(_safe_str, args)) indent = " " * self.indent - lines = [f"{indent}{content} [{':'.join(tags)}]\n"] + # The channel names come from the tracer's user, so they are rendered + # like any other text in the message. + channels = _safe_str(":".join(tags)) + + lines = [f"{indent}{content} [{channels}]\n"] for name, value in extra.items(): + # The key is text pluggy puts in the message itself: rendering it + # must not raise, nor leave a lone surrogate in the output. + key = _safe_str(name) rendered = _safe(_render_value, value, "format") # A bare \r is a line break too: inline, the terminal would # return to column 0 and overwrite the key. body = rendered.splitlines() if body in ([], [rendered]): - lines.append(f"{indent} {name}: {rendered}\n") + lines.append(f"{indent} {key}: {rendered}\n") else: - lines.append(f"{indent} {name}:\n") + lines.append(f"{indent} {key}:\n") lines.extend(_format_block(indent, body)) return "".join(lines) diff --git a/testing/test_tracer.py b/testing/test_tracer.py index b2553f13..a84a373d 100644 --- a/testing/test_tracer.py +++ b/testing/test_tracer.py @@ -324,6 +324,12 @@ def test_dictargs_escape_surrogate_values(rootlogger: TagTracer) -> None: out.encode() +def test_dictargs_escape_surrogate_keys(rootlogger: TagTracer) -> None: + out = rootlogger._format_message(["test"], ["test", {"\ud800": 1}]) + assert out == "test [test]\n \\ud800: 1\n" + out.encode() + + def test_escape_surrogates_from_repr(rootlogger: TagTracer) -> None: """A surrogate coming out of the object's own repr is escaped too.""" out = rootlogger._format_message(["test"], ["test", {"arg": SurrogateRepr()}]) @@ -337,6 +343,12 @@ def test_escape_surrogates_in_labels(rootlogger: TagTracer) -> None: out.encode() +def test_escape_surrogates_in_channels(rootlogger: TagTracer) -> None: + out = rootlogger._format_message(["\ud800"], ["test"]) + assert out == "test [\\ud800]\n" + out.encode() + + def test_non_ascii_values_are_kept(rootlogger: TagTracer) -> None: """Legible text is not mangled, only lone surrogates are escaped.""" out = rootlogger._format_message(["test"], ["héllo", {"arg": "wörld"}]) @@ -358,6 +370,13 @@ def test_broken_str_label_does_not_raise(rootlogger: TagTracer) -> None: out.encode() +def test_broken_str_key_does_not_raise(rootlogger: TagTracer) -> None: + out = rootlogger._format_message(["test"], ["test", {BrokenStr(): 1}]) + assert "RuntimeError('str is broken') raised in str()" in out + assert "BrokenStr object at 0x" in out + out.encode() + + def test_keyboard_interrupt_from_str_propagates(rootlogger: TagTracer) -> None: """Ctrl-C during a traced call still interrupts, it is not swallowed."""