Merge pull request #19 from wimglenn/issue18

v0.5

.github/workflows/tests.yml

@@ -0,0 +1,30 @@
+name: tests
+
+on:
+  push:
+    branches: ["master"]
+  pull_request:
+    branches: ["master"]
+  workflow_dispatch:
+
+jobs:
+  tests:
+    name: "Python ${{ matrix.python-version }}"
+    runs-on: "ubuntu-latest"
+
+    strategy:
+      matrix:
+        python-version: ["2.7", "3.9"]
+
+    steps:
+      - uses: "actions/checkout@v2"
+      - uses: "actions/setup-python@v2"
+        with:
+          python-version: "${{ matrix.python-version }}"
+      - name: "Install"
+        run: |
+          set -xe
+          python -VV
+          python -m pip install --editable .
+      - name: "Run tests for ${{ matrix.python-version }}"
+        run: python -m pytest

README.rst

@@ -1,7 +1,7 @@
-|travis|_ |pypi|_ |pyversions|_ |womm|_
+|actions|_ |pypi|_ |pyversions|_ |womm|_
 
-.. |travis| image:: https://travis-ci.com/wimglenn/pytest-structlog.svg?branch=master
-.. _travis: https://travis-ci.com/wimglenn/pytest-structlog
+.. |actions| image:: https://github.com/wimglenn/pytest-structlog/actions/workflows/tests.yml/badge.svg
+.. _actions: https://github.com/wimglenn/pytest-structlog/actions/workflows/tests.yml/
 
 .. |pypi| image:: https://img.shields.io/pypi/v/pytest-structlog.svg
 .. _pypi: https://pypi.org/project/pytest-structlog

pytest_structlog.py

@@ -3,7 +3,7 @@
 import structlog
 
 
-__version__ = "0.4"
+__version__ = "0.5"
 
 
 class EventList(list):
@@ -69,19 +69,28 @@ def log(monkeypatch, request):
     Example usage: ``assert log.has("some message", var1="extra context")``
     """
     # save settings for later
-    processors = structlog.get_config().get("processors", [])
-    configure = structlog.configure
+    original_processors = structlog.get_config().get("processors", [])
 
     # redirect logging to log capture
     cap = StructuredLogCapture()
-    structlog.configure(processors=[cap.process], cache_logger_on_first_use=False)
+    for processor in original_processors:
+        if isinstance(processor, structlog.stdlib.PositionalArgumentsFormatter):
+            # if there was a positional argument formatter in there, keep it there
+            # see https://github.com/wimglenn/pytest-structlog/issues/18
+            new_processors = [processor, cap.process]
+            break
+    else:
+        new_processors = [cap.process]
+    structlog.configure(processors=new_processors, cache_logger_on_first_use=False)
+    cap.original_configure = configure = structlog.configure
+    cap.configure_once = structlog.configure_once
     monkeypatch.setattr("structlog.configure", no_op)
     monkeypatch.setattr("structlog.configure_once", no_op)
     request.node.structlog_events = cap.events
     yield cap
 
-    # back to normal behavior
-    configure(processors=processors)
+    # back to original behavior
+    configure(processors=original_processors)
 
 
 @pytest.hookimpl(tryfirst=True, hookwrapper=True)

setup.py

@@ -2,7 +2,7 @@
 
 setup(
     name="pytest-structlog",
-    version="0.4",
+    version="0.5",
     url="https://github.com/wimglenn/pytest-structlog",
     description="Structured logging assertions",
     long_description=open("README.rst").read(),

tests/test_issue18.py

@@ -0,0 +1,32 @@
+import pytest
+
+import structlog
+
+
+logger = structlog.get_logger(__name__)
+
+
+@pytest.fixture
+def stdlib_configure():
+    structlog.configure(
+        processors=[
+            structlog.stdlib.filter_by_level,
+            structlog.stdlib.add_logger_name,
+            structlog.stdlib.add_log_level,
+            structlog.stdlib.PositionalArgumentsFormatter(),
+            structlog.processors.TimeStamper(fmt="iso"),
+            structlog.processors.StackInfoRenderer(),
+            structlog.processors.format_exc_info,
+            structlog.dev.ConsoleRenderer(),
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        wrapper_class=structlog.stdlib.BoundLogger,
+        context_class=structlog.threadlocal.wrap_dict(dict),
+    )
+
+
+def test_positional_formatting(stdlib_configure, log):
+    items_count = 2
+    dt = 0.02
+    logger.info("Processed %d CC items in total in %.2f seconds", items_count, dt)
+    assert log.has("Processed 2 CC items in total in 0.02 seconds", level="info")