Downgrade routine anon-403s on /api/v3/auth/profile/ to DEBUG (#759)

A fresh browser visit to Codex probes /api/v3/auth/profile/ before any
session cookie exists, which Django's BaseHandler.get_response logs as
a WARNING ("Forbidden: /api/v3/auth/profile/") for every first-time
visitor. That drowns the main log in routine noise.

Add a logging.Filter on django.request that downgrades records matching
that exact "Forbidden: <path>" pattern to DEBUG, parameterized by a
small frozenset of known-noisy paths so abuse on other endpoints still
surfaces at WARNING.

Also move django.request into the loggers dict where dictConfig will
actually see it — the old top-level placement was silently ignored.
Records still flow to the root loguru handler via propagation.

Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

Author: ajslater

codex/settings/logging.py

@@ -1,10 +1,35 @@
 """Logging Settings."""
 
-from logging import Handler
-from typing import override
+import logging
+from logging import Filter, Handler
+from typing import Final, override
 
 from loguru import logger
 
+# Paths whose routine anon-403s are noise, not abuse. The first-load
+# probe to ``/api/v3/auth/profile/`` is the obvious offender — a fresh
+# browser hits it before any session cookie exists. Django's
+# BaseHandler.get_response logs every 4xx at WARNING; we downgrade the
+# ones we expect so the main log stays useful.
+_NOISY_FORBIDDEN_PATHS: Final[frozenset[str]] = frozenset({"/api/v3/auth/profile/"})
+
+
+class DowngradeNoisyForbiddenFilter(Filter):
+    """Downgrade routine anon 403s on known-noisy paths to DEBUG."""
+
+    @override
+    def filter(self, record) -> bool:
+        if record.levelno != logging.WARNING:
+            return True
+        msg = record.getMessage()
+        if not msg.startswith("Forbidden: "):
+            return True
+        path = msg.split(": ", 1)[1]
+        if path in _NOISY_FORBIDDEN_PATHS:
+            record.levelno = logging.DEBUG
+            record.levelname = "DEBUG"
+        return True
+
 
 class LoguruHandler(Handler):
     """Redirect logging to loguru."""
@@ -71,9 +96,22 @@ def get_logging_settings(loglevel: str | int, *, debug: bool) -> dict[str, int |
             }
         )
     level = "DEBUG" if loglevel == "TRACE" else loglevel
+    # ``django.request`` belongs inside ``loggers`` so dictConfig sees it;
+    # putting it at the top level (as this file used to) is silently
+    # ignored. Records still reach the root ``loguru`` handler via
+    # propagation, but the filter only runs when the logger is declared
+    # here.
+    loggers["django.request"] = {
+        "filters": ["downgrade_noisy_forbidden"],
+    }
     return {
         "version": 1,
         "disable_existing_loggers": True,
+        "filters": {
+            "downgrade_noisy_forbidden": {
+                "()": "codex.settings.logging.DowngradeNoisyForbiddenFilter",
+            },
+        },
         "handlers": {
             "loguru": {
                 "class": "codex.settings.logging.LoguruHandler",
@@ -84,20 +122,5 @@ def get_logging_settings(loglevel: str | int, *, debug: bool) -> dict[str, int |
             "level": level,
             "propagate": True,
         },
-        "django": {
-            "handlers": ["loguru"],
-            "level": level,
-            "propagate": True,
-        },
-        "django.request": {
-            "handlers": ["loguru"],
-            "level": level,
-            "propagate": True,
-        },
-        "django.server": {
-            "handlers": ["loguru"],
-            "level": level,
-            "propagate": True,
-        },
         "loggers": loggers,
     }

tests/test_logging_filter.py

@@ -0,0 +1,68 @@
+"""Tests for the noisy-Forbidden log filter."""
+
+import logging
+from typing import Final, override
+
+from django.test import TestCase
+
+from codex.settings.logging import DowngradeNoisyForbiddenFilter
+
+_FILTER_NAME: Final = "test"
+
+
+def _build_record(level: int, msg: str, *args: object) -> logging.LogRecord:
+    return logging.LogRecord(
+        name="django.request",
+        level=level,
+        pathname=__file__,
+        lineno=0,
+        msg=msg,
+        args=args,
+        exc_info=None,
+    )
+
+
+class DowngradeNoisyForbiddenFilterTests(TestCase):
+    """Cover the level-downgrade logic on the request logger filter."""
+
+    @override
+    def setUp(self) -> None:
+        """Build one filter shared across the cases."""
+        self.flt = DowngradeNoisyForbiddenFilter(_FILTER_NAME)  # pyright: ignore[reportUninitializedInstanceVariable]
+
+    def test_downgrades_noisy_path(self) -> None:
+        """First-load profile probe becomes DEBUG."""
+        record = _build_record(
+            logging.WARNING, "%s: %s", "Forbidden", "/api/v3/auth/profile/"
+        )
+        kept = self.flt.filter(record)
+        assert kept is True
+        assert record.levelno == logging.DEBUG
+        assert record.levelname == "DEBUG"
+
+    def test_keeps_unrelated_forbidden_at_warning(self) -> None:
+        """A Forbidden on a non-noisy path stays at WARNING."""
+        record = _build_record(
+            logging.WARNING, "%s: %s", "Forbidden", "/api/v3/admin/users/"
+        )
+        kept = self.flt.filter(record)
+        assert kept is True
+        assert record.levelno == logging.WARNING
+
+    def test_keeps_non_forbidden_at_warning(self) -> None:
+        """A Bad Request line through django.request stays at WARNING."""
+        record = _build_record(
+            logging.WARNING, "%s: %s", "Bad Request", "/api/v3/auth/profile/"
+        )
+        kept = self.flt.filter(record)
+        assert kept is True
+        assert record.levelno == logging.WARNING
+
+    def test_ignores_non_warning_levels(self) -> None:
+        """ERROR-level records pass through untouched."""
+        record = _build_record(
+            logging.ERROR, "%s: %s", "Forbidden", "/api/v3/auth/profile/"
+        )
+        kept = self.flt.filter(record)
+        assert kept is True
+        assert record.levelno == logging.ERROR