Do not configure logging when pyprep is imported - #211
Merged
Conversation
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.
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.
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.
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.
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #211 +/- ##
==========================================
+ Coverage 97.92% 98.03% +0.10%
==========================================
Files 8 8
Lines 869 864 -5
==========================================
- Hits 851 847 -4
+ Misses 18 17 -1 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
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.
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.
Reverts pyprep's loud-by-default logging, which shipped in 0.8.0, and aligns the
_loggingmodule with the design used by a few sibling projects.This is a breaking change. Anyone who got
"INFO"output for free byimporting pyprep 0.8.0 will now see only warnings and errors until they ask for
more.
Why
0.8.0 called
setup_logging()at import time, attaching a handler onsys.stdoutto thepypreplogger. That is a decision a library cannot make onthe application's behalf: it does not know whether the application wants stdout,
a file, JSON to an aggregator, or a Rich console. MNE does this, but MNE is the
exception people copy rather than the model.
No
NullHandlergoes in its place, deliberately, and this is not the old"libraries should add a NullHandler" advice. A
NullHandlersatisfies thehandler search in
logging.Logger.callHandlers, which stopslogging.lastResortfrom firing and would silently drop warnings and errorsinstead of merely hiding
"INFO". So pyprep is now quiet, but not silent:with no configuration at all, warnings and errors still reach
stderr.tests/test_logging.pyenforces both properties from a clean interpreter.What changed
pyprepconfigures nothing. Thepypreplogger sits atNOTSETwith no handlers and
propagate = True.pyprep.set_log_level(level, return_old_level=False), mirroringmne.set_log_level. It changes only the level, so an application that alreadyroutes pyprep's records through its own handlers can turn the package up
without losing the stream, format and propagation it chose.
setup_logging(level="info", *, stream=None, fmt=DEFAULT_FORMAT): level namesare accepted in any case,
streamand the newfmtare keyword-only, thehandler is always installed fresh on the given stream rather than reusing a
previously installed one, and the configured logger is returned.
propagateargument is removed. It existed to undo the import-timeconfiguration and hand the records to the application's handlers; with nothing
configured on import, propagation is simply what happens when
setup_loggingis never called.
propagatefor the session is gone withthe import-time call it worked around.
caplognow works out of the box.Examples and RANSAC output
Examples execute on every docs build here, so their log output is published. All
three now call
pyprep.setup_logging("info")themselves —run_ransac.pyconfigured nothing at all before — and keep
mne.set_log_level("warning").That made two print-era artifacts in
pyprep/ransac.pyvisible. Channel-wiseRANSAC emitted
logger.info(current)once per chunk: a bare integer on its owntimestamped line, 94 of them in
run_ransac.pyalone, under a"Current chunk:"header that only read asprintoutput. It now reports the chunk sizeand the number of chunks once, after the first chunk has proved the size fits in
memory. Two other messages carried embedded newlines that split each of them
across two log lines with an empty prefix.
In
run_ransac.pythe second RANSAC call alone published 94 bare-integer loglines; the whole example now publishes 6 log lines in total.
Also in here
removeTrendlogged an error for a'local detrend'step size larger thanthe window or smaller than one sample, then detrended with it anyway. It now
raises.
get_bads' docstring said the summary is "printed" and typedverboseasbool | Nonewhen only its truthiness is used.level.upper()fix is a strict subset of the new_as_levelhelper. That PR is superseded and closed; its changelog entry isreworked here.
Docs
The
Loggingsection ofdocs/api.rstis the one place this is explained:quiet-by-default, the
lastResortfallback, the two ways to ask for"INFO",and the fact that the progress bar drawn during window-wise RANSAC comes from
MNE and writes to its own stream, so neither function silences it — otherwise
that looks like a bug.
README.rstorients the reader in three sentences and links there.CONTRIBUTING.mdcarries only what library code has to do to keep thatbehavior true — one module logger, no
print, no configuring anyone else'slogger, do not add a
NullHandler, keep_logging.pyin sync with the siblingcopies — which is not user documentation and is not written down anywhere else.
Verification
pytest: 61 passed (the new ValueError gets a test of its own)pre-commit run --all-files: cleancd docs && make html: clean, all three examples executedpyprepand theroot logger with no handlers; a warning from
pyprep.xreachesstderrwithno configuration;
INFOis hidden until eitherset_log_level("info")withan application root handler or
setup_logging("info"), and appears exactlyonce in both cases.
only long-stable
loggingAPI and adds no MNE call.Open questions
pyprojectpin is touched, even thoughdocs/changelog.rstdescribes 0.9.0 as unreleased. Cutting it is yours todecide.
:gh:211``, assuming this PR takes that number. Ifit does not, they need a one-line correction.