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

[olucasandrade]

Summary

• Move apply_logging_dictconfig into app/sep/settings_override.py and register it on WORKER_OVERRIDE_CALLBACKS so a HOT LOGGING override re-enters dictConfig in Celery children (matching the web lifespan path from SEP-1720).
• Verify re-application is safe under disable_existing_loggers: False: worker tests assert the effective app logger level changes and that a runtime logger outside the configured tree (kombu.connection) stays enabled.
• No changelog fragment — settings-override worker refresh is still unreleased (same cycle as SEP-1720).

Known limitation (not a regression vs the web process): this callback fires only on a change. A process that boots while a LOGGING override row already exists never re-applies dictConfig — the inline seed fires no callbacks, the periodic loop then sees no diff, and boot-time dictConfig reads non-HOT LOGGING_CONFIG (YAML/env level). Tracked as SEP-1814.

Fixes SEP-1724

Tested

• on this branch, start backend + Celery worker with SETTINGS_OVERRIDE_REFRESHER_ENABLED=true (and a short refresh interval if useful)
• Confirm worker logs at WARNING after boot (LOGGING: WARNING in settings.yaml or equivalent)
• PATCH /api/sep/admin/settings/Settings with key LOGGING value DEBUG → 200; subsequent GET reports DEBUG live
• Wait for a worker refresh cycle (or run a task that drives celery.loop.run_until_complete) and confirm the worker emits DEBUG lines without restart
• Regression: changing an unrelated override does not break worker logging; Celery task logging still appears

Checklist

• New/modified functions have type hints and rST docstrings
• New tests added for new features or bug fixes
• All tests pass locally (make test) — logging rebind + override callback tests (11 targeted passed this round)
• Pre-commit hooks pass (make run-pre-commit) — passed on commit
• Database migrations generated if models changed (make makemigrations) (N/A)
• User-facing changes documented (README, inline help, UI text) (N/A)
• Configuration changes documented with examples (N/A)
• Changelog fragment added under changelog.d/ if the change is user-facing (make changelog-add), or confirmed N/A (internal-only change, or a same-release-cycle fix for an unreleased sibling ticket)

[Copilot]

Pull request overview

This PR ensures Celery worker processes re-apply logging.config.dictConfig when the HOT LOGGING setting is overridden at runtime, aligning worker behavior with the SEP web lifespan path.

Changes:

• Move apply_logging_dictconfig into app/sep/settings_override.py and register it in WORKER_OVERRIDE_CALLBACKS for (SETTINGS, "LOGGING").
• Update SEP web override-callback wiring to use the shared apply_logging_dictconfig.
• Add/adjust tests to verify worker log level changes take effect after refresh without breaking Celery logger handler wiring.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated no comments.

File	Description
tests/app/sep/test_settings_override_worker.py	Extends worker override callback coverage and adds tests proving worker dictConfig is re-applied on LOGGING overrides while preserving Celery logger handlers.
tests/app/sep/test_override_callbacks.py	Updates callback imports and patches to target the new apply_logging_dictconfig location.
app/sep/settings_override.py	Introduces apply_logging_dictconfig and registers it in WORKER_OVERRIDE_CALLBACKS so worker refresh cycles re-enter dictConfig.
app/sep/main.py	Removes the local _apply_logging_dictconfig and wires the lifespan callback to the shared implementation.

[github-actions]

Coverage report

Click to see where and how coverage changed

File	Statements	Missing	Coverage	Coverage (new stmts)	Lines missing
app/sep
main.py
settings_override.py
app/sep/sync/syncers
pmm.py
Project Total

This report was generated by python-coverage-comment-action

[olucasandrade]

@copilot resolve the merge conflicts in this pull request

[Copilot]

@copilot resolve the merge conflicts in this pull request

Resolved the merge conflict and pushed merge commit b54a9704.

[olucasandrade]

@copilot resolve the merge conflicts in this pull request

[Copilot]

@copilot resolve the merge conflicts in this pull request

Resolved and pushed merge commit 29bf971f.

[yyyyyyyan]

@olucasandrade — the wiring here is clean and faithful to the ticket. apply_logging_dictconfig is a byte-for-byte move that still mirrors set_log_level key-for-key (app/core/config.py:644-645) — I checked the real LOGGING_CONFIG for handler-level level keys a rebind would miss and there are none, so the two-key mutation is complete. Promoting the symbol rather than reaching across the module boundary for a private one is the right call now that both registries need it, test_registry_is_pmm_and_logging pins the worker subset from the registry instead of a literal, and test_without_the_callback_boot_level_survives is a proper control that makes the treatment test's level assertion mean something. Skipping the changelog fragment checks out too: changelog.d/SEP-1720.fixed.md is still unreleased and already promises restart-free worker overrides for the global Settings, so this makes an existing claim true rather than adding one.

Two things I'd like settled before merge.

The Celery-preservation assertion cannot fail — tests/app/sep/test_settings_override_worker.py:513. The LOGGING_CONFIG: boot_config entry injected at line 495 is discarded before the callback runs, so the callback re-applies the real production config, which always declares a celery logger and handler. The assertion holds in every branch — including the one its own message names. Since this is the verification the ticket turns on rather than wiring, it is worth making discriminating. Details inline.

The residual boot-path limitation is recorded nowhere — app/sep/settings_override.py:177. The callback fires only on a change, so a worker child that boots while an override row already exists never applies it. This is not a regression and not worse than the web process — the PR does reach the parity the ticket asks for — but this PR retires the Known-limitations entry that used to carry the caveat, so it ends up undocumented. I have left a separate comment tracking the fix; the ask here is just to note the limitation in the description.

Three Minor items inline as well — a redundant import, a docstring that credits the wrong mechanism, and a duplicated test preamble that mutates global logging state outside its try. Two of them are one-click suggestions.

Nothing here is a regression, and none of it is expensive. Happy to re-review once the assertion and the limitation note land.

[yyyyyyyan]

A Settings.LOGGING override is never applied to a process that boots after the override row is written.

Splitting this out of the PR #1281 review — the change itself is correct for the case SEP-1724 reproduces (override written while the worker is running). What it cannot cover is the boot path, and the gap is uniform across every SEP process rather than worker-specific:

• Every process applies logging.config.dictConfig(settings.LOGGING_CONFIG) before any override snapshot exists — app/celery.py:51 (Celery's setup_logging, in the parent, pre-fork), app/main.py:216,257, app/sep/main.py:433, app/tasks/main.py:214, app/inventory/main.py:134. LOGGING_CONFIG is not a HOT field (app/core/config.py:600), so its baked-in level always comes from the YAML/env LOGGING, never from the DB row.
• The refresher's inline seed deliberately fires no callbacks — start_refresh_task seeds via refresh_all(session_maker_factory, proxies) at app/core/settings_override/lifecycle.py:284 and :290, and passes callbacks only to the periodic loop at :309.
• The periodic loop then has nothing to diff: fire_change_callbacks skips a key whose previous and current values are equal (app/core/settings_override/lifecycle.py:145-146), and the seed already published the overridden value.

So after any worker restart or child re-fork with a LOGGING override active, GET /api/sep/admin/settings/Settings reports DEBUG while the process keeps logging at the file's level — permanently, with nothing in the logs to indicate it. The same holds for the web process, which is why PR #1281 does reach parity with the web behaviour SEP-1724 asks it to match.

Worth recording because of why the "seed fires no callbacks" rule holds elsewhere: the rule is sound for a callback whose effect the boot path reproduces from the snapshot on its own. invalidate_pmm_clients qualifies — a fresh child starts with an empty client registry and key-misses to a client built from the seeded snapshot, so evicting nothing is correct. apply_logging_dictconfig is the first registered callback that does not qualify, because the boot-time dictConfig reads LOGGING_CONFIG — which no snapshot can carry — rather than the effective LOGGING. The design assumption is load-bearing and now has its first exception.

Closing it is a design decision rather than a mechanical fix, which is why it is tracked separately. Two candidate shapes:

• Have the boot-time dictConfig read the effective level from the proxy after the seed, instead of from the construction-time LOGGING_CONFIG.
• Fire the rebind callbacks once on the inline seed for the subset of callbacks whose effect the boot path does not otherwise reproduce.

[yyyyyyyan]

@olucasandrade — both substantive asks landed well. The limitation note in the description is specific rather than hand-wavy: it names the seed-fires-no-callbacks path, the equal-snapshot diff, and the non-HOT LOGGING_CONFIG read, which is exactly the chain that makes a booted-with-override worker log at the file's level. worker_logging_boot folds the duplicated preamble into one fixture with the snapshot mutation inside the guard, the redundant import is gone, and the docstring now credits the right mechanism — disable_existing_loggers: False for leaving runtime loggers enabled, and named loggers re-created rather than preserved.

The Celery-preservation assertion still cannot fail — tests/app/sep/test_settings_override_worker.py:506. This one is my fault: I suggested celery.app.trace, and it is a child of the celery logger that LOGGING_CONFIG declares, so dictConfig refuses to disable it whatever disable_existing_loggers says. I checked this time, flipping only the flag against a production-shaped config: celery.app.trace reports disabled=False on both branches, while kombu.connection and billiard.pool report False then True. A one-word swap to a logger outside the configured tree makes the assertion discriminating — measurements and the exact line are on the re-opened thread. Everything else in that test is sound; the level assertion and its control still carry the ticket.

Minor — the worker_logging_boot docstring says teardown always runs, but logging.config.dictConfig(boot_config) at line 468 is still ahead of the try, so a failure there would leave the NullHandler config installed with nothing to restore it. The config is a literal dict and will not realistically raise, so this is about the claim being unconditional rather than about risk; moving that one line inside the try makes it true.

One note on the description rather than the code: "Tracked as a follow-up outside this PR" has no ticket behind it — the only tracking that exists today is my open thread, which disappears from view on merge. Worth filing so the boot-path gap outlives this PR.

Happy to re-review as soon as the logger name changes.

[yyyyyyyan]

Tracked the follow-up from this comment as SEP-1814: A Settings.LOGGING override is never applied to a process that boots after the override row is written.

[yyyyyyyan]

@olucasandrade — the kombu.connection swap does discriminate: it sits outside every name LOGGING_CONFIG declares, so dictConfig disables it when disable_existing_loggers is True and leaves it enabled when it is False. All five threads addressed, LGTM.