✨ Redesign logging: routing options, advanced flag, log level audit#7323
Open
agoscinski wants to merge 6 commits into
Open
✨ Redesign logging: routing options, advanced flag, log level audit#7323agoscinski wants to merge 6 commits into
agoscinski wants to merge 6 commits into
Conversation
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## main #7323 +/- ##
==========================================
- Coverage 80.26% 80.18% -0.07%
==========================================
Files 577 577
Lines 45497 45548 +51
==========================================
+ Hits 36514 36519 +5
- Misses 8983 9029 +46 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
25c43d9 to
926ad36
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 24, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 24, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
926ad36 to
6a6fdf1
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 24, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 24, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
6a6fdf1 to
81543e9
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
81543e9 to
01b3f81
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
01b3f81 to
ce6ad15
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
ce6ad15 to
cacde89
Compare
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
agoscinski
added a commit
to agoscinski/aiida-core
that referenced
this pull request
Apr 30, 2026
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
…m#7322 Mark all 11 existing per-logger options as advanced via `json_schema_extra`. Add `Option.advanced` property and `--advanced` flag to `verdi config list` with a footer hint. Update `verdi_loglevel` description to clarify it is a source-level filter only.
Add `logging.terminal_loglevel` and `logging.logfile_loglevel` to `ProfileOptionsSchema`. Wire `terminal_loglevel` as handler level on `console` and `cli` handlers. Replace hardcoded `DEBUG` in the daemon file handler with `logfile_loglevel`. Extend `CLI_LOG_LEVEL` to also override the `cli` handler level so `verdi --verbosity` still works.
Two messages about unparseable scheduler output were logged at INFO and silently missing from `verdi process report`. At WARNING they are captured by the default `db_loglevel=REPORT` threshold and stored in the `DbLog` table.
Internal step messages (transport upload/submit/retrieve, scheduler poll, broker connection steps) are machinery detail. Demoting to DEBUG reduces noise at the default REPORT level.
Replace `warnings.warn(ResourceWarning)` with `LOGGER.info` in `RabbitmqBroker.__del__` and `StorageBackend.__del__` so that unclosed-resource messages go through the logging system instead of the warnings machinery. Harden `CliHandler.emit`, `CliFormatter.format`, and `DBLogHandler.emit` against interpreter-shutdown scenarios where module globals may already be cleared.
All client (non-daemon) log output is now persisted to
``~/.aiida/log/aiida-{profile}.log`` using the same rotating
file handler as the daemon. Both handlers share a unified
``_add_log_file_handler`` helper controlled by ``logfile_loglevel``.
cacde89 to
e21e584
Compare
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.
This was produced by an agentic workflow from the design doc below. Please note that the design doc is not anymore up to date with the current commits. I further added a commit 03f2d5b to handle logging during a Python finalization. In this case certain functionalities of the logger are not available like styling so a reduced form of logging is taking place. Also a client logfile has been added in 01b3f81 (when interacting with aiida through python or verdi). When dogfooding we realized that the client logfile also contains the verdi status outputs. We might not want to include it. I am not sure exactly how to exclude it but lets see if the logfiles become to big because of this.
Context
AiiDA's current logging exposes 11 individual
logging.*_logleveloptions to all users. Most users don't need this granularity. Terminal output and daemon log output are fully coupled — there is no way to write more detail to the daemon log file while keeping the terminal clean. The REPORT level (workflow progress viaself.report()) is stored in the DB viaDBLogHandler; this is correct but not well communicated to workflow developers.Goals:
--advancedverdi process reportby defaultDesign
Two separate concerns, clearly separated:
Source control (what messages are generated) → existing advanced options
logging.aiida_loglevel,logging.plumpy_loglevel, etc.These gate what messages exist. Unchanged semantics, just hidden from default view.
Routing control (where messages go) → two new simple options
logging.terminal_loglevel— additional handler-level filter for all terminal outputlogging.system_loglevel— additional handler-level filter for daemon log file outputThese are handler-level filters, not source-level. If
aiida_loglevel=REPORT(default) andsystem_loglevel=INFO, no extra INFO messages appear in the daemon log because the logger already blocked them. An advanced user who wants INFO in the daemon log sets BOTHaiida_loglevel=INFO(source) ANDsystem_loglevel=INFO(routing), which cleanly routes INFO to file whileterminal_loglevel=REPORTkeeps the terminal uncluttered.logging.terminal_loglevelis the persistent equivalent ofverdi --verbosity. The-vflag remains a per-command override.Scenario Trace (verified)
verdi process listverdi -v debug process listPrototype validity confirmed (PoC run 2026-04-03):
evaluate_logging_configuration()recurses into allMappingobjects including handler configs, so lambdas inside handler dicts ARE evaluated. ✓ (verified by running the exact function with a test config — lambda insidehandlers.console.levelwas called and resolved to'REPORT')dictConfigsupports alevelkey on handlers (callshandler.setLevel()). ✓ (verified: logger set to DEBUG, handler set to WARNING via dictConfig — INFO messages blocked, WARNING messages passed)Field(json_schema_extra={'advanced': True})propagatesadvanced: Trueintomodel_json_schema()['properties'][field_name]. ✓ (verified: the key appears in the schema dict and is absent for fields without it)get_config_optionis imported inside thewith_ormblock (line 236 oflog.py), which runs after the daemon handler is constructed (line 198). Phase 2b must add its ownfrom aiida.manage.configuration import get_config_optionat the top of the daemon block — the plan already shows this. ✓Phase 1: New Config Options + Advanced Flag
1a. Add two new fields to
ProfileOptionsSchemaFile:
src/aiida/manage/configuration/config.pyAdd before the existing logging fields:
Both default to REPORT → no behavior change for existing installations.
1b. Mark all 11 existing individual logging options as advanced
File:
src/aiida/manage/configuration/config.pyAdd
json_schema_extra={'advanced': True}to each of the 11logging__*_loglevelfields:Also update the description of
logging__verdi_loglevel: it currently says'Minimum level to log to console when running a verdi command', which implies it controls terminal output. After this change, terminal routing is controlled byterminal_loglevel;verdi_loglevelis a source filter only. Change to:'Minimum source log level for the verdi logger.'Note:
logging__circus_loglevelis a pre-existing dead option — nocircuslogger is configured inget_logging_config(). Mark it advanced like the others; do not wire it up (out of scope).1c. Add
advancedproperty toOptionFile:
src/aiida/manage/configuration/options.py— add after theglobal_onlyproperty (line 53):_schemais the dict fromGlobalOptionsSchema.model_json_schema()['properties'][option_name](line 103 in options.py). Pydantic propagatesjson_schema_extrafields into that dict, soself._schema.get('advanced', False)returnsTruefor any field marked withjson_schema_extra={'advanced': True}.1d. Add
--advancedflag toverdi config listFile:
src/aiida/cmdline/commands/cmd_config.pyverdi_config_listis defined at line 35. Three changes:Add a click option decorator before the existing
@click.pass_contextat line 34:@click.option('--advanced', is_flag=True, help='Show all options including advanced per-logger settings.')And add
advanced: boolto the function signature.Add
option.advanced and not advancedto both list comprehensions (lines 60–64 and 67–71) that build thetable.option_valuesis a dict of{name: (Option, source, value)}, so add:After
echo.echo(tabulate(...))at line 76, print a hint when advanced options are hidden:Tests:
tests/cmdline/commands/test_config.py— any test that asserts logging options appear in the defaultverdi config listoutput will fail after this change. Update those assertions to either pass--advancedor check for the footer hint instead.Phase 2: Routing Filters
File:
src/aiida/common/log.pyBackground: two terminal handlers, one daemon handler
AiiDA uses three output destinations, each with its own Python logging handler:
log.pyline 88–94)consolelogging.StreamHandler→ stdoutcliaiida.cmdline.utils.log.CliHandler→ styled stdoutverdicommand is running (CLI_ACTIVE is True)daemon_log_filelogging.handlers.RotatingFileHandler→ log fileconsoleandcliare not two loggers — they are two handlers for the same loggers.configure_logging()lines 218–223 switch every logger fromconsoletocliwhen a verdi command is active.Currently none of these handlers has a
levelset, so they pass every record through without filtering. The routing feature adds handler-level filtering so the destination can be independently controlled.2a. (NEW FEATURE) Add
terminal_loglevelas a handler-level filter onconsoleandcliIn
get_logging_config()(src/aiida/common/log.pylines 88–94), both terminal handlers currently have nolevelkey. Add one to each:The lambda is evaluated by
evaluate_logging_configuration()(src/aiida/common/log.pylines 149–166), which recursively evaluates all lambdas in the config dict — including inside thehandlerssub-dict. The resolved string (e.g.'REPORT') is then passed todictConfig, which callshandler.setLevel('REPORT').2b. (NEW FEATURE) Add
system_loglevelas a handler-level filter on the daemon log handlerIn
configure_logging()(src/aiida/common/log.pylines 197–206), the daemon file handler is constructed directly in Python code (not inside the config dict), so we callget_config_optiondirectly rather than using a lambda. Line 199 currently hardcodes'level': 'DEBUG'; replace it:2c. (BUG FIX required by 2a) Make
--verbosityalso override theclihandler levelverdi --verbosity DEBUG process listsetsCLI_LOG_LEVEL = 'DEBUG'. The existing block atsrc/aiida/common/log.pylines 229–232 lowers the source logger levels foraiida,verdi, anddisk_objectstoreto DEBUG — so those loggers now emit DEBUG records. But after Phase 2a, theclihandler hasterminal_loglevel(default'REPORT') set on it, which will now block those DEBUG records before they reach the terminal.Fix: add one line to the existing
CLI_LOG_LEVELblock to also lower theclihandler level:No other changes to
configure_logging().Phase 3: Promote CalcJob Diagnostic INFO → WARNING
File:
src/aiida/engine/processes/calcjobs/calcjob.pyThese 3 messages go through the CalcJob node logger (with
dbnode_id). Currently INFO so they miss the DB atdb_loglevel=REPORTdefault and don't appear inverdi process report. Promoting to WARNING fixes this:'could not parse scheduler output: thedetailed_job_infoattribute is missing'→ WARNING'could not parse scheduler output: return value ofdetailed_job_infois non-zero'→ WARNINGf'{scheduler.class.name}does not implement scheduler output parsing'→ keep INFO (feature notice, not a problem)db_loglevelstays REPORT default, stays advanced. The threshold is correct: REPORT (23) ≥ captures REPORT + WARNING + ERROR.Phase 4: Log Level Audit — INFO → DEBUG
Demote all verbose operational INFO calls to DEBUG. These messages are internal machinery detail (transport steps, scheduler interactions, state transitions) that users don't need to see by default.
Move to DEBUG
Grep for
logger.info(in each file and demote all calls that describe routine internal steps — not errors, warnings, or significant operational events:src/aiida/engine/processes/calcjobs/tasks.py(~20 calls): all transport task step messages (upload, submit, update, retrieve, stash, kill progress messages)src/aiida/engine/processes/calcjobs/manager.py:'waiting for transport','successfully retrieved status of active jobs'src/aiida/engine/processes/calcjobs/monitors.py:'Monitor returned: ...'src/aiida/engine/processes/calcjobs/calcjob.py: scheduler timing info noticesrc/aiida/engine/processes/process.py:'Loaded process from saved state','no controller/connection to kill child'src/aiida/engine/processes/workchains/workchain.py:'received callback that awaitable has terminated'src/aiida/engine/processes/workchains/restart.py:'output was already attached, skipping'src/aiida/engine/runners.py:'adding subscriber for broadcasts'src/aiida/schedulers/plugins/slurm.py: job submission and status poll messagessrc/aiida/schedulers/plugins/sge.py: job submission and status poll messagessrc/aiida/schedulers/plugins/pbsbaseclasses.py: job submission and status poll messagessrc/aiida/schedulers/plugins/direct.py: job submission and status poll messagessrc/aiida/schedulers/plugins/lsf.py: job submission and status poll messagessrc/aiida/brokers/rabbitmq/defaults.py: broker connection step messagessrc/aiida/parsers/plugins/diff_tutorial/parsers.py: tutorial parser step messagessrc/aiida/orm/nodes/data/code/portable.py: portable code copy step messagesrc/aiida/storage/psql_dos/backend.py: one internal step message (keep maintenance operation messages as INFO)Keep as INFO (significant operational events worth surfacing)
src/aiida/engine/daemon/worker.py: daemon lifecycle (start/stop/signal)src/aiida/engine/runners.py: process confirmed terminated by pollingsrc/aiida/engine/processes/process.py: kill request received, kill signal unable to reach childsrc/aiida/engine/processes/control.py: continue message receivedsrc/aiida/engine/processes/launcher.py: process already terminatedsrc/aiida/storage/psql_dos/backend.py: maintenance operations (backup, vacuum, migrate)src/aiida/schedulers/plugins/direct.py: configuration noticesrc/aiida/transports/ssh_async.py: auth script successFiles Modified (Summary)
src/aiida/manage/configuration/config.pysrc/aiida/manage/configuration/options.pyadvancedpropertysrc/aiida/cmdline/commands/cmd_config.py--advancedflag; filter optionssrc/aiida/common/log.py--verbosityalso overrides cli handler levelsrc/aiida/engine/processes/calcjobs/calcjob.pysrc/aiida/engine/processes/calcjobs/tasks.pysrc/aiida/engine/processes/calcjobs/manager.pysrc/aiida/engine/processes/calcjobs/monitors.pysrc/aiida/engine/processes/process.pysrc/aiida/engine/processes/workchains/workchain.pysrc/aiida/engine/processes/workchains/restart.pysrc/aiida/engine/runners.pysrc/aiida/schedulers/plugins/slurm.pysrc/aiida/schedulers/plugins/sge.pysrc/aiida/schedulers/plugins/pbsbaseclasses.pysrc/aiida/schedulers/plugins/direct.pysrc/aiida/schedulers/plugins/lsf.pysrc/aiida/brokers/rabbitmq/defaults.pysrc/aiida/parsers/plugins/diff_tutorial/parsers.pysrc/aiida/orm/nodes/data/code/portable.pysrc/aiida/storage/psql_dos/backend.pyCommit Plan
Four commits, one per phase. Each is self-contained and bisectable.
Follows project conventions: emoji prefix, imperative mood, 50/72 rule.
Commit 1 — Phase 1
Files:
config.py,options.py,cmd_config.py,test_config.pyCommit 2 — Phase 2
Files:
src/aiida/common/log.pyCommit 3 — Phase 3
Files:
src/aiida/engine/processes/calcjobs/calcjob.pyCommit 4 — Phase 4
Files: all Phase 4 files listed in Files Modified table
Verification
verdi config listshows exactly 2 logging options:logging.terminal_loglevelandlogging.system_loglevelverdi config list --advancedshows all 13 logging optionsverdi -v debug process liststill works (debug messages appear in terminal)aiida_loglevel=INFO+system_loglevel=INFOroutes INFO to daemon log; terminal still shows REPORT+verdi process report <pk>shows the promoted WARNING messages for scheduler output parse failurespytest tests/cmdline/commands/test_config.py(update assertions for hidden options)pytest tests/common/test_logging.py