Escape and guard traced dictionary keys and channel names

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 <https://github.com/pytest-dev/pluggy/pull/805>`_).

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)

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."""