#9347 log method parens (#12040)

src/twisted/logger/_format.py

@@ -6,6 +6,8 @@
 Tools for formatting logging events.
 """
 
+from __future__ import annotations
+
 from datetime import datetime as DateTime
 from typing import Any, Callable, Iterator, Mapping, Optional, Union, cast
 
@@ -164,6 +166,51 @@ def formatEventAsClassicLogText(
     return eventText + "\n"
 
 
+def keycall(key: str, getter: Callable[[str], Any]) -> PotentialCallWrapper:
+    """
+    Check to see if C{key} ends with parentheses ("C{()}"); if not, wrap up the
+    result of C{get} in a L{PotentialCallWrapper}.  Otherwise, call the result
+    of C{get} first, before wrapping it up.
+
+    @param key: The last dotted segment of a formatting key, as parsed by
+        L{Formatter.vformat}, which may end in C{()}.
+
+    @param getter: A function which takes a string and returns some other
+        object, to be formatted and stringified for a log.
+
+    @return: A L{PotentialCallWrapper} that will wrap up the result to allow
+        for subsequent usages of parens to defer execution to log-format time.
+    """
+    callit = key.endswith("()")
+    realKey = key[:-2] if callit else key
+    value = getter(realKey)
+    if callit:
+        value = value()
+    return PotentialCallWrapper(value)
+
+
+class PotentialCallWrapper(object):
+    """
+    Object wrapper that wraps C{getattr()} so as to process call-parentheses
+    C{"()"} after a dotted attribute access.
+    """
+
+    def __init__(self, wrapped: object) -> None:
+        self._wrapped = wrapped
+
+    def __getattr__(self, name: str) -> object:
+        return keycall(name, self._wrapped.__getattribute__)
+
+    def __format__(self, format_spec: str) -> str:
+        return self._wrapped.__format__(format_spec)
+
+    def __repr__(self) -> str:
+        return self._wrapped.__repr__()
+
+    def __str__(self) -> str:
+        return self._wrapped.__str__()
+
+
 class CallMapping(Mapping[str, Any]):
     """
     Read-only mapping that turns a C{()}-suffix in key names into an invocation
@@ -190,12 +237,7 @@ def __getitem__(self, key: str) -> Any:
         Look up an item in the submapping for this L{CallMapping}, calling it
         if C{key} ends with C{"()"}.
         """
-        callit = key.endswith("()")
-        realKey = key[:-2] if callit else key
-        value = self._submapping[realKey]
-        if callit:
-            value = value()
-        return value
+        return keycall(key, self._submapping.__getitem__)
 
 
 def formatWithCall(formatString: str, mapping: Mapping[str, Any]) -> str:

src/twisted/logger/test/test_format.py

@@ -36,6 +36,17 @@ class FormattingTests(unittest.TestCase):
     Tests for basic event formatting functions.
     """
 
+    def format(self, logFormat: AnyStr, **event: object) -> str:
+        """
+        Create a Twisted log event dictionary from C{event} with the given
+        C{logFormat} format string, format it with L{formatEvent}, ensure that
+        its type is L{str}, and return its result.
+        """
+        event["log_format"] = logFormat
+        result = formatEvent(event)
+        self.assertIs(type(result), str)
+        return result
+
     def test_formatEvent(self) -> None:
         """
         L{formatEvent} will format an event according to several rules:
@@ -53,27 +64,36 @@ def test_formatEvent(self) -> None:
         L{formatEvent} will always return L{str}, and if given bytes, will
         always treat its format string as UTF-8 encoded.
         """
-
-        def format(logFormat: AnyStr, **event: object) -> str:
-            event["log_format"] = logFormat
-            result = formatEvent(event)
-            self.assertIs(type(result), str)
-            return result
-
-        self.assertEqual("", format(b""))
-        self.assertEqual("", format(""))
-        self.assertEqual("abc", format("{x}", x="abc"))
+        self.assertEqual("", self.format(b""))
+        self.assertEqual("", self.format(""))
+        self.assertEqual("abc", self.format("{x}", x="abc"))
         self.assertEqual(
             "no, yes.",
-            format("{not_called}, {called()}.", not_called="no", called=lambda: "yes"),
+            self.format(
+                "{not_called}, {called()}.", not_called="no", called=lambda: "yes"
+            ),
         )
-        self.assertEqual("S\xe1nchez", format(b"S\xc3\xa1nchez"))
-        self.assertIn("Unable to format event", format(b"S\xe1nchez"))
-        maybeResult = format(b"S{a!s}nchez", a=b"\xe1")
+        self.assertEqual("S\xe1nchez", self.format(b"S\xc3\xa1nchez"))
+        self.assertIn("Unable to format event", self.format(b"S\xe1nchez"))
+        maybeResult = self.format(b"S{a!s}nchez", a=b"\xe1")
         self.assertIn("Sb'\\xe1'nchez", maybeResult)
 
         xe1 = str(repr(b"\xe1"))
-        self.assertIn("S" + xe1 + "nchez", format(b"S{a!r}nchez", a=b"\xe1"))
+        self.assertIn("S" + xe1 + "nchez", self.format(b"S{a!r}nchez", a=b"\xe1"))
+
+    def test_formatMethod(self) -> None:
+        """
+        L{formatEvent} will format PEP 3101 keys containing C{.}s ending with
+        C{()} as methods.
+        """
+
+        class World:
+            def where(self) -> str:
+                return "world"
+
+        self.assertEqual(
+            "hello world", self.format("hello {what.where()}", what=World())
+        )
 
     def test_formatEventNoFormat(self) -> None:
         """

src/twisted/newsfragments/9347.bugfix

@@ -0,0 +1,4 @@
+twisted.logger.formatEvent now honors dotted method names, not just flat
+function names, in format strings, as it has long been explicitly documented to
+do.  So, you will now get the expected result from `formatEvent("here's the
+result of calling a method at log-format time: {obj.method()}", obj=...)`