SEP-1724: Re-apply logging dictConfig on worker LOGGING overrides

app/sep/main.py

@@ -18,7 +18,6 @@
 import logging.config
 from collections.abc import AsyncGenerator, Callable, Mapping
 from contextlib import asynccontextmanager
-from copy import deepcopy
 from typing import Any
 
 from fastapi import FastAPI, HTTPException, Request, status
@@ -51,6 +50,7 @@
 from app.sep.db import get_async_session_maker
 from app.sep.db.seed import get_system_periodic_tasks, init_sep_db
 from app.sep.settings_override import (
+    apply_logging_dictconfig,
     build_sep_override_proxies,
     invalidate_pmm_clients,
 )
@@ -154,30 +154,6 @@ async def _rebind(_: Mapping[str, object]) -> None:
     return _rebind
 
 
-async def _apply_logging_dictconfig(_: Mapping[str, object]) -> None:
-    """Re-apply ``logging.config.dictConfig`` after a global ``LOGGING`` override.
-
-    ``LOGGING`` is a HOT field, but ``LOGGING_CONFIG`` (the dict handed to
-    ``dictConfig``) is not: the override snapshot replaces only the ``LOGGING``
-    key, so ``settings.LOGGING_CONFIG`` still carries the level baked in by the
-    ``set_log_level`` model validator at construction time. This callback mirrors
-    that validator -- inject the now-live ``settings.LOGGING`` into a copy of the
-    config and re-apply it -- so a log-level change takes effect in the SEP web
-    process without a restart. Failures are logged and swallowed: a malformed
-    config must not take the process down mid-request.
-
-    :param _: The new effective ``Settings`` snapshot mapping (unused -- the level
-        is re-read from the proxy).
-    """
-    try:
-        config = deepcopy(settings.LOGGING_CONFIG)
-        config["loggers"][""]["level"] = settings.LOGGING
-        config["loggers"]["app"]["level"] = settings.LOGGING
-        logging.config.dictConfig(config)
-    except Exception:
-        logger.exception("Failed to re-apply logging config after LOGGING override")
-
-
 async def _reseed_system_periodic_tasks(_: Mapping[str, object]) -> None:
     """Re-seed the SEP beat schedule after a hot interval override.
 
@@ -246,7 +222,7 @@ async def sep_overrides_lifespan(app: FastAPI) -> AsyncGenerator[None, None]:
             ssl_certfile=tasks_settings.SSL_CERTFILE,
         ),
         (SettingClassEnum.SETTINGS, "PMM"): invalidate_pmm_clients,
-        (SettingClassEnum.SETTINGS, "LOGGING"): _apply_logging_dictconfig,
+        (SettingClassEnum.SETTINGS, "LOGGING"): apply_logging_dictconfig,
         (
             SettingClassEnum.SNIPPETS_SETTINGS,
             "SYNC_INTERVAL",

app/sep/settings_override.py

@@ -25,7 +25,9 @@
 ``celery.tasks``.
 """
 
+import logging.config
 from collections.abc import Mapping
+from copy import deepcopy
 from typing import Any
 
 from celery.signals import worker_process_init, worker_process_shutdown
@@ -47,6 +49,8 @@
 from app.sep.db import get_async_session_maker
 from app.sep.snippets.config import snippets_settings, SnippetsSettings
 
+logger = logging.getLogger(__name__)
+
 
 def build_sep_override_proxies() -> ProxyRegistry:
     """Compose the SEP-side proxy registry: app-owned entries plus SEP's own.
@@ -132,14 +136,45 @@ async def invalidate_pmm_clients(_: Mapping[str, object]) -> None:
         await settings.invalidate_client(str(endpoint))
 
 
+async def apply_logging_dictconfig(_: Mapping[str, object]) -> None:
+    """Re-apply ``logging.config.dictConfig`` after a global ``LOGGING`` override.
+
+    ``LOGGING`` is a HOT field, but ``LOGGING_CONFIG`` (the dict handed to
+    ``dictConfig``) is not: the override snapshot replaces only the ``LOGGING``
+    key, so ``settings.LOGGING_CONFIG`` still carries the level baked in by the
+    ``set_log_level`` model validator at construction time. This callback mirrors
+    that validator -- inject the now-live ``settings.LOGGING`` into a copy of the
+    config and re-apply it -- so a log-level change takes effect in the SEP web
+    process and Celery worker children without a restart. Failures are logged and
+    swallowed: a malformed config must not take the process down mid-request or
+    mid-task. ``LOGGING_CONFIG`` sets ``disable_existing_loggers: False``, so
+    re-entering ``dictConfig`` from a worker refresh cycle leaves the loggers
+    Celery created at runtime enabled, and re-creates the ones the config names
+    -- ``celery`` among them -- with their handlers.
+
+    :param _: The new effective ``Settings`` snapshot mapping (unused -- the level
+        is re-read from the proxy).
+    """
+    try:
+        config = deepcopy(settings.LOGGING_CONFIG)
+        config["loggers"][""]["level"] = settings.LOGGING
+        config["loggers"]["app"]["level"] = settings.LOGGING
+        logging.config.dictConfig(config)
+    except Exception:
+        logger.exception("Failed to re-apply logging config after LOGGING override")
+
+
 #: The callbacks the worker refresher registers -- deliberately a strict subset
 #: of the web lifespan's registry. The dropped entries either rebind ``app.state``
 #: clients or reseed beat-schedule rows, neither of which a worker child owns.
 #: ``invalidate_pmm_clients`` is kept because ``ClientRegistry.IMMUTABLE_KEYS``
 #: excludes ``api_key``: a same-endpoint credential override would otherwise
 #: refresh the snapshot while worker tasks keep the client with the old key.
+#: ``apply_logging_dictconfig`` is kept so a HOT ``LOGGING`` override re-enters
+#: ``dictConfig`` after Celery's ``setup_logging`` installed boot-time levels.
 WORKER_OVERRIDE_CALLBACKS: CallbackRegistry = {
     (SettingClassEnum.SETTINGS, "PMM"): invalidate_pmm_clients,
+    (SettingClassEnum.SETTINGS, "LOGGING"): apply_logging_dictconfig,
 }
 
 

tests/app/sep/test_override_callbacks.py

@@ -32,7 +32,7 @@
     _make_remote_api_rebinder,
     _reseed_system_periodic_tasks,
 )
-from app.sep.settings_override import invalidate_pmm_clients
+from app.sep.settings_override import apply_logging_dictconfig, invalidate_pmm_clients
 from app.sep.snippets.config import snippets_settings
 
 
@@ -162,10 +162,10 @@ async def test_apply_logging_dictconfig_reapplies_new_level(
     the overridden level into the config before re-applying it — otherwise the
     stale level baked in at construction time would be re-applied.
     """
-    dict_config = mocker.patch("app.sep.main.logging.config.dictConfig")
+    dict_config = mocker.patch("app.sep.settings_override.logging.config.dictConfig")
     settings._set_snapshot({"LOGGING": "DEBUG"})
     try:
-        await sep_main._apply_logging_dictconfig({})
+        await apply_logging_dictconfig({})
     finally:
         settings._set_snapshot({})
 
@@ -181,12 +181,13 @@ async def test_apply_logging_dictconfig_swallows_failure(
 ) -> None:
     """Assert a malformed logging config is logged and swallowed, never crashing the app."""
     mocker.patch(
-        "app.sep.main.logging.config.dictConfig", side_effect=ValueError("bad config")
+        "app.sep.settings_override.logging.config.dictConfig",
+        side_effect=ValueError("bad config"),
     )
     settings._set_snapshot({"LOGGING": "DEBUG"})
     try:
         # Must not raise.
-        await sep_main._apply_logging_dictconfig({})
+        await apply_logging_dictconfig({})
     finally:
         settings._set_snapshot({})
 
@@ -200,7 +201,7 @@ async def test_logging_and_app_drain_callbacks_registered() -> None:
             callbacks = sep_main.sep_app.state.override_callbacks
         assert (
             callbacks[(SettingClassEnum.SETTINGS, "LOGGING")]
-            is sep_main._apply_logging_dictconfig
+            is apply_logging_dictconfig
         )
         assert (
             callbacks[(SettingClassEnum.SEP_SETTINGS, "APP_DRAIN")]

tests/app/sep/test_settings_override_worker.py

@@ -16,6 +16,8 @@
 """Tests for the SEP worker's settings-override wiring."""
 
 import asyncio
+import logging
+import logging.config
 from typing import ClassVar
 
 import pytest
@@ -30,7 +32,7 @@
 from sqlmodel.pool import StaticPool
 
 from app.core.alerts.config import alert_settings
-from app.core.config import BaseYamlSettings, settings
+from app.core.config import BaseYamlSettings, LogLevel, settings
 from app.core.db.utils import get_async_session_maker_from_engine
 from app.core.settings_override import lifecycle
 from app.core.settings_override.api.routes import AppOwnedClassEntry
@@ -221,9 +223,12 @@ def test_builder_shares_no_keys_with_the_tasks_registry(self) -> None:
 class TestWorkerOverrideCallbacks:
     """Cover the callback subset the worker refresher registers."""
 
-    def test_registry_is_exactly_the_pmm_invalidation(self) -> None:
-        """Pin the disposition: PMM client invalidation, and nothing else."""
-        assert set(WORKER_OVERRIDE_CALLBACKS) == {(SettingClassEnum.SETTINGS, "PMM")}
+    def test_registry_is_pmm_and_logging(self) -> None:
+        """Pin the disposition: PMM invalidation plus LOGGING dictConfig rebind."""
+        assert set(WORKER_OVERRIDE_CALLBACKS) == {
+            (SettingClassEnum.SETTINGS, "PMM"),
+            (SettingClassEnum.SETTINGS, "LOGGING"),
+        }
 
 
 class TestSepWorkerHandlers:
@@ -442,6 +447,86 @@ async def _boom(_: object) -> None:
         assert settings.PMM.api_key == SecretStr("new-key")
 
 
+@pytest.fixture(name="worker_logging_boot")
+def worker_logging_boot_fixture() -> None:
+    """Install a WARNING-level NullHandler config and restore process logging.
+
+    Mutates process-global logging and the ``settings`` snapshot; teardown
+    always runs so a leaked ``NullHandler`` root config cannot silence later
+    tests. Snapshot restore is belt-and-suspenders with the autouse
+    ``_override_snapshot_cleared`` fixture (that one runs only on setup).
+    """
+    boot_config = {
+        "version": 1,
+        "disable_existing_loggers": False,
+        "handlers": {"default": {"class": "logging.NullHandler"}},
+        "loggers": {
+            "": {"handlers": ["default"], "level": "WARNING"},
+            "app": {"handlers": ["default"], "level": "WARNING", "propagate": False},
+        },
+    }
+    try:
+        logging.config.dictConfig(boot_config)
+        settings._set_snapshot({"LOGGING": LogLevel.WARNING})
+        yield
+    finally:
+        settings._set_snapshot({})
+        logging.config.dictConfig(settings.LOGGING_CONFIG)
+
+
+class TestWorkerLoggingRebind:
+    """Verify a LOGGING override re-applies dictConfig in the worker path."""
+
+    @pytest.mark.asyncio
+    @pytest.mark.usefixtures("no_app_owned_classes", "worker_logging_boot")
+    async def test_logging_override_changes_effective_app_level(
+        self, override_session_maker: async_sessionmaker
+    ) -> None:
+        """Raise the worker's app logger to the overridden level on refresh.
+
+        Also pin ``disable_existing_loggers: False``: a runtime logger outside
+        the configured logger tree (not under a name ``LOGGING_CONFIG``
+        declares) must stay enabled after the callback re-enters ``dictConfig``.
+        Children of configured names -- e.g. ``celery.app.trace`` under
+        ``celery`` -- are never disabled either way, so they cannot discriminate.
+        """
+        runtime_logger = logging.getLogger("kombu.connection")
+        proxies = build_sep_override_proxies()
+        await _upsert_override(
+            override_session_maker,
+            setting_class=SettingClassEnum.SETTINGS,
+            key="LOGGING",
+            value="DEBUG",
+        )
+
+        await refresh_all(
+            lambda: override_session_maker, proxies, WORKER_OVERRIDE_CALLBACKS
+        )
+
+        assert settings.LOGGING == LogLevel.DEBUG
+        assert logging.getLogger("app").isEnabledFor(logging.DEBUG)
+        assert not runtime_logger.disabled
+
+    @pytest.mark.asyncio
+    @pytest.mark.usefixtures("no_app_owned_classes", "worker_logging_boot")
+    async def test_without_the_callback_boot_level_survives(
+        self, override_session_maker: async_sessionmaker
+    ) -> None:
+        """Pin the gap: snapshot updates LOGGING but handlers stay at boot level."""
+        proxies = build_sep_override_proxies()
+        await _upsert_override(
+            override_session_maker,
+            setting_class=SettingClassEnum.SETTINGS,
+            key="LOGGING",
+            value="DEBUG",
+        )
+
+        await refresh_all(lambda: override_session_maker, proxies)
+
+        assert settings.LOGGING == LogLevel.DEBUG
+        assert not logging.getLogger("app").isEnabledFor(logging.DEBUG)
+
+
 class TestRepublishSepSettingsSnapshot:
     """Cover the forced republish a task takes before deciding on settings."""