diff --git a/tasktiger/logging.py b/tasktiger/logging.py index 02e81626..19efdfda 100644 --- a/tasktiger/logging.py +++ b/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 diff --git a/tests/test_logging.py b/tests/test_logging.py index c8ebdb67..d74ae914 100644 --- a/tests/test_logging.py +++ b/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):