diff --git a/.github/CONTRIBUTING.md b/.github/CONTRIBUTING.md index 49f74bf..e062ff3 100644 --- a/.github/CONTRIBUTING.md +++ b/.github/CONTRIBUTING.md @@ -37,6 +37,35 @@ 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 + +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, 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. + ## 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..7fa21ed 100644 --- a/README.rst +++ b/README.rst @@ -76,6 +76,19 @@ 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 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/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 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: 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/__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..ec1bc18 100644 --- a/pyprep/_logging.py +++ b/pyprep/_logging.py @@ -6,57 +6,101 @@ 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. 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`. + 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, 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. - 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. + To hand the output back afterwards, drop the handler again with + ``logging.getLogger("pyprep").handlers.clear()``. """ - 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/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/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 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" ) 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 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)