-
-
Notifications
You must be signed in to change notification settings - Fork 7.9k
[MRG] Replace verbose class with standard logging library #9313
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
@@ -1442,7 +1445,7 @@ def convert_psfrags(tmpfile, psfrags, font_preamble, custom_preamble, | |||
latexfile = latexfile.replace("~", "\\string~") | |||
command = [str("latex"), "-interaction=nonstopmode", | |||
'"%s"' % latexfile] | |||
verbose.report(command, 'debug') | |||
log.debug(command) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please use log.debug('%s', command)
(throughout) so as not to crash if command has the bad idea of including a %
. See sphinx-doc/sphinx#4070 for a similar issue (except that they mangled the fix :-/).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK, I can see this has an advantage. OTOH, there is lots of this kind of formatting that was being passed to verbose
. I don't mind fixing the easy cases, but there are also cases like:
log.info('figure size (inches) has been adjusted '
'from %s x %s to %s x %s' % (wo, ho, w, h))
I tested this, and its not as simple as:
log.info('figure size (inches) has been adjusted '
'from %s x %s to %s x %s', (wo, ho, w, h))
which fails.
More importantly, I'm concerned that by redoing all these I'll screw something up. These aren't the easiest parts of the code to debug since the tests don't get run with the logging turned on.
For now, I'll fix the easy one-%s
cases, but not the more complicated formatting.
lib/matplotlib/__init__.py
Outdated
if "".join(config['text.latex.preamble']): | ||
verbose.report(""" | ||
log.info(""" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The standard way is to do
log.info("format_string %s", args)
instead of
log.info("format string %s" % args)
Note that the latter form will raise an exception if args has the bad idea of including a %
(see comment below for more details).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Additional point of information: the reason the logging module uses a format string followed by arguments is that this means the string interpolation is done only if the logging level is such that the result will actually be used. In other words, it is a performance optimization.
Asking for functionality reviews before I write up docs as they will need to be changed in a number of places if this is the way we want to go forward. |
lib/matplotlib/__init__.py
Outdated
output: | ||
`import logging` | ||
`logger=logging.getLogger('matplotlib')` | ||
`logger.set_level(logging.INFO)` |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
import logging
logging.getLogger('matplotlib').setLevel(logging.INFO)
yes it's camelcase
and if you want to keep it over three lines, spaces around =
lib/matplotlib/__init__.py
Outdated
""" | ||
levelmap = {'silent': logging.WARNING, 'helpful': logging.INFO, | ||
'debug': logging.DEBUG, 'debug-annoying': logging.DEBUG, | ||
'info': logging.INFO, 'warning': logging.warning} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
logging.WARNING
lib/matplotlib/__init__.py
Outdated
fileo = open(file_str, 'w') | ||
# if this fails, we will just write to stdout | ||
except IOError: | ||
warning.warn('could not open log file "{0}"' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
warnings
lib/matplotlib/__init__.py
Outdated
# if this fails, we will just write to stdout | ||
except IOError: | ||
warning.warn('could not open log file "{0}"' | ||
'for writing.\nCheck your ' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I tend not to prefer embedding newlines into this kind of messages because you never know what the width of the console is going to be anyways. Not a big deal though.
lib/matplotlib/__init__.py
Outdated
|
||
for arg in sys.argv[1:]: | ||
# cast to str because we are using unicode_literals, | ||
# and argv is always str |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think you need the cast? On Py2 the str will just happily check for startswith against unicode; on Py3 everything is str.
If you do need the cast I'd just write for arg in map(str, sys.argv[1:])
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This might a 2.6 hold over?
This works as expected on as far back as 2.7.3 (the earliest version conda had easily available).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Works with 2.6.8 as well, I do wonder how far back this goes...
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm going to leave this in as I just copied from old code and don't understand the cast. Feel free to tell me the proper way to do it.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I would also suggest leaving out the cast and the comment block that goes with it.
lib/matplotlib/__init__.py
Outdated
output through logger | ||
|
||
if always is True, the report will occur on every function | ||
call; otherwise only on the first time the function is called |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think we ever use always=True so we may as well drop that
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The whole class is deprecated, so...
lib/matplotlib/__init__.py
Outdated
@@ -760,7 +858,8 @@ def gen_candidates(): | |||
|
|||
_deprecated_ignore_map = {} | |||
|
|||
_obsolete_set = {'text.dvipnghack', 'legend.isaxes'} | |||
_obsolete_set = {'text.dvipnghack', 'legend.isaxes', 'verbose.level', | |||
'verbose.fileo'} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why did you deprecated them? I the log level should stay configurable from the mplrc?
@@ -3,7 +3,7 @@ | |||
|
|||
import six | |||
|
|||
import os, sys | |||
import os, sys, loging |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
tyop
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There's bunch of minor edits here and there (haven't listed them all) and I think the logger level should stay configurable from the matplotlibrc, but the general approach looks good to me.
The main point that must be paid attention to is that by default, a given warning.warn (same content and emitted from the same line of code) will only be shown once (it is then stored in a cache and later calls will be suppressed), whereas a logger.warning will be shown every time. |
@anntzer Thanks so much for the comments. I'll try and address (though quite a few were just copied over, rather than new). Your larger points: More than happy to walk back the changes and deprecation warnings on the matplotlibrc. I personally think it could cause more confusion than not, but maybe thats also how I've implemented it. Right now, it takes the most verbose of a) an already instantiated I think there is also a problem calling all these things WRT guidance about what level of verbosity folks should use, and choices between |
I think we can leave the calls to warnings.warn as they are for now and change them to logger.warning in a piecemeal fashion whereever appropriate. |
I will try to give this a close look ASAP. Thank you for taking this on; it's definitely the direction we need to go. |
Yes, please go ahead with @anntzer's suggestions. |
lib/matplotlib/animation.py
Outdated
else: | ||
w, h = self.fig.get_size_inches() | ||
verbose.report('frame size in pixels is %s x %s' % self.frame_size, | ||
level='debug') | ||
log.info('frame size in pixels is %s x %s' % self.frame_size) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Did you mean to change the lever on this one (makes sense to match the one just above)
Without minimizing the amount of work done, this is less invasive change than I expected! I definitely think that this is the right way to go. On a quick read, the mapping between the verbose levels and the logging level makes sense. Agree with @anntzer to not touch A while ago I also wrote up notes on loggers (https://github.com/scikit-beam/scikit-beam/blob/dd8625baa22c886601d51ff0c6fea0aee01c86cb/doc/resource/dev_guide/logging.rst ) which may or may not be a useful reference. |
@anntzer Above you proposed to prioritze:
The problem is I don't think there is anyway from within If its true that we can't detect that the user has specified this in their code, then that becomes very confusing if we say that the coded logger will take priority unless it is set to I am personally against this being set at all in the My proposal would be:
If we want to keep the This is probably just my bias, as I think I've dug out my |
@tacaswell Not minimizing the amount of work at all. It was pretty minimal. Which I think is somewhat unfortunate, because it means people are avoiding putting debugging into their code. Not sure if this will change that, and maybe there are good reasons not to spam the logger if you are doing something that requires high performance. |
I think I'm +0.5 on keeping matplotlibrc support, but am happy to hear input from others. |
Awesome! I’m fine with instantiation trumps all if that is the route to go. If anyone else has an opinion let me know. If not I’ll implement @anntzers preferred method. |
Meh. If we set So, given that we can't tell if the root logger has been set (I don't think), what do we want to do? |
doc/devel/contributing.rst
Outdated
Using logging for debug messages | ||
-------------------------------- | ||
|
||
Matplotlib uses the standard python logging_ library to write verbose |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We have an intersphinx mapping (https://github.com/matplotlib/matplotlib/blob/master/doc/conf.py#L95) to the stdlib so you can (should) just write
`logging`
`print`
`warnings.warn`
etc. and they will link to the corresponding entries in the stdlib docs
doc/devel/contributing.rst
Outdated
Which logging level to use? | ||
~~~~~~~~~~~~~~~~~~~~~~~~~~~ | ||
|
||
There are five logging levels. :func:`logging.critical()` and |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
the level is logging.CRITICAL, not logging.critical.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK, but I want to refer to the functions. Changed to There are five levels at which you can emit messages.
doc/faq/troubleshooting_faq.rst
Outdated
|
||
import matplotlib.pyplot as plt | ||
|
||
Note that if you want to use logging_ in your own code, but do not |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
see above re: intersphinx
6b3edf1
to
d77e94f
Compare
.appveyor.yml
Outdated
@@ -144,7 +144,7 @@ after_test: | |||
# After the tests were a success, build packages (wheels and conda) | |||
|
|||
# Build the wheel with the static libs | |||
# Hide the output, the copied files really clutter the build log... | |||
# Hide the output, the copied files really clutter the build_log... |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
leave this as it was?
doc/devel/contributing.rst
Outdated
There are five levels at which you can emit messages. | ||
`logging.critical` and `logging.error` | ||
are really only there for errors that will end the use of the library but | ||
not kill the interpreter. :`logging.warning()` overlaps with the |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
spurious colon
lib/matplotlib/__init__.py
Outdated
_verbose_msg = """\ | ||
Command line argument --verbose-LEVEL is deprecated. | ||
This functionality is now provided by the standard | ||
python logging library. To get more (or less) logging output:" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
spurious quote
lib/matplotlib/__init__.py
Outdated
verbose.report('platform is %s' % sys.platform) | ||
verbose.report('loaded modules: %s' % list(sys.modules), 'debug') | ||
_log.info('matplotlib version %s', __version__) | ||
#_log.info('verbose.level %s' % verbose.level) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
just remove it?
lib/matplotlib/animation.py
Outdated
@@ -650,7 +640,8 @@ def _args(self): | |||
'-s', '%dx%d' % self.frame_size, '-pix_fmt', self.frame_format, | |||
'-r', str(self.fps)] | |||
# Logging is quieted because subprocess.PIPE has limited buffer size. | |||
if not verbose.ge('debug'): | |||
|
|||
if not (_log.getEffectiveLevel() >= logging.DEBUG): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
aka < DEBUG? :-)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I guess that works!
@@ -48,6 +49,8 @@ | |||
TransformedBbox) | |||
from matplotlib.backend_bases import NonGuiException | |||
|
|||
_log = logging.getLogger(__name__) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
can do without? (and without the import)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I stuck it in there because I have a PR that will need it anyways ;-) I actually think this should be at the top of most modules so folks use the debugging. I appreciate there may be a small performance hit on some intensive modules, but hopefully not a big deal
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Not sure I agree with changing some of the warnings.warn
to logging in animation
, but I'll leave it to someone who uses that to comment.
doc/devel/contributing.rst
Outdated
|
||
will log to a logger named ``matplotlib.yourmodulename``. | ||
|
||
If an end-user of your module sets up `logging` to display at levels |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
of Matplotlib
doc/devel/contributing.rst
Outdated
import logging | ||
Format = '%(name)s:%(lineno)5d - %(levelname)s - %(message)s' | ||
logging.basicConfig(level=logging.DEBUG, | ||
format=Format) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Too much indent.
doc/devel/contributing.rst
Outdated
more verbose than `logger.WARNING` in their code as follows:: | ||
|
||
import logging | ||
Format = '%(name)s:%(lineno)5d - %(levelname)s - %(message)s' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
No capitalization for variables; fmt
if you want to avoid format
.
~~~~~~~~~~~~~~~~~~~~~~~~~~~ | ||
|
||
There are five levels at which you can emit messages. | ||
`logging.critical` and `logging.error` |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Use bullet list?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'll leave as is for now, but am happy for tweaks later...
doc/faq/troubleshooting_faq.rst
Outdated
* You can get very helpful debugging output from matlotlib by running your | ||
script with a ``verbose-helpful`` or ``--verbose-debug`` flags and posting | ||
the verbose output the lists:: | ||
* You can get helpful debugging output from matlotlib by using the logging_ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Matplotlib
@@ -3,7 +3,11 @@ | |||
|
|||
import six | |||
|
|||
import os, sys, warnings | |||
import logging | |||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Extra blank line.
"not enabled the matplotlib 'text.latex.unicode' " | ||
"rcParam.", 'helpful') | ||
_log.info("You are using unicode and latex, but have " | ||
"not enabled the matplotlib 'text.latex.unicode' " |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
One more space.
|
||
command = [str('dvips'), '-q', '-R0', '-o', os.path.basename(psfile), | ||
os.path.basename(dvifile)] | ||
verbose.report(command, 'debug') | ||
_log.debug(command) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why did you convert the one above to use '%s'
and not this one (or the rest of them)?
lib/matplotlib/dviread.py
Outdated
@@ -21,6 +21,7 @@ | |||
unicode_literals) | |||
|
|||
import six | |||
import logging |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Should be in the next block.
@@ -17,17 +17,20 @@ | |||
from six.moves.urllib.request import urlopen | |||
|
|||
import datetime | |||
import logging |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
As this file is deprecated, you may want to send these changes to the new upstream.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Not sure what you mean? Whatever is replacing this file? Not sure what that is!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh mpl_finance
? Hmmm
Using logging for debug messages | ||
-------------------------------- | ||
|
||
Matplotlib uses the standard python `logging` library to write verbose |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
My mistake
Change verbose to standard logging library PEP8 fixes and formatting of log messages @anntzer PEP8 fixes and formatting of log messages @anntzer Small fixes as suggested by @aantzer and @tacaswell Documentation Fix on merge Number small fixes Small fix for docs Small fix for error in animate.py fixed import order and small doc fix Small doc fix Changed log. to _log. Fix on merge Number small fixes Small fix for docs Small fix for error in animate.py fixed import order and small doc fix Small doc fix Changed log. to _log. Changed log. to _log. fixed fonts gah gah gah gah gah gah PEP8 doc fix revert _base.py fix missing _log Fixes for @efiring Fixes for @anntzer minor Doc link fixes @anntzer Small doc change Many small changes, thanks @QuLogic and @anntzer Link error docs
master rebase |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I agree with @efiring that this is good enough to go in as is.
Sweet! 🎉 |
PR Summary
This replaces Matplotlib's
Verbose
class and calls with the standardlogging
library. Hopefully this will lead to more debugging information and better integration with downstream packages.See #9302 and discussion therein.
How to use:
For the end-user:
The old command-line
--verbose-debug
and--verbose-helpful
are still respected (and--verbose-info
was even added). These are likely to be deprecated but are not for now.Better is for a script to load and configure the
logging
library before importing matplotlib:At its most basic:
in the header should do it. A slightly more useful formatting will give line numbers:
The resulting console output will be something like:
which is then pretty easily grep-able to find debug info in particular modules.
For the module writer
At the top of the module, you need to
import logging
. Then calls likewill log to a logger named
matplotlib.yourmodulename
. Theoretically,getLogger
is not too expensive, so you need not save the logger for each class (and you don't need to instantiate it in any way other than a call togetLogger
somewhere).I've used the name
log
throughout the code, which maybe is a problematic choice. One can use any name you want if this clashes in your module's namespace.Which logging level to use?
There are five logging levels.
logging.critical()
andlogging.error()
are really only there for errors that will end the use of the library but not kill the interpreter.WARNING
overlaps with thewarning
library. The logging tutorial has suggested differentiation betweenlogging.warning()
andwarning.warn()
.By default,
logging
displays all log messages at levels higher thanlogging.WARNING
tosys.stderr
.logging.info()
is not displayed by default. Its for information that the user may want to know if the program behaves oddly. For instance, if an object isn't drawn because its position isNaN
, that can usually be ignored, but a mystified user could setlogging.basicConfig(level=logging.INFO)
and if the module writer is kind get an error message that says why.logging.debug()
is the least likely to be displayed, and hence can be the most verbose.Fate of --verbose and the rcParams...
The
--verbose-debug
and--verbose-helpful
command line options are still handled and setlogging.basicConfig(level=logging.DEBUG)
and ``logging.basicConfig(level=logging.INFO)` respectively.The entries in
matplotlibrc
are still respected by the same logic (verbose.level
andverbose.fileo
). However, they are on thedeprecated
list and those entries have been removed from thematplotlibrc.template
.PR Checklist