Change verbose to standard logging library

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

doc/devel/contributing.rst

@@ -171,7 +171,7 @@ repository <https://github.com/matplotlib/matplotlib/>`__ on GitHub,
 then submit a "pull request" (PR).
 
 The best practices for using GitHub to make PRs to Matplotlib are
-documented in the :ref:`development-workflow` section. 
+documented in the :ref:`development-workflow` section.
 
 A brief overview is:
 
@@ -437,6 +437,70 @@ forced to use ``**kwargs``.  An example is
       elif len(args) == 1:
          ...etc...
 
+.. _using_logging:
+
+Using logging for debug messages
+--------------------------------
+
+Matplotlib uses the standard python `logging` library to write verbose
+warnings, information, and
+debug messages.  Please use it!  In all those places you write :func:`print()`
+statements to do your debugging, try using :func:`log.debug()` instead!
+
+
+To include `logging` in your module, at the top of the module, you need to
+``import logging``.  Then calls in your code like::
+
+  _log = logging.getLogger(__name__)  # right after the imports
+
+  # code
+  # more code
+  _log.info('Here is some information')
+  _log.debug('Here is some more detailed information')
+
+will log to a logger named ``matplotlib.yourmodulename``.
+
+If an end-user of Matplotlib sets up `logging` to display at levels
+more verbose than `logger.WARNING` in their code as follows::
+
+  import logging
+  fmt = '%(name)s:%(lineno)5d - %(levelname)s - %(message)s'
+  logging.basicConfig(level=logging.DEBUG, format=fmt)
+  import matplotlib.pyplot as plt
+
+Then they will receive messages like::
+
+  matplotlib.backends:   89 - INFO - backend MacOSX version unknown
+  matplotlib.yourmodulename: 347 - INFO - Here is some information
+  matplotlib.yourmodulename: 348 - DEBUG - Here is some more detailed information
+
+Which logging level to use?
+~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+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
+``warnings`` library.  The
+`logging tutorial <https://docs.python.org/3/howto/logging.html#logging-basic-tutorial>`_
+suggests that the difference
+between `logging.warning` and `warnings.warn` is that
+`warnings.warn` be used for things the user must change to stop
+the warning, whereas `logging.warning` can be more persistent.
+
+By default, `logging` displays all log messages at levels higher than
+`logging.WARNING` to `sys.stderr`.
+
+Calls to `logging.info` are not displayed by default.  They are 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 is ``NaN``,
+that can usually be ignored, but a mystified user could set
+``logging.basicConfig(level=logging.INFO)`` and get an error message that
+says why.
+
+`logging.debug` is the least likely to be displayed, and hence can
+be the most verbose.
+
 .. _custom_backend:
 
 Developing a new backend

doc/faq/troubleshooting_faq.rst

@@ -9,10 +9,10 @@ Troubleshooting
 
 .. _matplotlib-version:
 
-Obtaining matplotlib version
+Obtaining Matplotlib version
 ============================
 
-To find out your matplotlib version number, import it and print the
+To find out your Matplotlib version number, import it and print the
 ``__version__`` attribute::
 
     >>> import matplotlib
@@ -25,7 +25,7 @@ To find out your matplotlib version number, import it and print the
 :file:`matplotlib` install location
 ===================================
 
-You can find what directory matplotlib is installed in by importing it
+You can find what directory Matplotlib is installed in by importing it
 and printing the ``__file__`` attribute::
 
     >>> import matplotlib
@@ -37,7 +37,7 @@ and printing the ``__file__`` attribute::
 :file:`matplotlib` configuration and cache directory locations
 ==============================================================
 
-Each user has a matplotlib configuration directory which may contain a
+Each user has a Matplotlib configuration directory which may contain a
 :ref:`matplotlibrc <customizing-with-matplotlibrc-files>` file. To
 locate your :file:`matplotlib/` configuration directory, use
 :func:`matplotlib.get_configdir`::
@@ -79,7 +79,7 @@ directory and the cache directory.
 Getting help
 ============
 
-There are a number of good resources for getting help with matplotlib.
+There are a number of good resources for getting help with Matplotlib.
 There is a good chance your question has already been asked:
 
 - The `mailing list archive <http://matplotlib.1069221.n5.nabble.com/>`_.
@@ -114,11 +114,35 @@ provide the following information in your e-mail to the `mailing list
   the error will help you find a bug in *your* code that is causing the
   problem.
 
-* 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`
+  library in your code and posting the verbose output to the lists.  For a
+  command-line version of this, try::
 
-     python simple_plot.py --verbose-helpful > output.txt
+     python -c "from logging import *; basicConfig(level=DEBUG); from pylab import *; plot(); show()"
+
+
+  If you want to put the debugging hooks in your own code, then the
+  most simple way to do so is to insert the following *before* any calls
+  to ``import matplotlib``::
+
+    import logging
+    logging.basicConfig(level=logging.DEBUG)
+
+    import matplotlib.pyplot as plt
+
+  Note that if you want to use `logging` in your own code, but do not
+  want verbose Matplotlib output, you can set the logging level
+  for Matplotlib independently::
+
+    import logging
+    # set DEBUG for everything
+    logging.basicConfig(level=logging.DEBUG)
+    logger = logging.getLogger('matplotlib')
+    # set WARNING for Matplotlib
+    logger.setLevel(logging.WARNING)
+
+  The `logging` module is very flexible, and can be a valuable tool in chasing
+  down errors.
 
 If you compiled Matplotlib yourself, please also provide:
 

doc/users/next_whats_new/2017_10_10_logging.rst

@@ -0,0 +1,24 @@
+Logging for debug output
+------------------------
+
+Matplotlib has in the past (sporadically) used an internal
+verbose-output reporter.  This version converts those calls to using the
+standard python `logging` library.
+
+Support for the old ``rcParams`` ``verbose.level`` and ``verbose.fileo`` is
+dropped.
+
+The command-line options ``--verbose-helpful`` and ``--verbose-debug`` are
+still accepted, but deprecated.  They are now equivalent to setting
+``logging.INFO`` and ``logging.DEBUG``.
+
+The logger's root name is ``matplotlib`` and can be accessed from programs
+as::
+
+  import logging
+  mlog = logging.getLogger('matplotlib')
+
+Instructions for basic usage are in :ref:`troubleshooting-faq` and for
+developers in :ref:`contributing`.
+
+.. _logging: https://docs.python.org/3/library/logging.html

lib/matplotlib/__init__.py

@@ -113,6 +113,7 @@
 import inspect
 import itertools
 import locale
+import logging
 import os
 import re
 import sys
@@ -137,6 +138,8 @@
 __version__ = str(get_versions()['version'])
 del get_versions
 
+_log = logging.getLogger(__name__)
+
 __version__numpy__ = str('1.7.1')  # minimum required numpy version
 
 __bibtex__ = r"""@Article{Hunter:2007,
@@ -160,6 +163,9 @@
 if not (_python27 or _python34):
     raise ImportError("Matplotlib requires Python 2.7 or 3.4 or later")
 
+if _python27:
+    _log.addHandler(logging.NullHandler())
+
 
 def compare_versions(a, b):
     "return True if a is greater than or equal to b"
@@ -215,7 +221,75 @@ def _is_writable_dir(p):
     """
     return os.access(p, os.W_OK) and os.path.isdir(p)
 
+_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:
+    import logging
+    logger = logging.getLogger('matplotlib')
+    logger.set_level(logging.INFO)"""
+
+
+def _set_logger_verbose_level(level_str='silent', file_str='sys.stdout'):
+    """
+    Use a --verbose-LEVEL level to set the logging level:
+
+    """
+    levelmap = {'silent': logging.WARNING, 'helpful': logging.INFO,
+                'debug': logging.DEBUG, 'debug-annoying': logging.DEBUG,
+                'info': logging.INFO, 'warning': logging.WARNING}
+    # Check that current state of logger isn't already more verbose
+    # than the requested level.  If it is more verbose, then leave more
+    # verbose.
+    newlev = levelmap[level_str]
+    oldlev = _log.getEffectiveLevel()
+    if newlev < oldlev:
+        _log.setLevel(newlev)
+        std = {
+            'sys.stdout': sys.stdout,
+            'sys.stderr': sys.stderr,
+        }
+        if file_str in std:
+            fileo = std[file_str]
+        else:
+            fileo = sys.stdout
+            try:
+                fileo = open(file_str, 'w')
+                # if this fails, we will just write to stdout
+            except IOError:
+                warnings.warn('could not open log file "{0}"'
+                              'for writing.  Check your '
+                              'matplotlibrc'.format(file_str))
+        console = logging.StreamHandler(fileo)
+        console.setLevel(newlev)
+        _log.addHandler(console)
+
+
+def _parse_commandline():
+    """
+    Check for --verbose-LEVEL type command line arguments and
+    set logging level appropriately.
+    """
 
+    levels = ('silent', 'helpful', 'debug', 'debug-annoying',
+              'info', 'warning')
+
+    for arg in sys.argv[1:]:
+        # cast to str because we are using unicode_literals,
+        # and argv is always str
+
+        if arg.startswith(str('--verbose-')):
+            level_str = arg[10:]
+            # If it doesn't match one of ours, then don't even
+            # bother noting it, we are just a 3rd-party library
+            # to somebody else's script.
+            if level_str in levels:
+                _set_logger_verbose_level(level_str)
+
+_parse_commandline()
+
+
+@cbook.deprecated("2.2", message=_verbose_msg)
 class Verbose(object):
     """
     A class to handle reporting.  Set the fileo attribute to any file
@@ -311,7 +385,29 @@ def ge(self, level):
         return self.vald[self.level] >= self.vald[level]
 
 
-verbose = Verbose()
+def _wrap(fmt, func, level='INFO', always=True):
+    """
+    return a callable function that wraps func and reports its
+    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
+    """
+    assert callable(func)
+
+    def wrapper(*args, **kwargs):
+        ret = func(*args, **kwargs)
+
+        if (always or not wrapper._spoke):
+            lvl = logging.getLevelName(level.upper())
+            _log.log(lvl, fmt % ret)
+            spoke = True
+            if not wrapper._spoke:
+                wrapper._spoke = spoke
+        return ret
+    wrapper._spoke = False
+    wrapper.__doc__ = func.__doc__
+    return wrapper
 
 
 def checkdep_dvipng():
@@ -512,7 +608,7 @@ def _create_tmp_config_dir():
     return configdir
 
 
-get_home = verbose.wrap('$HOME=%s', _get_home, always=False)
+get_home = _wrap('$HOME=%s', _get_home, always=False)
 
 
 def _get_xdg_config_dir():
@@ -601,7 +697,7 @@ def _get_configdir():
     """
     return _get_config_or_cache_dir(_get_xdg_config_dir())
 
-get_configdir = verbose.wrap('CONFIGDIR=%s', _get_configdir, always=False)
+get_configdir = _wrap('CONFIGDIR=%s', _get_configdir, always=False)
 
 
 def _get_cachedir():
@@ -613,7 +709,7 @@ def _get_cachedir():
     """
     return _get_config_or_cache_dir(_get_xdg_cache_dir())
 
-get_cachedir = verbose.wrap('CACHEDIR=%s', _get_cachedir, always=False)
+get_cachedir = _wrap('CACHEDIR=%s', _get_cachedir, always=False)
 
 
 def _decode_filesystem_path(path):
@@ -671,8 +767,8 @@ def _get_data_path_cached():
         defaultParams['datapath'][0] = _get_data_path()
     return defaultParams['datapath'][0]
 
-get_data_path = verbose.wrap('matplotlib data path %s', _get_data_path_cached,
-                             always=False)
+get_data_path = _wrap('matplotlib data path %s', _get_data_path_cached,
+                      always=False)
 
 
 def get_py2exe_datafiles():
@@ -1035,22 +1131,18 @@ def rc_params_from_file(fname, fail_on_error=False, use_default_template=True):
                                       if key not in _all_deprecated])
     config.update(config_from_file)
 
-    verbose.set_level(config['verbose.level'])
-    verbose.set_fileo(config['verbose.fileo'])
-
     if config['datapath'] is None:
         config['datapath'] = get_data_path()
 
     if "".join(config['text.latex.preamble']):
-        verbose.report("""
+        _log.info("""
 *****************************************************************
 You have the following UNSUPPORTED LaTeX preamble customizations:
 %s
 Please do not ask for support with these customizations active.
 *****************************************************************
-""" % '\n'.join(config['text.latex.preamble']), 'helpful')
-
-    verbose.report('loaded rc file %s' % fname)
+""", '\n'.join(config['text.latex.preamble']))
+    _log.info('loaded rc file %s', fname)
 
     return config
 
@@ -1736,9 +1828,7 @@ def inner(ax, *args, **kwargs):
         return inner
     return param
 
-
-verbose.report('matplotlib version %s' % __version__)
-verbose.report('verbose.level %s' % verbose.level)
-verbose.report('interactive is %s' % is_interactive())
-verbose.report('platform is %s' % sys.platform)
-verbose.report('loaded modules: %s' % list(sys.modules), 'debug')
+_log.info('matplotlib version %s', __version__)
+_log.info('interactive is %s', is_interactive())
+_log.info('platform is %s', sys.platform)
+_log.debug('loaded modules: %s', list(sys.modules))