From 92804f98002b4bd5fde62355a776909ea67997a8 Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:40:58 +0200 Subject: [PATCH 1/7] Do not configure logging when pyprep is imported 0.8.0 attached a handler on sys.stdout to the pyprep logger at import time, so everyone got INFO output for free. That is a decision a library cannot make: it does not know whether the application wants stdout, a file, JSON to an aggregator, or a Rich console. Hand it back to the caller. No NullHandler goes in its place, deliberately. A NullHandler satisfies the handler search in logging.Logger.callHandlers, which stops logging.lastResort from firing and would drop warnings and errors instead of merely hiding INFO. pyprep is now quiet, but not silent: without any configuration warnings and errors still reach stderr, and INFO appears once the caller asks for it. setup_logging gains that shape too. It always installs a fresh handler on the stream it was given rather than reusing a previously installed one, takes the stream and a new format string as keyword-only arguments, accepts level names in any case like mne.set_log_level, and returns the logger it configured. The propagate argument is gone: it existed to undo the import-time configuration, and with nothing configured on import, propagation is simply what happens when setup_logging is never called. Changing the level is the job of the new set_log_level, which mirrors mne.set_log_level and touches nothing but the level, so an application that routes pyprep's records through its own handlers can turn the package up without losing the stream, the format and the propagation it chose. The autouse fixture that flipped propagate for the test session goes away with the import-time call it was working around; caplog now works out of the box. --- pyprep/__init__.py | 6 +- pyprep/_logging.py | 128 +++++++++++++++++++++++++----------- tests/conftest.py | 18 ------ tests/test_logging.py | 146 ++++++++++++++++++++++++++++-------------- 4 files changed, 189 insertions(+), 109 deletions(-) diff --git a/pyprep/__init__.py b/pyprep/__init__.py index 2b6b22b..64e8d0f 100644 --- a/pyprep/__init__.py +++ b/pyprep/__init__.py @@ -4,15 +4,11 @@ # SPDX-License-Identifier: MIT import pyprep.ransac as ransac # noqa: F401 -from pyprep._logging import setup_logging # noqa: F401 +from pyprep._logging import set_log_level, setup_logging # noqa: F401 from pyprep.find_noisy_channels import NoisyChannels # noqa: F401 from pyprep.prep_pipeline import PrepPipeline # noqa: F401 from pyprep.reference import Reference # noqa: F401 -# Loud by default, like MNE. Applications turn it down with -# setup_logging("WARNING") or take over the output with setup_logging(propagate=True). -setup_logging() - try: from importlib.metadata import version diff --git a/pyprep/_logging.py b/pyprep/_logging.py index 507c24f..ec9e13c 100644 --- a/pyprep/_logging.py +++ b/pyprep/_logging.py @@ -6,57 +6,109 @@ import logging import sys -_FORMAT = "%(asctime)s [%(levelname)s] %(name)s: %(message)s" -_LOGGER_NAME = "pyprep" +LOGGER_NAME = "pyprep" +DEFAULT_FORMAT = "%(asctime)s [%(levelname)s] %(name)s: %(message)s" class _StreamHandler(logging.StreamHandler): - """Marker subclass identifying the handler that pyprep installed.""" + """Marker subclass identifying the handler that this package installed.""" -def setup_logging(level="INFO", stream=None, propagate=False): - """Configure the ``pyprep`` logger. +def _as_level(level): + """Accept a name in any case, or a stdlib constant like logging.DEBUG.""" + return level.upper() if isinstance(level, str) else level - This is called at import time with its defaults, so pyprep logs at ``"INFO"`` - to :data:`sys.stdout` without any setup. Call it again to change that. + +def set_log_level(level, return_old_level=False): + """Change the level of the ``pyprep`` logger, leaving its handlers alone. + + Use this rather than :func:`pyprep.setup_logging` to turn the package up or + down: :func:`pyprep.setup_logging` also decides *where* the records go, so + calling it again just to change the level would reset the stream, the format, + and the propagation that an application had chosen. + + Parameters + ---------- + level : int | str + Level for the ``pyprep`` logger, either a name (e.g. ``"debug"``, + ``"WARNING"``) or a stdlib constant such as :data:`logging.DEBUG`. Names + are case-insensitive, as in :func:`mne.set_log_level`. + return_old_level : bool + Whether to return the level the logger had before this call, so that a + caller can put it back afterwards. Defaults to ``False``. + + Returns + ------- + old_level : int | None + The previous level of the ``pyprep`` logger if ``return_old_level`` is + ``True``, and ``None`` otherwise. + + Notes + ----- + This cannot make records appear on its own. Until :func:`pyprep.setup_logging` + has run, or the application has configured a logger that this one propagates + to, there is no handler to write them. + """ + logger = logging.getLogger(LOGGER_NAME) + old_level = logger.level + logger.setLevel(_as_level(level)) + if return_old_level: + return old_level + + +def setup_logging(level="info", *, stream=None, fmt=DEFAULT_FORMAT): + """Send pyprep's log records to a stream, at the given level. + + If your application already routes logging somewhere of its own, do not call + this at all. The records will reach your handlers by propagation, and + :func:`pyprep.set_log_level` is there if you want the ``"INFO"`` ones too. Parameters ---------- level : int | str - Level for the ``pyprep`` logger. Pass ``"WARNING"`` to keep only warnings - and errors, or ``"DEBUG"`` for more detail. Defaults to ``"INFO"``. + Level for the ``pyprep`` logger, either a name (e.g. ``"debug"``, + ``"WARNING"``) or a stdlib constant such as :data:`logging.DEBUG`. Names + are case-insensitive, as in :func:`mne.set_log_level`. Defaults to + ``"info"``. stream : file-like | None - Destination for pyprep's own handler. ``None`` keeps the current - destination, which is :data:`sys.stdout` on a fresh interpreter. Ignored - when ``propagate`` is ``True``. - propagate : bool - ``False`` (the default) prints through pyprep's own handler and stops the - records there, so an application that configures the root logger does not - see them twice. ``True`` removes that handler and passes the records to - ancestor loggers instead, letting the application's own handlers format - and route them. + Destination for pyprep's handler. ``None`` means :data:`sys.stdout`. + fmt : str + Format string for the handler, in the style of :class:`logging.Formatter`. + Defaults to ``pyprep._logging.DEFAULT_FORMAT``, which prefixes each + record with a timestamp, its level, and the name of the logger it came + from. + + Returns + ------- + logger : logging.Logger + The configured ``pyprep`` logger. Notes ----- - Only the ``pyprep`` namespace is configured; the root logger is never touched. + Only the ``pyprep`` namespace is configured; the root logger is never + touched. Records stop at pyprep's own handler, so an application that + configures the root logger does not see them twice. To hand the output back, + drop the handler again with + ``logging.getLogger("pyprep").handlers.clear()``. + MNE has its own ``mne`` logger, controlled separately through - :func:`mne.set_log_level`. Before pyprep 0.8.0 several pyprep modules logged - through MNE's logger, so ``mne.set_log_level`` used to silence them; use this - function instead. + :func:`mne.set_log_level`. The progress bar that window-wise RANSAC draws is + an ``mne.utils.ProgressBar``, which writes to its own stream rather than + through either logger, so neither function silences it. """ - logger = logging.getLogger(_LOGGER_NAME) - logger.setLevel(level) - own = [h for h in logger.handlers if isinstance(h, _StreamHandler)] - if propagate: - for handler in own: - logger.removeHandler(handler) - handler.close() - elif own: - if stream is not None: - for handler in own: - handler.setStream(stream) - else: - handler = _StreamHandler(stream or sys.stdout) - handler.setFormatter(logging.Formatter(_FORMAT)) - logger.addHandler(handler) - logger.propagate = propagate + logger = logging.getLogger(LOGGER_NAME) + logger.setLevel(_as_level(level)) + + # Repeated calls swap our handler out instead of stacking a new one on top. The + # marker subclass is what makes ours identifiable: a plain isinstance check + # against logging.StreamHandler would also match a FileHandler that the + # application attached to this logger, and we would remove and close it. + for handler in [h for h in logger.handlers if isinstance(h, _StreamHandler)]: + logger.removeHandler(handler) + handler.close() + + handler = _StreamHandler(sys.stdout if stream is None else stream) + handler.setFormatter(logging.Formatter(fmt)) + logger.addHandler(handler) + logger.propagate = False + return logger diff --git a/tests/conftest.py b/tests/conftest.py index 28d9d28..d9aadd9 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -3,30 +3,12 @@ # Authors: The PyPREP developers # SPDX-License-Identifier: MIT -import logging - import mne import numpy as np import pytest from mne.datasets import eegbci -@pytest.fixture(autouse=True) -def configure_pyprep_logging(): - """Quiet pyprep's own INFO output and let ``caplog`` capture its records. - - pyprep configures its logger at import time with ``propagate = False``, which - keeps records away from the root-level handler that ``caplog`` installs. - """ - logger = logging.getLogger("pyprep") - level, propagate = logger.level, logger.propagate - logger.setLevel("WARNING") - logger.propagate = True - yield - logger.setLevel(level) - logger.propagate = propagate - - @pytest.fixture(scope="session") def montage(): """Fixture for standard EEG montage.""" diff --git a/tests/test_logging.py b/tests/test_logging.py index 43d9a1d..c2f5658 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -10,75 +10,125 @@ import pytest -from pyprep import setup_logging -from pyprep._logging import _StreamHandler - -# Emitted from a clean interpreter, so the logger state of this test session -# cannot influence what is observed. -_FRESH = ( - "import logging, pyprep; " - "logging.getLogger('pyprep.mod').info('hello'); " - "print('root handlers:', logging.getLogger().handlers)" -) +import pyprep +from pyprep._logging import LOGGER_NAME, _StreamHandler @pytest.fixture -def restore_logger(): - """Restore the pyprep logger after a test reconfigured it.""" - logger = logging.getLogger("pyprep") - handlers, level, propagate = logger.handlers[:], logger.level, logger.propagate +def logger(): + """Hand out the package logger and undo whatever the test did to it.""" + logger = logging.getLogger(LOGGER_NAME) + level, propagate, handlers = logger.level, logger.propagate, logger.handlers[:] yield logger logger.handlers[:] = handlers logger.setLevel(level) logger.propagate = propagate -def _run_fresh(): - """Import pyprep in a clean interpreter and return its output.""" +def _run(code): + """Run a snippet in a clean interpreter, where logging state is untouched.""" return subprocess.run( - [sys.executable, "-c", _FRESH], capture_output=True, text=True, check=True + [sys.executable, "-c", code], capture_output=True, text=True, check=True + ) + + +def _child(name=LOGGER_NAME): + return logging.getLogger(f"{name}.a_module") + + +def test_import_configures_nothing(): + """Importing the package installs no handler and leaves the root logger alone.""" + done = _run( + "import logging, pyprep;" + "print(logging.getLogger('pyprep').handlers, logging.getLogger().handlers)" ) + assert done.stdout.strip() == "[] []" -def test_visible_by_default(): - """Test that importing pyprep is enough to see its log messages.""" - completed = _run_fresh() - assert "[INFO] pyprep.mod: hello" in completed.stdout - assert "hello" not in completed.stderr +def test_warning_is_visible_without_any_configuration(): + """A warning reaches the user even when setup_logging was never called. + + A NullHandler on the package logger would satisfy the handler search in + ``logging.Logger.callHandlers``, which stops ``logging.lastResort`` from + firing and silently drops warnings and errors instead of only hiding INFO. + """ + done = _run( + "import logging, pyprep;" + "logging.getLogger('pyprep.a_module').warning('the warning')" + ) + assert "the warning" in done.stderr -def test_root_logger_untouched(): - """Test that pyprep does not configure the root logger.""" - completed = _run_fresh() - assert "root handlers: []" in completed.stdout +def test_setup_logging_writes_formatted_records(logger): + """The records land on the given stream, with the level and logger name.""" + stream = io.StringIO() + pyprep.setup_logging(stream=stream) + _child().info("hello") + assert "[INFO] pyprep.a_module: hello" in stream.getvalue() -def test_setup_logging_level(restore_logger): - """Test that the level set by setup_logging is respected.""" +def test_setup_logging_level_filters(logger): + """A higher level keeps warnings and drops INFO.""" stream = io.StringIO() - setup_logging(level="WARNING", stream=stream) - logger = logging.getLogger("pyprep.mod") - logger.info("invisible") - logger.warning("visible") - assert "invisible" not in stream.getvalue() - assert "visible" in stream.getvalue() + pyprep.setup_logging("warning", stream=stream) + _child().info("dropped") + _child().warning("kept") + assert "dropped" not in stream.getvalue() + assert "kept" in stream.getvalue() + +@pytest.mark.parametrize("level", ["warning", "WARNING", "Warning", logging.WARNING]) +def test_level_spelling(logger, level): + """Level names are accepted in any case, and stdlib constants work too.""" + pyprep.setup_logging(level, stream=io.StringIO()) + assert logger.level == logging.WARNING -def test_setup_logging_is_idempotent(restore_logger): - """Test that repeated setup_logging calls do not duplicate output.""" + +def test_setup_logging_is_idempotent(logger): + """Repeated calls swap the handler out rather than stacking another one on.""" stream = io.StringIO() - setup_logging(stream=stream) - n_handlers = len(restore_logger.handlers) - setup_logging(stream=stream) - logging.getLogger("pyprep.mod").info("once") - assert len(restore_logger.handlers) == n_handlers + for _ in range(3): + pyprep.setup_logging(stream=stream) + assert len([h for h in logger.handlers if isinstance(h, _StreamHandler)]) == 1 + _child().info("once") assert stream.getvalue().count("once") == 1 -def test_setup_logging_propagate_hands_over(restore_logger, caplog): - """Test that propagate=True lets an application handle the records.""" - setup_logging(propagate=True) - assert not [h for h in restore_logger.handlers if isinstance(h, _StreamHandler)] - with caplog.at_level(logging.INFO, logger="pyprep.mod"): - logging.getLogger("pyprep.mod").info("handed over") - assert "handed over" in caplog.text +def test_setup_logging_keeps_a_handler_it_did_not_install(logger): + """An application's own handler on this logger survives, and still gets records.""" + app_stream = io.StringIO() + app_handler = logging.StreamHandler(app_stream) + app_handler.setFormatter(logging.Formatter("%(message)s")) + logger.addHandler(app_handler) + + pyprep.setup_logging(stream=io.StringIO()) + _child().info("seen by both") + + assert app_handler in logger.handlers + assert app_stream.getvalue() == "seen by both\n" + + +def test_set_log_level_changes_only_the_level(logger): + """The handler, its stream and its format survive a level change.""" + stream = io.StringIO() + pyprep.setup_logging("info", stream=stream, fmt="%(message)s") + handler = logger.handlers[-1] + + old_level = pyprep.set_log_level("warning", return_old_level=True) + assert old_level == logging.INFO + assert logger.handlers[-1] is handler + assert handler.stream is stream + assert handler.formatter._fmt == "%(message)s" + + _child().info("dropped") + _child().warning("kept") + pyprep.set_log_level(old_level) + _child().info("kept again") + assert stream.getvalue() == "kept\nkept again\n" + + +def test_set_log_level_returns_nothing_by_default(logger): + """The previous level is handed back only when it is asked for.""" + pyprep.setup_logging("info", stream=io.StringIO()) + assert pyprep.set_log_level("warning") is None + assert logger.level == logging.WARNING From 3b00d057e508c84c888047e0062fff88630c9c3c Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:41:22 +0200 Subject: [PATCH 2/7] Document pyprep's logging The README and the API page describe quiet-by-default, the lastResort fallback that keeps warnings and errors visible with no configuration at all, and the two ways to ask for INFO: setup_logging for a script or a notebook, set_log_level for an application that already routes logging somewhere of its own. Both note that the progress bar drawn during window-wise RANSAC comes from MNE and writes to its own stream, so neither function silences it; without that it looks like a bug. CONTRIBUTING gains the conventions the library code follows, including why the NullHandler is absent and that _logging.py is kept in sync with copies in sibling projects. --- .github/CONTRIBUTING.md | 30 +++++++++++++++++++++++++++ README.rst | 45 +++++++++++++++++++++++++++++++++++++++++ docs/api.rst | 38 ++++++++++++++++++++++++++++++---- 3 files changed, 109 insertions(+), 4 deletions(-) diff --git a/.github/CONTRIBUTING.md b/.github/CONTRIBUTING.md index 49f74bf..1d0fe64 100644 --- a/.github/CONTRIBUTING.md +++ b/.github/CONTRIBUTING.md @@ -37,6 +37,36 @@ From the project root, call: - `pytest` to run tests and coverage - `pre-commit run -a` to run style checks (Ruff and some additional hooks) +## Logging conventions + +`pyprep` is a library, so it never decides where log records go. It configures +nothing on import, and library code must never configure the root logger, add a +handler, or touch another package's logger (including MNE's). Those are the +application's calls to make; `setup_logging` and `set_log_level` exist so that +the application can make them in one line. + +Note that we deliberately do *not* install a `NullHandler` on the `pyprep` +logger. A `NullHandler` satisfies the handler search in +`logging.Logger.callHandlers`, which stops `logging.lastResort` from firing and +would silently drop warnings and errors instead of merely hiding `"INFO"`. We +want quiet, not silent. `tests/test_logging.py` enforces both properties from a +clean interpreter. + +Within the library: + +- one `logger = logging.getLogger(__name__)` per module, at module level, so + records carry the module they came from +- never `print` from library code; user-facing output is the application's job +- pass arguments to the logging call (`logger.info("Found %s bads", n)`) rather + than formatting the string yourself, so the work is skipped when the level is + off +- log values with a label. A bare `logger.info(some_number)` produces an + unreadable line, and the examples render their log output into the docs + +`pyprep/_logging.py` is a verbatim copy of the same module in a few sibling +projects, save for the package name in `LOGGER_NAME` and the docstrings. If you +change its behavior, the copies need to stay in sync. + ## Building the documentation The documentation can be built using [Sphinx](https://www.sphinx-doc.org). diff --git a/README.rst b/README.rst index d98b184..a1fe4cb 100644 --- a/README.rst +++ b/README.rst @@ -76,6 +76,51 @@ all required dependencies automatically. The dependencies are defined in the ``pyproject.toml`` file under the ``dependencies`` and ``project.optional-dependencies`` sections. +Logging +======= + +``pyprep`` logs through the standard ``logging`` module, on a logger named +``pyprep``, and configures nothing on import. +It is quiet, but not silent: warnings and errors still reach ``stderr`` without +any setup, because Python falls back to ``logging.lastResort`` when it finds no +handler. +``"INFO"`` records, which is where the pipeline reports what it decided, stay +hidden until you ask for them. + +To see them without writing handler boilerplate, for example in a script or a +notebook: + +.. code-block:: python + + import pyprep + + pyprep.setup_logging("info") + +This attaches a handler on ``sys.stdout`` to the ``pyprep`` logger only, and +stops those records from propagating to the root logger so they are not printed +twice. +Pass ``"warning"`` to keep only warnings and errors, or ``"debug"`` for more +detail. + +If your application already routes logging somewhere of its own, a file or a +Rich console, do not call ``setup_logging`` at all. +The records reach your handlers by propagation, and ``set_log_level`` will raise +``pyprep``'s verbosity if you want the ``"INFO"`` ones too, without touching the +handler, the stream, the format, or the propagation your application chose: + +.. code-block:: python + + pyprep.set_log_level("info") + +To take the output back after calling ``setup_logging``, drop the handler again: + +.. code-block:: python + + logging.getLogger("pyprep").handlers.clear() + +MNE has its own ``mne`` logger, controlled separately through +``mne.set_log_level``. + Contributing ============ diff --git a/docs/api.rst b/docs/api.rst index 1430779..2d715f2 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -55,10 +55,39 @@ The :mod:`~pyprep.ransac` module Logging ======= -pyprep logs at ``"INFO"`` through its own ``pyprep`` logger, which is configured -when the package is imported. Use the function below to change the level, redirect -the stream, or hand the records to your application's own handlers. The root logger -is never configured. +pyprep logs through the standard :mod:`logging` module, on a logger named +``pyprep``, and — like any well-behaved library — configures nothing on import. +It is quiet, but not silent: with no configuration at all, warnings and errors +still reach :data:`sys.stderr`, because Python falls back to +:data:`logging.lastResort` when no handler is found. ``"INFO"`` records, which +is where the pipeline reports what it decided, are hidden until you ask for +them. + +There are two ways to ask. Interactively, :func:`~pyprep.setup_logging` +attaches a handler to the ``pyprep`` logger and stops those records from +propagating any further, so they are not printed twice: + +.. code-block:: python + + import pyprep + + pyprep.setup_logging("info") + +In an application that already routes logging somewhere of its own — a file, a +JSON aggregator, a Rich console — do not call it at all. The records reach your +handlers by propagation, and :func:`~pyprep.set_log_level` raises pyprep's +verbosity without touching the handler, the stream, the format, or the +propagation you chose: + +.. code-block:: python + + pyprep.set_log_level("info") + +The root logger is never configured either way. MNE has its own ``mne`` logger, +controlled separately with :func:`mne.set_log_level`; note also that the +progress bar drawn during window-wise RANSAC is an ``mne.utils.ProgressBar``, +which writes to its own stream rather than through either logger, so neither +function silences it. .. currentmodule:: pyprep @@ -66,3 +95,4 @@ is never configured. :toctree: generated/ setup_logging + set_log_level From 3a1f3a6c91baedfb6fa2f7a7bb81c93aa142f0e1 Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:41:59 +0200 Subject: [PATCH 3/7] Switch the examples on and make RANSAC's own logging readable The examples now configure pyprep themselves, at INFO, since importing it no longer does. run_ransac.py configured nothing at all before and printed only its own timings. They run on every docs build, so their output is published, and channel-wise RANSAC emitted logger.info(current) once per chunk: a bare integer on its own timestamped line, 94 of them in run_ransac.py alone, preceded by a "Current chunk:" header that only made sense as print output. Report the chunk size and the number of chunks once, after the first chunk has proved the size fits in memory. Two messages also carried embedded newlines left over from the same print era, which split each of them across two lines with an empty prefix. --- examples/run_full_prep.py | 10 +++++----- examples/run_prep_in_stages.py | 10 +++++----- examples/run_ransac.py | 8 ++++++++ pyprep/ransac.py | 25 +++++++++++-------------- 4 files changed, 29 insertions(+), 24 deletions(-) diff --git a/examples/run_full_prep.py b/examples/run_full_prep.py index 05c929a..de5db8a 100644 --- a/examples/run_full_prep.py +++ b/examples/run_full_prep.py @@ -21,7 +21,7 @@ import numpy as np from mne.datasets import eegbci -from pyprep import setup_logging +import pyprep from pyprep.prep_pipeline import PrepPipeline ############################################################################### @@ -32,11 +32,11 @@ # a fairly noisy recording, which makes it a good candidate for demonstrating # PREP. The data are 64-channel EEG sampled at 160 Hz. # -# MNE and pyprep each log at ``"INFO"`` by default; we turn both down to keep -# this example's output short. +# pyprep configures no logging of its own, so we ask it for ``"INFO"`` here to +# see what each step decides. MNE is loud at ``"INFO"``, so we turn it down. -mne.set_log_level("WARNING") -setup_logging("WARNING") +mne.set_log_level("warning") +pyprep.setup_logging("info") edf_fpath = eegbci.load_data(subjects=4, runs=1, update_path=True)[0] raw = mne.io.read_raw_edf(edf_fpath, preload=True) diff --git a/examples/run_prep_in_stages.py b/examples/run_prep_in_stages.py index 928c9af..73ea6dc 100644 --- a/examples/run_prep_in_stages.py +++ b/examples/run_prep_in_stages.py @@ -26,7 +26,7 @@ import numpy as np from mne.datasets import eegbci -from pyprep import setup_logging +import pyprep from pyprep.prep_pipeline import PrepPipeline ############################################################################### @@ -37,11 +37,11 @@ # PhysioNet BCI2000 (eegbci) dataset: a fairly noisy 64-channel recording # sampled at 160 Hz. # -# MNE and pyprep each log at ``"INFO"`` by default; we turn both down to keep -# this example's output short. +# pyprep configures no logging of its own, so we ask it for ``"INFO"`` here to +# see what each step decides. MNE is loud at ``"INFO"``, so we turn it down. -mne.set_log_level("WARNING") -setup_logging("WARNING") +mne.set_log_level("warning") +pyprep.setup_logging("info") edf_fpath = eegbci.load_data(subjects=4, runs=1, update_path=True)[0] raw = mne.io.read_raw_edf(edf_fpath, preload=True) diff --git a/examples/run_ransac.py b/examples/run_ransac.py index 6eed304..efb49ea 100644 --- a/examples/run_ransac.py +++ b/examples/run_ransac.py @@ -20,8 +20,16 @@ import numpy as np from scipy import signal as signal +import pyprep from pyprep.find_noisy_channels import NoisyChannels +############################################################################### +# pyprep configures no logging of its own, so we ask it for ``"INFO"`` here to +# see what RANSAC decides. MNE is loud at ``"INFO"``, so we turn it down. + +mne.set_log_level("warning") +pyprep.setup_logging("info") + ############################################################################### # Now let's make some arbitrary MNE raw object for demonstration purposes. # We will think of good channels as sine waves and bad channels correlated with diff --git a/pyprep/ransac.py b/pyprep/ransac.py index a68f2e8..58e42b3 100644 --- a/pyprep/ransac.py +++ b/pyprep/ransac.py @@ -202,7 +202,7 @@ def find_bad_by_ransac( # Is now data.shape[0] = n_chans_complete # They came from the same drop of channels - logger.info("Executing RANSAC\nThis may take a while, so be patient...") + logger.info("Executing RANSAC, this may take a while, so be patient...") # If enabled, run window-wise RANSAC if not channel_wise: @@ -229,9 +229,7 @@ def find_bad_by_ransac( while mem_error and channel_wise: try: channel_chunks = _split_list(job, chunk_size) - total_chunks = len(channel_chunks) - current = 1 - for chunk in channel_chunks: + for i, chunk in enumerate(channel_chunks): interp_mats_for_chunk = [mat[chunk, :] for mat in interp_mats] channel_correlations[:, good_idx[chunk]] = _ransac_by_channel( data[good_idx, :], @@ -242,17 +240,16 @@ def find_bad_by_ransac( random_ch_picks, matlab_strict, ) - if chunk == channel_chunks[0]: - # If it gets here, it means it is the optimal - logger.info("Finding optimal chunk size : %s", chunk_size) - logger.info("Total # of chunks: %s", total_chunks) - logger.info("Current chunk:") - - logger.info(current) - current = current + 1 + if i == 0: + # If it gets here, it means the chunk size is small enough + # to fit in memory, so it is the one we will use throughout. + logger.info( + "Optimal chunk size: %s channels (%s chunks in total)", + chunk_size, + len(channel_chunks), + ) mem_error = False # All chunks processed, hurray! - del current except MemoryError: if len(chunk_sizes): chunk_size = chunk_sizes.pop() @@ -271,7 +268,7 @@ def find_bad_by_ransac( bad_ransac_channels_idx = np.argwhere(frac_bad_corr_windows > frac_bad) bad_ransac_channels_name = complete_chn_labs[bad_ransac_channels_idx.astype(int)] bad_by_ransac = [i[0] for i in bad_ransac_channels_name] - logger.info("\nRANSAC done!") + logger.info("RANSAC done!") return bad_by_ransac, channel_correlations From 0f3b01588888a9cf00c3107f8575e6c491977a76 Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:42:04 +0200 Subject: [PATCH 4/7] Reject an unusable local-detrend step size removeTrend logged an error for a 'local detrend' step size larger than the window or smaller than one sample, and then detrended with it anyway. Raise instead, so the caller finds out before reading the output. Also correct get_bads' docstring: the summary is logged, not printed, and verbose is a plain bool, only its truthiness being used. --- pyprep/find_noisy_channels.py | 9 +++++---- pyprep/removeTrend.py | 2 +- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/pyprep/find_noisy_channels.py b/pyprep/find_noisy_channels.py index 74cfb54..c6e58e0 100644 --- a/pyprep/find_noisy_channels.py +++ b/pyprep/find_noisy_channels.py @@ -228,10 +228,11 @@ def get_bads(self, verbose=False, as_dict=False): Parameters ---------- - verbose : bool | None - If ``True``, a summary of the channels currently flagged as by bad per - category is printed. Defaults to ``False``. - as_dict: bool | None + verbose : bool + If ``True``, a summary of the channels currently flagged as bad per + category is logged at ``"INFO"`` through the ``pyprep`` logger. + Defaults to ``False``. + as_dict : bool If ``True``, this method will return a dict of the channels currently flagged as bad by each individual bad channel type. If ``False``, this method will return a list of all unique bad channels detected so far. diff --git a/pyprep/removeTrend.py b/pyprep/removeTrend.py index cb2f339..ef8e887 100644 --- a/pyprep/removeTrend.py +++ b/pyprep/removeTrend.py @@ -111,7 +111,7 @@ def removeTrend( dn = np.round(sample_rate * stepSize) if dn > n or dn < 1: - logger.error( + raise ValueError( "Step size should be less than the window size and " "contain at least 1 sample" ) From 7f1a0457fd7d963c5cf303a5c594cc7ab31dac7a Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:42:37 +0200 Subject: [PATCH 5/7] Add changelog entries for the logging changes --- docs/changelog.rst | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/docs/changelog.rst b/docs/changelog.rst index 9e0509a..afbfa5b 100644 --- a/docs/changelog.rst +++ b/docs/changelog.rst @@ -26,7 +26,18 @@ Version 0.9.0 (unreleased) Changelog ~~~~~~~~~ -- Nothing yet +- The new :func:`pyprep.set_log_level` changes the level of the ``pyprep`` logger without touching its handler, stream, format, or propagation, mirroring :func:`mne.set_log_level`. Use it instead of calling :func:`pyprep.setup_logging` a second time, which would reset all of those, by `Stefan Appelhoff`_ (:gh:`211`) +- :func:`pyprep.setup_logging` now accepts level names in any case, so ``setup_logging("warning")`` works like :func:`mne.set_log_level` instead of raising ``ValueError``. Its ``stream`` argument became keyword-only and now defaults to :data:`sys.stdout` on every call rather than keeping whatever stream a previous call had installed, and a new keyword-only ``fmt`` argument sets the format of the installed handler, by `Stefan Appelhoff`_ (:gh:`211`) +- All three examples now switch pyprep's logging on themselves with ``pyprep.setup_logging("info")``, since importing the package no longer does. Channel-wise RANSAC no longer logs a bare chunk counter on every chunk, reporting the chunk size and the number of chunks once instead, and two of its messages no longer carry embedded newlines that split them across two log lines, by `Stefan Appelhoff`_ (:gh:`211`) + +API +~~~ +- ``pyprep`` no longer configures logging when it is imported. 0.8.0 attached a handler on :data:`sys.stdout` to the ``pyprep`` logger at import time, so users got ``"INFO"`` output for free; a library cannot know whether the application wants stdout, a file, JSON to an aggregator, or a Rich console, so that decision is handed back to the caller. Without any configuration ``pyprep`` is quiet but not silent: warnings and errors still reach :data:`sys.stderr` through :data:`logging.lastResort`, and ``"INFO"`` records appear once you call :func:`pyprep.setup_logging` or :func:`pyprep.set_log_level`. Note that no :class:`logging.NullHandler` is installed either, deliberately: one would satisfy the handler search in ``logging.Logger.callHandlers`` and suppress the ``lastResort`` fallback, dropping warnings and errors instead of merely hiding ``"INFO"``, by `Stefan Appelhoff`_ (:gh:`211`) +- The ``propagate`` argument of :func:`pyprep.setup_logging` was removed. It existed to undo the import-time configuration and hand the records to the application's handlers; with nothing configured on import, propagation is simply what happens when :func:`pyprep.setup_logging` is never called, by `Stefan Appelhoff`_ (:gh:`211`) + +Bug +~~~ +- :func:`pyprep.removeTrend.removeTrend` now raises a :class:`ValueError` for a ``'local detrend'`` step size that is larger than the window or smaller than one sample, instead of logging an error and detrending with it anyway, by `Stefan Appelhoff`_ (:gh:`211`) .. _changes_0_8_0: From 391630766d30713e26cd890de7b1c9c646b0acc0 Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 08:58:35 +0200 Subject: [PATCH 6/7] Test that an unusable local-detrend step size raises --- tests/test_removeTrend.py | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/tests/test_removeTrend.py b/tests/test_removeTrend.py index af553e7..93ad281 100644 --- a/tests/test_removeTrend.py +++ b/tests/test_removeTrend.py @@ -4,6 +4,7 @@ # SPDX-License-Identifier: MIT import numpy as np +import pytest import pyprep.removeTrend as removeTrend @@ -50,3 +51,18 @@ def test_detrend(): ) error3 = signal_detrend - signal assert np.sqrt(np.mean(error3**2)) < 0.1 + + +def test_detrend_rejects_unusable_step_size(): + """A local-detrend step size that cannot work raises instead of detrending.""" + signal = np.zeros(100) + + # A cutoff this high makes the window shorter than the fixed 0.02 s step. + with pytest.raises(ValueError, match="Step size should be less"): + removeTrend.removeTrend( + signal, detrendType="Local detrend", sample_rate=100, detrendCutoff=1000 + ) + + # A sample rate this low makes the step round down to zero samples. + with pytest.raises(ValueError, match="at least 1 sample"): + removeTrend.removeTrend(signal, detrendType="Local detrend", sample_rate=10) From 1771bbd9be7ba887ee2418340655433597e5d808 Mon Sep 17 00:00:00 2001 From: Stefan Appelhoff Date: Fri, 21 Aug 2026 10:15:48 +0200 Subject: [PATCH 7/7] Keep the logging documentation in one place The same explanation had been written out three times: in the README, in the Logging section of the API docs, and in CONTRIBUTING. Keep the API docs as the one narrative and point the others at it. The README now orients the reader in three sentences and links to that section. CONTRIBUTING keeps only what library code has to do to keep the documented behavior true, which is not user documentation and is not written down anywhere else. setup_logging's Notes had also grown into a second copy of the same narrative, which renders on the very same page as the section it repeated. --- .github/CONTRIBUTING.md | 29 ++++++++++++------------ README.rst | 50 ++++++++--------------------------------- pyprep/_logging.py | 10 +-------- 3 files changed, 24 insertions(+), 65 deletions(-) diff --git a/.github/CONTRIBUTING.md b/.github/CONTRIBUTING.md index 1d0fe64..e062ff3 100644 --- a/.github/CONTRIBUTING.md +++ b/.github/CONTRIBUTING.md @@ -39,30 +39,29 @@ From the project root, call: ## Logging conventions -`pyprep` is a library, so it never decides where log records go. It configures -nothing on import, and library code must never configure the root logger, add a -handler, or touch another package's logger (including MNE's). Those are the -application's calls to make; `setup_logging` and `set_log_level` exist so that -the application can make them in one line. - -Note that we deliberately do *not* install a `NullHandler` on the `pyprep` -logger. A `NullHandler` satisfies the handler search in -`logging.Logger.callHandlers`, which stops `logging.lastResort` from firing and -would silently drop warnings and errors instead of merely hiding `"INFO"`. We -want quiet, not silent. `tests/test_logging.py` enforces both properties from a -clean interpreter. - -Within the library: +What pyprep's logging does, and how a user turns it on, is documented in the +[Logging section of the API documentation](https://pyprep.readthedocs.io/en/stable/api.html#logging). +The rules below are the ones library code has to follow to keep that true. - one `logger = logging.getLogger(__name__)` per module, at module level, so records carry the module they came from -- never `print` from library code; user-facing output is the application's job +- never `print` from library code, and never configure the root logger, add a + handler, or touch another package's logger (including MNE's). Those are the + application's calls to make; `setup_logging` and `set_log_level` exist so that + it can make them in one line - pass arguments to the logging call (`logger.info("Found %s bads", n)`) rather than formatting the string yourself, so the work is skipped when the level is off - log values with a label. A bare `logger.info(some_number)` produces an unreadable line, and the examples render their log output into the docs +Do not add a `NullHandler` to the `pyprep` logger, even though older advice +says a library should. A `NullHandler` satisfies the handler search in +`logging.Logger.callHandlers`, which stops `logging.lastResort` from firing and +would silently drop warnings and errors instead of merely hiding `"INFO"`. We +want quiet, not silent, and `tests/test_logging.py` enforces both properties +from a clean interpreter. + `pyprep/_logging.py` is a verbatim copy of the same module in a few sibling projects, save for the package name in `LOGGER_NAME` and the docstrings. If you change its behavior, the copies need to stay in sync. diff --git a/README.rst b/README.rst index a1fe4cb..7fa21ed 100644 --- a/README.rst +++ b/README.rst @@ -79,47 +79,15 @@ The dependencies are defined in the ``pyproject.toml`` file under the Logging ======= -``pyprep`` logs through the standard ``logging`` module, on a logger named -``pyprep``, and configures nothing on import. -It is quiet, but not silent: warnings and errors still reach ``stderr`` without -any setup, because Python falls back to ``logging.lastResort`` when it finds no -handler. -``"INFO"`` records, which is where the pipeline reports what it decided, stay -hidden until you ask for them. - -To see them without writing handler boilerplate, for example in a script or a -notebook: - -.. code-block:: python - - import pyprep - - pyprep.setup_logging("info") - -This attaches a handler on ``sys.stdout`` to the ``pyprep`` logger only, and -stops those records from propagating to the root logger so they are not printed -twice. -Pass ``"warning"`` to keep only warnings and errors, or ``"debug"`` for more -detail. - -If your application already routes logging somewhere of its own, a file or a -Rich console, do not call ``setup_logging`` at all. -The records reach your handlers by propagation, and ``set_log_level`` will raise -``pyprep``'s verbosity if you want the ``"INFO"`` ones too, without touching the -handler, the stream, the format, or the propagation your application chose: - -.. code-block:: python - - pyprep.set_log_level("info") - -To take the output back after calling ``setup_logging``, drop the handler again: - -.. code-block:: python - - logging.getLogger("pyprep").handlers.clear() - -MNE has its own ``mne`` logger, controlled separately through -``mne.set_log_level``. +``pyprep`` logs through the standard ``logging`` module and configures nothing +when it is imported, so it is quiet by default but never silent: warnings and +errors reach ``stderr`` without any setup. +Call ``pyprep.setup_logging("info")`` to see what the pipeline decided, or +``pyprep.set_log_level("info")`` if your application already routes logging +somewhere of its own. + +See the `Logging section of the API documentation +`_ for the details. Contributing ============ diff --git a/pyprep/_logging.py b/pyprep/_logging.py index ec9e13c..ec1bc18 100644 --- a/pyprep/_logging.py +++ b/pyprep/_logging.py @@ -85,16 +85,8 @@ def setup_logging(level="info", *, stream=None, fmt=DEFAULT_FORMAT): Notes ----- - Only the ``pyprep`` namespace is configured; the root logger is never - touched. Records stop at pyprep's own handler, so an application that - configures the root logger does not see them twice. To hand the output back, - drop the handler again with + To hand the output back afterwards, drop the handler again with ``logging.getLogger("pyprep").handlers.clear()``. - - MNE has its own ``mne`` logger, controlled separately through - :func:`mne.set_log_level`. The progress bar that window-wise RANSAC draws is - an ``mne.utils.ProgressBar``, which writes to its own stream rather than - through either logger, so neither function silences it. """ logger = logging.getLogger(LOGGER_NAME) logger.setLevel(_as_level(level))