Normalize and truncate job args in logging.

Author: Majsvaffla

src/dreng/admin.py

@@ -1,13 +1,13 @@
 from __future__ import annotations
 
-import logging
 from typing import TYPE_CHECKING
 
 from django.contrib import admin, messages
 from django.db.models import QuerySet, TextChoices
 from django.urls import reverse
 from django.utils import timezone
 
+from . import logging
 from .constants import Priority
 from .models import BaseJob, FailedJob, Job
 from .utils import import_task

src/dreng/logging.py

@@ -0,0 +1,17 @@
+import logging
+from logging import INFO, WARNING
+
+__all__ = ["INFO", "WARNING", "getLogger"]
+
+
+class JobArgsFilter(logging.Filter):
+    def filter(self, record: logging.LogRecord) -> logging.LogRecord:
+        if (job := getattr(record, "job", {})) and isinstance(job, dict) and "args" in job:
+            job["args"] = str(job["args"])[:1000]  # Avoid "overflowing" logging infrastructure.
+        return record
+
+
+def getLogger(name: str = "dreng") -> logging.Logger:
+    logger = logging.getLogger(name)
+    logger.addFilter(JobArgsFilter())
+    return logger

src/dreng/models.py

@@ -1,6 +1,5 @@
 from __future__ import annotations
 
-import logging
 from datetime import UTC, datetime, timedelta
 from typing import TYPE_CHECKING, Final, Literal, TypedDict
 from uuid import UUID, uuid4
@@ -9,6 +8,7 @@
 from django.db import connection, models
 from django.utils import timezone
 
+from . import logging
 from .constants import STATUS_FAILURE
 from .utils import JSONDecoder, JSONEncoder, import_task
 

src/dreng/scripts/start_repeating_tasks.py

@@ -1,8 +1,9 @@
-import logging
 from datetime import timedelta
 
 import click
 
+from dreng import logging
+
 logger = logging.getLogger(__name__)
 
 

src/dreng/task.py

@@ -1,7 +1,6 @@
 from __future__ import annotations
 
 import datetime
-import logging
 import random
 from contextlib import ExitStack
 from dataclasses import dataclass
@@ -13,6 +12,7 @@
 from django.db import models, transaction
 from django.utils import timezone
 
+from . import logging
 from .exceptions import SilentFail
 from .signals import before_task_run
 

src/dreng/utils.py

@@ -4,7 +4,6 @@
 import contextlib
 import datetime
 import json
-import logging
 import signal
 from dataclasses import dataclass
 from datetime import timedelta
@@ -13,6 +12,7 @@
 
 from django.utils.module_loading import import_string
 
+from . import logging
 from .exceptions import TimeLimitReached
 
 __all__ = ["Decoded", "JSONDecoder", "JSONEncoder", "TimeLimit", "get_claim_count_cache_key", "import_task"]

src/dreng/worker.py

@@ -1,7 +1,6 @@
 # cspell: words noreload
 from __future__ import annotations
 
-import logging
 import signal
 import time
 from datetime import timedelta
@@ -13,6 +12,7 @@
 from django.utils import timezone
 from django.utils.module_loading import import_string
 
+from . import logging
 from .constants import CLAIM_COUNT_LIMIT, STATUS_FAILURE, STATUS_SUCCESS
 from .models import FailedJob, Job
 from .signals import after_job_finished, after_task_imported

tests/logging.py

@@ -0,0 +1,27 @@
+from typing import Any
+
+import pytest
+
+from dreng import logging
+
+
+@pytest.mark.parametrize(
+    ("extra", "expected_job"),
+    [
+        (
+            {"slack": {"chill": True}, "job": {"some_number": 123, "args": [1, 2, 3]}},
+            {"some_number": 123, "args": "[1, 2, 3]"},
+        ),
+        (
+            {"slack": {"chill": True}},
+            {},
+        ),
+    ],
+)
+def test_JobArgsFilter(caplog: pytest.LogCaptureFixture, extra: dict[str, Any], expected_job: dict[str, Any]) -> None:
+    logger = logging.getLogger("tests")
+    logger.info("Working hard or hardly working?", extra=extra)
+    (record,) = caplog.records
+    assert hasattr(record, "slack")
+    assert record.slack["chill"] is True
+    assert getattr(record, "job", {}) == expected_job