Configure the fwl logger at CLI entry points (#708)#776
Draft
egpbos wants to merge 5 commits into
Draft
Conversation
The 'fwl' logger was only given handlers inside Proteus.start() (and a few CLI commands), but records are emitted earlier: Proteus.__init__ calls set_directories(), which logs at INFO, and the grid-summarise / grid-pack commands never configure logging at all. With no handler on 'fwl', those records fall through to logging.lastResort, which emits only WARNING and above, so INFO/DEBUG output was silently lost. Add bootstrap_logger(), which attaches a stdout handler to 'fwl' only when it has none, and call it from the top-level CLI group callback so every subcommand has console logging active before it runs. It is idempotent and non-destructive: setup_logger() still clears handlers and installs the file-backed logger once the output directory is known, so there is no duplicate output and file logging is unchanged. Refs #708
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #776 +/- ##
==========================================
- Coverage 92.66% 92.60% -0.07%
==========================================
Files 110 110
Lines 15807 16006 +199
Branches 2846 2906 +60
==========================================
+ Hits 14648 14822 +174
- Misses 1159 1170 +11
- Partials 0 14 +14
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
Extract _resolve_level and _console_handler so setup_logger and bootstrap_logger no longer duplicate the level check and the stdout handler construction. The two entry points keep their distinct, complementary roles: bootstrap_logger is the lightweight, non-destructive fallback the CLI installs at entry. It guarantees there is always a console handler before a command knows its output directory, no-ops if a handler already exists, and never opens a logfile. setup_logger is the authoritative configuration used once the output directory is known, both from the CLI and from the Python API. It clears handlers, installs the file-backed logger, and sets the exception hook. Neither public contract changes; behaviour is unchanged.
The grid manager had its own setup_logger that configured the root logger, while bootstrap_logger and the main setup_logger configure the 'fwl' logger. With bootstrap_logger now installed at CLI entry, both a 'fwl' handler and the grid's root handler emitted every grid log line, so grid console output was duplicated. Point the grid manager at the shared proteus.utils.logs.setup_logger, which configures 'fwl' and clears its handlers first, so grid logs print once. Add an optional fmt/datefmt to setup_logger so the grid keeps its plain, timestamped manager.log layout; all other callers are unchanged. Remove the grid-local setup_logger and the tests that covered it, since that behaviour is now the shared function's, covered under tests/utils/test_logs.py.
| logging.getLogger('fwl').info('PLAINMARK') | ||
| for h in logging.getLogger('fwl').handlers: | ||
| h.flush() | ||
| contents = open(logpath).read().strip() |
| logging.getLogger('fwl').info('TAGMARK') | ||
| for h in logging.getLogger('fwl').handlers: | ||
| h.flush() | ||
| contents = open(logpath).read().strip() |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Description
The
fwllogger only received handlers insideProteus.start()and a few CLI commands, but records are emitted earlier:Proteus.__init__callsset_directories(), which logs at INFO, and thegrid-summarise/grid-packcommands never configure logging at all. With no handler onfwl, those records fall through tologging.lastResort, which emits only WARNING and above, so INFO/DEBUG output was silently lost.This adds
bootstrap_logger(), which attaches a stdout handler tofwlonly when it has none, and calls it from the top-level CLI group callback so every subcommand has console logging active before it runs. It is idempotent and non-destructive:setup_logger()still clears handlers and installs the file-backed logger once the output directory is known, so there is no duplicate output and file logging is unchanged.Closes #708
Two loggers, two purposes (note for reviewers)
bootstrap_loggeris deliberately not a replacement forsetup_logger; they play complementary roles:bootstrap_logger: the lightweight, non-destructive fallback installed at CLI entry. Its job is to guarantee there is at least something catching console output before a command knows its output directory. It no-ops if a handler already exists and never opens a logfile, so it cannot clobber a real configuration.setup_logger: the authoritative configuration, used once the output directory is known, both from the CLI and from the Python API. It clears handlers, installs the file-backed logger, and sets the exception hook.setup_loggercannot simply be called at CLI entry in place ofbootstrap_loggerbecause it unconditionally opens aFileHandlerat a path that is not known until the config is parsed inside the subcommand. The shared console-handler and level-validation code is factored into two private helpers (_resolve_level,_console_handler) so the two entry points stay consistent without duplication.Grid manager logging: merged into the shared setup_logger (input wanted)
Harrison, Tim: while wiring
bootstrap_loggerin, I found thatproteus griddoubled every log line, and I would like your read on the fix.Root cause:
grid/manage.pyhad its own localsetup_loggerthat configured the root logger, whereasbootstrap_loggerand the mainsetup_loggerconfigure thefwllogger. Oncebootstrap_loggerinstalls a handler onfwlat CLI entry, a grid log record (emitted onfwl.proteus.grid.manage) was handled by thefwlhandler and propagated up to the root handler the grid installed, so it printed twice. Measured: 1 line before this PR, 2 lines withbootstrap_loggerand the old grid function.Fix in this PR: point the grid manager at the shared
proteus.utils.logs.setup_loggerand delete the local copy. Because the shared function clears thefwlhandlers before installing its own, the bootstrap console handler is replaced rather than stacked, so grid logs print exactly once again (verified).The old grid function differed from the shared one in three ways. Two are now preserved, one is a genuine behaviour change I want you to sanity-check:
[%(asctime)s] %(message)s. I added an optionalfmt/datefmttosetup_loggerand the grid passes that exact format, somanager.logis byte-for-byte the same style as before. This one looked intentional to me (clean, timestamped logs are useful), which is why I kept it rather than dropping it.1-> INFO via amatch); the shared one takes the string names used everywhere else. The only call site passed1, nowlevel='INFO'.manager.logalso captured records from non-fwl(third-party) loggers. The shared function configuresfwlonly. Configuringfwlis what removes the double-logging and matches the rest of PROTEUS, but it does narrow whatmanager.logcaptures.Question: were these divergences (root logger, int levels, the timestamped format) intended design choices, or incidental historical drift from before the
fwlconvention settled? In particular, does the grid rely onmanager.logcapturing root-level / third-party logs, or is narrowing tofwlfine? If capturing root is wanted, I will keep it onfwlfor de-duplication but can widen capture another way.Validation of changes
tests/utils/test_logs.py(49 tests) andtests/grid/test_manage.py(44 tests): all pass locally. The logs file adds 6 tests forbootstrap_loggerand 2 for the newfmt/datefmtpath; the grid file drops the tests for the removed localsetup_logger.bootstrap_loggertests use an autouse fixture that snapshots and restores the sharedfwlsingleton so logger state does not leak between tests.bootstrap_loggerthensetup_loggeryields exactly one stdout handler (no duplicate); a grid-stylebootstrap_logger+setup_logger(fmt=...)sequence prints a grid record once (the double-logging fix) in the preserved timestamped format.ruff checkandruff format --checkpass onsrc/andtests/(ruff 0.15.22).@pytest.mark.slowtests/grid/test_grid.py. Itstest_grid_packfails on a missing per-caseruntime_helpfile.csv, which is produced by theproteus startsubprocess and is unavailable in this environment; it is unrelated to logging (themanager.logassertions in the same test pass, andmanager.loghas the correct timestamped format). This tier runs nightly, not in the PR checks.Test configuration: macOS; PROTEUS conda environment (Python 3.12, the supported version).
Checklist