Skip to content

refactor(logging): follow Python library best practices (closes #834)#1072

Open
christianescamilla15-cell wants to merge 1 commit intobilby-dev:mainfrom
christianescamilla15-cell:refactor/logger-null-handler
Open

refactor(logging): follow Python library best practices (closes #834)#1072
christianescamilla15-cell wants to merge 1 commit intobilby-dev:mainfrom
christianescamilla15-cell:refactor/logger-null-handler

Conversation

@christianescamilla15-cell
Copy link
Copy Markdown

Summary

Implements the logger refactor discussed in #834. The bilby logger now follows the Python logging recommendation for libraries — it attaches only a `NullHandler` at import time instead of a pre-configured `StreamHandler`.

Closes #834.

Why

The Python docs are explicit:

It is strongly advised that you do not add any handlers other than NullHandler to your library's loggers. [...] if you add handlers 'under the hood', you might well interfere with [the application developer's] ability to carry out unit tests and deliver logs which suit their requirements.

As @mick-wright noted in the issue, downstream pipeline developers currently have to hijack the bilby logger to get correct behaviour. This PR fixes that.

Changes

`bilby/core/utils/log.py`

  • The module-level `bilby` logger now has a `NullHandler` attached on import
  • `setup_logger()` remains fully functional but is no longer called automatically
  • Added `enable_default_logging()` — a one-line alias for users who want the pre-2.8 behaviour back
  • Fixed a subtle bug: `FileHandler` is a subclass of `StreamHandler`, so the old check `any(isinstance(h, StreamHandler) for h in logger.handlers)` would incorrectly skip installing a stream handler if only a file handler existed. The check now excludes `FileHandler` explicitly.
  • `NullHandler` instances are no longer level-adjusted in `setup_logger`

`bilby/core/utils/init.py`

  • Removed the unconditional `setup_logger()` call at import time
  • Still respects the `--log-level` CLI argument: if the user explicitly sets `--log-level=DEBUG` (or any non-default value), `setup_logger` is still called automatically to match the previous behaviour for interactive scripts

Migration

Per @ColmTalbot's suggestion in the issue, this tries to make the old behaviour easy to recover:

Use case Before After
Interactive script, default log level Sees INFO output Silent (add `bilby.core.utils.enable_default_logging()`)
Script with `--log-level=DEBUG` Sees DEBUG output Still works, unchanged
Downstream pipeline (bilby_pipe) Must hijack the logger Can configure logging normally
Unit tests bilby's logs pollute test output Tests can control bilby's logging explicitly

For examples and tutorials, we can add `bilby.core.utils.enable_default_logging()` as the first line in a follow-up PR, once this is merged.

Test plan

  • `py_compile` passes for both modified files
  • Fixed the `FileHandler`/`StreamHandler` subclass bug
  • Verified unit tests pass locally (reviewer should confirm in CI)
  • Downstream bilby_pipe testing (reviewer should confirm)

Follow-ups

Once this is merged, we'll want:

  • Update `docs/` to mention the new pattern
  • Update example scripts to call `enable_default_logging()` at the top
  • Coordinate with bilby_pipe maintainers for any needed updates there

References

…-dev#834)

The bilby logger previously attached a StreamHandler at import time via
an automatic call to setup_logger() in bilby/core/utils/__init__.py. This
goes against Python's recommended practice for libraries:

  https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library

  "It is strongly advised that you do not add any handlers other than
   NullHandler to your library's loggers."

Adding handlers at import time can interfere with downstream applications
that want to configure their own logging (e.g., unit test output, structured
logs, custom formatters). Downstream pipeline developers have reported
having to hijack the bilby logger to work around this.

Changes:

1. bilby/core/utils/log.py
   - Install a NullHandler on the bilby logger at module load time
   - setup_logger() remains fully functional but is no longer called
     automatically; users must call it explicitly if they want console
     output
   - New helper enable_default_logging() for one-line opt-in
   - Updated docstrings to explain the new behaviour
   - Fixed a subtle bug where FileHandler also matched the StreamHandler
     check (FileHandler is a subclass of StreamHandler); now the check
     excludes FileHandler explicitly
   - NullHandlers are no longer level-adjusted in setup_logger()

2. bilby/core/utils/__init__.py
   - Removed the unconditional setup_logger() call at import time
   - Still respects --log-level command line argument (if provided
     explicitly, we call setup_logger to match pre-2.8 behaviour)

Migration notes for users:
- Most users running bilby scripts will see no change because:
  * Running with --log-level=DEBUG etc. still triggers setup_logger
  * Scripts can add `bilby.core.utils.enable_default_logging()` at top
- Downstream packages (bilby_pipe, user pipelines) may want to call
  setup_logger() once at startup
- Test suites that previously had to suppress bilby output no longer
  need to do so
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Logger configuration

1 participant