Add 'task_func' to logging processor (#265)

* Add 'task_func' to logging processor

* Refactor 'tests.test_logging'

* Test 'test_func' in logging

tasktiger/logging.py

@@ -11,6 +11,7 @@ def tasktiger_processor(logger, method_name, event_dict):
     if g["current_tasks"] is not None and not g["current_task_is_batch"]:
         current_task = g["current_tasks"][0]
         event_dict["task_id"] = current_task.id
+        event_dict["task_func"] = current_task.serialized_func
         event_dict["queue"] = current_task.queue
 
     return event_dict

tests/test_logging.py

@@ -1,5 +1,6 @@
 from __future__ import absolute_import
 
+import pytest
 import structlog
 
 from tasktiger import TaskTiger, Worker
@@ -9,55 +10,52 @@
 from .utils import get_redis, get_tiger
 
 tiger = get_tiger()
-
 logger = structlog.getLogger("tasktiger")
 
 
+@pytest.fixture(autouse=True)
+def restore_structlog_config():
+    previous_config = structlog.get_config()
+
+    try:
+        yield
+    finally:
+        structlog.configure(**previous_config)
+
+
 def logging_task():
     log = logger.info("simple task")
+
     # Confirm tasktiger_processor injected task id and queue name
     assert log[1]["task_id"] == tiger.current_task.id
-    assert log[1]["queue"] == tiger.current_task.queue
+    assert log[1]["task_func"] == "tests.test_logging:logging_task"
+    assert log[1]["queue"] == "foo_qux"
 
 
 class TestLogging(BaseTestCase):
     """Test logging."""
 
     def test_structlog_processor(self):
-        try:
-            # Use ReturnLogger for testing
-            structlog.configure(
-                processors=[tasktiger_processor],
-                context_class=dict,
-                logger_factory=structlog.ReturnLoggerFactory(),
-                wrapper_class=structlog.stdlib.BoundLogger,
-                cache_logger_on_first_use=True,
-            )
-
-            # Run a simple task. Logging output is verified in
-            # the task.
-            self.tiger.delay(logging_task)
-            queues = self._ensure_queues(queued={"default": 1})
-            task = queues["queued"]["default"][0]
-            assert task["func"] == "tests.test_logging:logging_task"
-            Worker(self.tiger).run(once=True)
-            self._ensure_queues(queued={"default": 0})
-            assert not self.conn.exists("t:task:%s" % task["id"])
-        finally:
-            structlog.configure(
-                processors=[
-                    structlog.stdlib.add_log_level,
-                    structlog.stdlib.filter_by_level,
-                    structlog.processors.TimeStamper(fmt="iso", utc=True),
-                    structlog.processors.StackInfoRenderer(),
-                    structlog.processors.format_exc_info,
-                    structlog.processors.JSONRenderer(),
-                ],
-                context_class=dict,
-                logger_factory=structlog.ReturnLoggerFactory(),
-                wrapper_class=structlog.stdlib.BoundLogger,
-                cache_logger_on_first_use=True,
-            )
+        # Use ReturnLogger for testing
+        structlog.configure(
+            processors=[tasktiger_processor],
+            context_class=dict,
+            logger_factory=structlog.ReturnLoggerFactory(),
+            wrapper_class=structlog.stdlib.BoundLogger,
+            cache_logger_on_first_use=True,
+        )
+
+        # Run a simple task. Logging output is verified in
+        # the task.
+        self.tiger.delay(logging_task, queue="foo_qux")
+        queues = self._ensure_queues(queued={"foo_qux": 1})
+
+        task = queues["queued"]["foo_qux"][0]
+        assert task["func"] == "tests.test_logging:logging_task"
+
+        Worker(self.tiger).run(once=True)
+        self._ensure_queues(queued={"foo_qux": 0})
+        assert not self.conn.exists("t:task:%s" % task["id"])
 
 
 class TestSetupStructlog(BaseTestCase):