Refactoring the logging module #5367
Conversation
Need to add a fmt_string parameter if want to replicate earlier behavior
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## develop #5367 +/- ##
========================================
Coverage 93.84% 93.85%
========================================
Files 182 182
Lines 22497 22495 -2
Branches 3200 3202 +2
========================================
Hits 21113 21113
+ Misses 922 921 -1
+ Partials 462 461 -1 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
|
Can I ask for some feedback here? I feel this code here is fairly straightforward and readable, and it preserves existing behavior of the old code as well. I'm a bit confused on where to write the tests. There are two |
|
I also need to write docs as well |
| create( | ||
| "MDAnalysis", | ||
| stream=stream, | ||
| level="DEBUG", | ||
| fmt="%(asctime)s %(name)-12s %(levelname)-8s %(message)s", | ||
| ) | ||
| create( | ||
| "MDAnalysis", | ||
| stream=sys.stdout, | ||
| level="INFO", | ||
| fmt="%(name)-12s: %(levelname)-8s %(message)s", | ||
| ) |
There was a problem hiding this comment.
All of this is intend to replicate old behavior from the original.
| logger.info("MDAnalysis STOPPED logging") | ||
| clear_handlers(logger) # this _should_ do the job... | ||
|
|
||
|
|
There was a problem hiding this comment.
In general, I guess this PR make create() a more general type of function which add handlers to a master logger, so should it get renamed?
There was a problem hiding this comment.
Probably yes to renaming, but you'd need to
- deprecate the old function
- schedule for removal in 3.0.0
because we're following semantic versioning https://semver.org and we cannot remove documented functionality in a public function until we make a new major release.
Similarly, we cannot just rename kwargs in a public function like create(). You have to keep the old one around and deprecated them.
There was a problem hiding this comment.
Probably should raise an issue of it as well
orbeckst
left a comment
orbeckst
left a comment
There was a problem hiding this comment.
Overall this looks good and does not generate a lot more code. I'd be supportive of the change.
You'll need to deprecate kwargs if you change them. ALternatively, leave them and say in the docs that "logfile" can be any file-like or stream-like object.
I see that's WIP so you know that you'll also eventually need docs, tests, and CHANGELOG.
|
|
||
|
|
||
| def start_logging(logfile="MDAnalysis.log", version=version.__version__): | ||
| def start_logging(stream="MDAnalysis.log", version=version.__version__): |
There was a problem hiding this comment.
Under semantic versioning, you need to maintain backwards compatibility. So something like
def start_logging(stream="MDAnalysis.log", logfile=None, version=version.__version__):
if logfile is not None:
warnings.warn(DeprecationWarning, "logfile kwarg will be removed in MDAnalysis 3.0.0, use stream instead"
# we probably have a dedicated function for the deprecation warning...
stream = logfile
...|
|
||
| def create(logger_name="MDAnalysis", logfile="MDAnalysis.log"): | ||
| def create( | ||
| logger_name="MDAnalysis", stream="MDAnalysis.log", level="DEBUG", fmt=None |
There was a problem hiding this comment.
as above, you need to deprecate kwargs if you really want to rename them
jauy123
changed the title
| class RedirectedStderr(object): | ||
| """Temporarily replaces sys.stderr with *stream*. | ||
|
|
||
| Deals with cached stderr, see | ||
| http://stackoverflow.com/questions/6796492/temporarily-redirect-stdout-stderr | ||
| """ | ||
|
|
||
| def __init__(self, stream=None): | ||
| self._stderr = sys.stderr | ||
| self.stream = stream or sys.stdout | ||
|
|
||
| def __enter__(self): | ||
| self.old_stderr = sys.stderr | ||
| self.old_stderr.flush() | ||
| sys.stderr = self.stream | ||
|
|
||
| def __exit__(self, exc_type, exc_value, traceback): | ||
| self._stderr.flush() | ||
| sys.stderr = self.old_stderr | ||
|
|
||
|
|
||
| @pytest.fixture() | ||
| def buffer(): | ||
| return StringIO() | ||
|
|
||
|
|
||
| def _assert_in(output, string): | ||
| assert ( | ||
| string in output | ||
| ), "Output '{0}' does not match required format '{1}'.".format( | ||
| output.replace("\r", "\\r"), string.replace("\r", "\\r") | ||
| ) |
There was a problem hiding this comment.
If you were to grep -F -r for these functions or classes, they don't exist anywhere else in the testsuite. So they should be removed!
| class NullHandler(logging.Handler): | ||
| """Silent Handler. | ||
|
|
||
| Useful as a default:: | ||
|
|
||
| h = NullHandler() | ||
| logging.getLogger("MDAnalysis").addHandler(h) | ||
| del h | ||
|
|
||
| see the advice on logging and libraries in | ||
| http://docs.python.org/library/logging.html?#configuring-logging-for-a-library | ||
| """ | ||
|
|
||
| def emit(self, record): | ||
| pass | ||
|
|
||
|
|
There was a problem hiding this comment.
Should deprecated instead of remove huh
| def test_start_stop_logging(): | ||
| try: | ||
| MDAnalysis.log.start_logging() | ||
| logger = logging.getLogger("MDAnalysis") | ||
| logger.info("Using the MDAnalysis logger works") | ||
| except Exception as err: | ||
| raise AssertionError("Problem with logger: {0}".format(err)) | ||
| finally: | ||
| MDAnalysis.log.stop_logging() |
There was a problem hiding this comment.
This test doesn't really test functionality or properties of the mda.start/stop_logging() functions. It just tests if the command succeeds. Need a rewrite
| for h in list(logger.handlers): | ||
| logger.removeHandler(h) |
There was a problem hiding this comment.
There's a really subtle bug with the original version. logger.removeHandler(h) mutates the original logger.handlers so it "skips" handlers in the list. Putting in a list creates a copy, so the entire elements get deleted
See test_stop_logging under TestConvenienceFunctions. The original version without list would have failed that test.
| logger = logging.getLogger("MDAnalysis.__init__") | ||
|
|
||
| from .version import __version__ | ||
|
|
||
| try: | ||
| from .authors import __authors__ | ||
| except ImportError: | ||
| logger.info("Could not find authors.py, __authors__ will be empty.") | ||
| __authors__ = [] |
There was a problem hiding this comment.
Where is this logger output being captured exactly? There's no handlers or anything.
This is a result of me using breakpoint() on line 163.
> /nfs/homes3/jauy1/Projects/Dev/mdanalysis/package/MDAnalysis/__init__.py(164)<module>()
-> try:
(Pdb) logger
<Logger MDAnalysis.__init__ (WARNING)>
(Pdb) logger.info('hi')
(Pdb) logger.handlers
[]
(Pdb) from .authors import __authors__
(Pdb) print(__authors__)
['Naveen Michaud-Agrawal', 'Elizabeth J. Denning', 'Christian Beckstein (logo), ...]I think the loggers in this code should be deleted?
There was a problem hiding this comment.
logging get deleted in line 204, so I'm not exactly sure what the purpose of this log exactly is.
There was a problem hiding this comment.
I guess a more fundamental question is what case does __authors__ not get imported? There's aren't any minimalist install in MDAnalysis correct?
| # Just have the message logged it directly | ||
|
|
||
| def start_logging(logfile="MDAnalysis.log", version=version.__version__): | ||
| def start_logging(stream="MDAnalysis.log", version=version.__version__): |
There was a problem hiding this comment.
See my comment above in line 101. Why would a user want to manually change the version in this function? The version keyword should be deprecated and removed.
| def stop_logging(): | ||
| """Stop logging to logfile and console.""" | ||
| logger = logging.getLogger("MDAnalysis") | ||
| logger = logging.getLogger(__name__) |
There was a problem hiding this comment.
Standard library recommends constructing through logging.getLogger(__name__) because all loggers from all libraries share the same namespace and this is a standardized way of treating this.
__name__ is MDAnalysis so existing behavior should be preserved.
See 2nd paragraph: https://docs.python.org/3/library/logging.html#logger-objects
| # Standard library recommends constructing through | ||
| # logging.getLogger(__name__) because all loggers share the same namespace | ||
| # and this is a systemmatic way of defining loggers |
There was a problem hiding this comment.
Note that changing from logging.getLogger("MDAnalysis") to logging.getLogger(__name__) blindly breaks things for some reason (See commit 74bcc03 and commit 0fdd02e). It's something with the fancy printer.
[3] --- Logging error ---
Traceback (most recent call last):
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/io.py", line 326, in format_bibtex
bib_source = cpBibTeX(fname)
^^^^^^^^^^^^^^^
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibtex.py", line 69, in __init__
bibtex_database = BibTeXParser(filename, encoding)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibparse.py", line 44, in __init__
self._parse(self.file)
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibparse.py", line 50, in _parse
entry = self._parse_entry(file)
^^^^^^^^^^^^^^^^^^^^^^^
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibparse.py", line 98, in _parse_entry
value = self._parse_value(file)
^^^^^^^^^^^^^^^^^^^^^^^
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibparse.py", line 138, in _parse_value
value = self._parse_variable(file, char)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/citeproc/source/bibtex/bibparse.py", line 178, in _parse_variable
value = self.standard_variables[key.lower()]
~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^
KeyError: 'june'
During handling of the above exception, another exception occurred:
"""
Traceback (most recent call last):
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/logging/__init__.py", line 1163, in emit
stream.write(msg + self.terminator)
ValueError: I/O operation on closed file.
Call stack:
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/utils.py", line 209, in wrapped_func
return f(*args, **kwargs)
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/dueswitch.py", line 102, in dump
due_summary.dump()
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/collector.py", line 499, in dump
output.dump()
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/io.py", line 247, in dump
self.fd.write(get_text_rendering(cit.entry, style=self.style))
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/io.py", line 254, in get_text_rendering
return format_bibtex(get_bibtex_rendering(entry), style=style)
File "/nfs/homes3/jauy1/opt/miniforge3/envs/mdanalysis-dev/lib/python3.12/site-packages/duecredit/io.py", line 343, in format_bibtex
lgr.error(msg)
Message: "Failed to process BibTeX file /tmp/tmpj15zx5r6.bib: 'june'."
Arguments: ()
2 participants
Initial draft that address #5357 and #5368. It should be a quick relatively painless change to implement.
Changes made in this Pull Request:
LLM / AI generated code disclosure
LLMs or other AI-powered tools (beyond simple IDE use cases) were used in this contribution: yes / no
PR Checklist
package/CHANGELOGfile updated?package/AUTHORS? (If it is not, add it!)Developers Certificate of Origin
I certify that I can submit this code contribution as described in the Developer Certificate of Origin, under the MDAnalysis LICENSE.
📚 Documentation preview 📚: https://mdanalysis--5367.org.readthedocs.build/en/5367/