Fix hynek#19 Pass positional arguments down to stdlib

docs/changelog.rst

@@ -8,6 +8,7 @@ Changelog
 - :release:`0.4.2 <2014-07-26>`
 - :bug:`8` Fixed a memory leak in greenlet code that emulates thread locals.
   It shouldn't matter in practice unless you use multiple wrapped dicts within one program that is rather unlikely.
+- :bug:`19` Pass positional arguments to stdlib wrapped loggers that use string formatting.
 - :feature:`-` :class:`structlog.PrintLogger` now is thread-safe.
 - :feature:`-` Test Twisted-related code on Python 3 (with some caveats).
 - :feature:`-` Drop support for Python 3.2.

structlog/_base.py

@@ -156,7 +156,8 @@ def _process_event(self, method_name, event, event_kw):
                 "string."
             )
 
-    def _proxy_to_logger(self, method_name, event=None, **event_kw):
+    def _proxy_to_logger(self, method_name, event=None, *event_args,
+                         **event_kw):
         """
         Run processor chain on event & call *method_name* on wrapped logger.
 
@@ -181,6 +182,7 @@ def _proxy_to_logger(self, method_name, event=None, **event_kw):
         """
         try:
             args, kw = self._process_event(method_name, event, event_kw)
+            args = args[:] + event_args
             return getattr(self._logger, method_name)(*args, **kw)
         except DropEvent:
             return

structlog/processors.py

@@ -305,3 +305,30 @@ def __call__(self, logger, name, event_dict):
                 _find_first_app_frame_and_name()[0]
             )
         return event_dict
+
+
+class StdlibFormatEventRenderer(object):
+    """
+    Applies stdlib-like string formatting to the `event` key with the arguments
+    in the `positional_args` key. This is populated by
+    `structlog.stdlib.BoundLogger` or can be manually set.
+
+    `positional_args` can be any iterable, but a dictionary as the single
+    element of the tuple is used instead of the tuple, to mantain compatibility
+    with the undocumented feature of stdlib logging.
+
+    """
+    def __init__(self, strip_positional_args=False):
+        self.strip_positional_args = strip_positional_args
+        super(StdlibFormatEventRenderer, self).__init__()
+
+    def __call__(self, _, __, event_dict):
+        args = event_dict.get('positional_args')
+        if args:
+            args = tuple(args)
+            if len(args) == 1 and isinstance(args[0], dict) and args[0]:
+                args = args[0]
+            event_dict['event'] = event_dict['event'] % args
+            if self.strip_positional_args:
+                event_dict.pop('positional_args')
+        return event_dict

structlog/stdlib.py

@@ -62,37 +62,48 @@ class BoundLogger(BoundLoggerBase):
         )
 
     """
-    def debug(self, event=None, **kw):
+    def __getattr__(self, item):
+        return getattr(self._logger, item)
+
+    def debug(self, event=None, *args, **kw):
         """
         Process event and call ``Logger.debug()`` with the result.
         """
-        return self._proxy_to_logger('debug', event, **kw)
+        return self._proxy_to_logger('debug', event, *args, **kw)
 
-    def info(self, event=None, **kw):
+    def info(self, event=None, *args, **kw):
         """
         Process event and call ``Logger.info()`` with the result.
         """
-        return self._proxy_to_logger('info', event, **kw)
+        return self._proxy_to_logger('info', event, *args, **kw)
 
-    def warning(self, event=None, **kw):
+    def warning(self, event=None, *args, **kw):
         """
         Process event and call ``Logger.warning()`` with the result.
         """
-        return self._proxy_to_logger('warning', event, **kw)
+        return self._proxy_to_logger('warning', event, *args, **kw)
 
     warn = warning
 
-    def error(self, event=None, **kw):
+    def error(self, event=None, *args, **kw):
         """
         Process event and call ``Logger.error()`` with the result.
         """
-        return self._proxy_to_logger('error', event, **kw)
+        return self._proxy_to_logger('error', event, *args, **kw)
 
-    def critical(self, event=None, **kw):
+    def critical(self, event=None, *args, **kw):
         """
         Process event and call ``Logger.critical()`` with the result.
         """
-        return self._proxy_to_logger('critical', event, **kw)
+        return self._proxy_to_logger('critical', event, *args, **kw)
+
+    def _proxy_to_logger(self, method_name, event=None, *event_args,
+                         **event_kw):
+        if event_args:
+            event_kw['positional_args'] = event_args
+        return super(BoundLogger, self)._proxy_to_logger(method_name, event,
+                                                         *event_args,
+                                                         **event_kw)
 
     def exception(self, event=None, **kw):
         """

tests/test_processors.py

@@ -32,7 +32,7 @@
     UnicodeEncoder,
     _JSONFallbackEncoder,
     format_exc_info,
-)
+    StdlibFormatEventRenderer)
 from structlog.threadlocal import wrap_dict
 
 
@@ -266,3 +266,25 @@ def test_adds_stack_if_asked(self, sir):
     def test_renders_correct_stack(self, sir):
         ed = sir(None, None, {'stack_info': True})
         assert "ed = sir(None, None, {'stack_info': True})" in ed['stack']
+
+
+class TestStringFormatting(object):
+    def test_formats_tuple(self):
+        renderer = StdlibFormatEventRenderer()
+        event_dict = renderer(None, None, {'event': '%d %d %s',
+                                           'positional_args': [1, 2, 'test']})
+        assert event_dict['event'] == '1 2 test'
+
+    def test_formats_dict(self):
+        renderer = StdlibFormatEventRenderer()
+        event_dict = renderer(None, None, {'event': '%(foo)s bar',
+                                           'positional_args': (
+                                               {'foo': 'bar'},)})
+        assert event_dict['event'] == 'bar bar'
+
+    def test_pops_positional_args(self):
+        renderer = StdlibFormatEventRenderer(strip_positional_args=True)
+        event_dict = renderer(None, None, {'event': '%d %d %s',
+                                           'positional_args': [1, 2, 'test']})
+        assert event_dict['event'] == '1 2 test'
+        assert 'positional_args' not in event_dict