From 6ce209d1845fde3b7da116ed8905a4a8577865a3 Mon Sep 17 00:00:00 2001 From: Christian Hernandez Date: Fri, 10 Apr 2026 21:53:41 -0600 Subject: [PATCH] refactor(logging): follow Python library best practices (closes #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 --- CHANGELOG.md | 6 ++++ bilby/core/utils/__init__.py | 14 ++++++-- bilby/core/utils/log.py | 66 ++++++++++++++++++++++++++++++------ 3 files changed, 74 insertions(+), 12 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 16c762f38..7edcb0555 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,12 @@ The original MRs are only visible on the [LIGO GitLab repository](https://git.li ## [Unreleased] +### Changes +* The `bilby` logger no longer installs a `StreamHandler` at import time. It now has only a `NullHandler` attached, following the Python logging recommendation for libraries. To restore the previous behaviour, call `bilby.core.utils.setup_logger()` or `bilby.core.utils.enable_default_logging()` explicitly in your script (closes #834) + +### Additions +* Added `enable_default_logging()` as a one-line convenience for downstream scripts that want the pre-2.8 logging behaviour + ## [2.7.1] ### Fixes diff --git a/bilby/core/utils/__init__.py b/bilby/core/utils/__init__.py index 4b17c2b6c..fe6cd2e53 100644 --- a/bilby/core/utils/__init__.py +++ b/bilby/core/utils/__init__.py @@ -18,5 +18,15 @@ # Instantiate the default argument parser at runtime command_line_args, command_line_parser = set_up_command_line_arguments() -# Instantiate the default logging -setup_logger(print_version=False, log_level=command_line_args.log_level) + +# As of bilby 2.8, we follow the Python logging recommendation for +# libraries and do NOT install a StreamHandler at import time. The +# ``bilby`` logger has only a NullHandler attached (see log.py). This +# avoids interfering with downstream applications that want to manage +# their own logging configuration. +# +# If the user runs bilby with a ``--log-level`` command-line argument we +# honour it by calling :func:`setup_logger` explicitly, matching the +# pre-2.8 behaviour for scripts that rely on this pattern. +if command_line_args.log_level != 'INFO': + setup_logger(print_version=False, log_level=command_line_args.log_level) diff --git a/bilby/core/utils/log.py b/bilby/core/utils/log.py index b6c45152b..7146cc379 100644 --- a/bilby/core/utils/log.py +++ b/bilby/core/utils/log.py @@ -5,22 +5,40 @@ import sys from importlib import metadata +#: The ``bilby`` library logger. Following the recommended practice for +#: libraries (https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library), +#: this logger only has a :class:`logging.NullHandler` attached by default, +#: so bilby does not emit any log records unless the application importing +#: bilby has configured logging itself. To restore the previous bilby +#: behaviour (a formatted stream handler writing to stderr), call +#: :func:`setup_logger` or :func:`enable_default_logging` explicitly. logger = logging.getLogger('bilby') +logger.addHandler(logging.NullHandler()) def setup_logger(outdir='.', label=None, log_level='INFO', print_version=False): - """ Setup logging output: call at the start of the script to use + """Configure bilby's logger with a stream handler (and optional file handler). + + This installs a :class:`logging.StreamHandler` on the bilby logger with + a timestamped formatter, and optionally a :class:`logging.FileHandler` + writing to ``outdir/label.log``. Calling ``setup_logger`` is now + **optional** — since bilby 2.8, the library attaches only a + :class:`logging.NullHandler` by default, per the Python logging + recommendations for libraries. Call this function from your script + (or use :func:`enable_default_logging`) if you want bilby log records + to appear on the console. Parameters ========== outdir, label: str - If supplied, write the logging output to outdir/label.log - log_level: str, optional - ['debug', 'info', 'warning'] - Either a string from the list above, or an integer as specified - in https://docs.python.org/2/library/logging.html#logging-levels + If supplied, write the logging output to ``outdir/label.log``. + log_level: str or int, optional + One of ``['debug', 'info', 'warning', 'error', 'critical']`` (case + insensitive), or an integer as specified in + https://docs.python.org/3/library/logging.html#logging-levels print_version: bool - If true, print version information + If ``True``, print the bilby version information after configuring + the logger. """ if isinstance(log_level, str): @@ -35,14 +53,17 @@ def setup_logger(outdir='.', label=None, log_level='INFO', print_version=False): logger.propagate = False logger.setLevel(level) - if not any([isinstance(h, logging.StreamHandler) for h in logger.handlers]): + if not any( + isinstance(h, logging.StreamHandler) and not isinstance(h, logging.FileHandler) + for h in logger.handlers + ): stream_handler = logging.StreamHandler() stream_handler.setFormatter(logging.Formatter( '%(asctime)s %(name)s %(levelname)-8s: %(message)s', datefmt='%H:%M')) stream_handler.setLevel(level) logger.addHandler(stream_handler) - if not any([isinstance(h, logging.FileHandler) for h in logger.handlers]): + if not any(isinstance(h, logging.FileHandler) for h in logger.handlers): if label: Path(outdir).mkdir(parents=True, exist_ok=True) log_file = '{}/{}.log'.format(outdir, label) @@ -54,13 +75,38 @@ def setup_logger(outdir='.', label=None, log_level='INFO', print_version=False): logger.addHandler(file_handler) for handler in logger.handlers: - handler.setLevel(level) + if not isinstance(handler, logging.NullHandler): + handler.setLevel(level) if print_version: version = get_version_information() logger.info('Running bilby version: {}'.format(version)) +def enable_default_logging(log_level='INFO'): + """Convenience alias for :func:`setup_logger` with default arguments. + + This is a one-line way for downstream scripts, pipelines, or tutorials + to restore the pre-2.8 behaviour where bilby automatically emitted log + records to stderr. + + Parameters + ========== + log_level: str or int, optional + Log level, defaults to ``'INFO'``. See :func:`setup_logger` for + accepted values. + + Examples + ======== + .. code-block:: python + + import bilby + bilby.core.utils.enable_default_logging() + # bilby will now print its INFO-level log messages to stderr + """ + setup_logger(log_level=log_level) + + def get_version_information(): from bilby import __version__ return __version__