Source code for MDAnalysis.lib.log

# -*- Mode: python; tab-width: 4; indent-tabs-mode:nil; coding:utf-8 -*-
# vim: tabstop=4 expandtab shiftwidth=4 softtabstop=4
#
# MDAnalysis --- https://www.mdanalysis.org
# Copyright (c) 2006-2017 The MDAnalysis Development Team and contributors
# (see the file AUTHORS for the full list of names)
#
# Released under the GNU Public Licence, v2 or any higher version
#
# Please cite your use of MDAnalysis in published work:
#
# R. J. Gowers, M. Linke, J. Barnoud, T. J. E. Reddy, M. N. Melo, S. L. Seyler,
# D. L. Dotson, J. Domanski, S. Buchoux, I. M. Kenney, and O. Beckstein.
# MDAnalysis: A Python package for the rapid analysis of molecular dynamics
# simulations. In S. Benthall and S. Rostrup editors, Proceedings of the 15th
# Python in Science Conference, pages 102-109, Austin, TX, 2016. SciPy.
# doi: 10.25080/majora-629e541a-00e
#
# N. Michaud-Agrawal, E. J. Denning, T. B. Woolf, and O. Beckstein.
# MDAnalysis: A Toolkit for the Analysis of Molecular Dynamics Simulations.
# J. Comput. Chem. 32 (2011), 2319--2327, doi:10.1002/jcc.21787
#


"""Setting up logging --- :mod:`MDAnalysis.lib.log`
====================================================

Configure logging for MDAnalysis. Import this module if logging is
desired in application code.

Logging to a file and the console is set up by default as described
under `logging to multiple destinations`_.

The top level logger of the library is named *MDAnalysis* by
convention; a simple logger that writes to the console and logfile can
be created with the :func:`create` function. This only has to be done
*once*. For convenience, the default MDAnalysis logger can be created
with :func:`MDAnalysis.start_logging`::

 import MDAnalysis
 MDAnalysis.start_logging()

Once this has been done, MDAnalysis will write messages to the logfile
(named `MDAnalysis.log` by default but this can be changed with the
optional argument to :func:`~MDAnalysis.start_logging`).

Any code can log to the MDAnalysis logger by using ::

 import logging
 logger = logging.getLogger('MDAnalysis.MODULENAME')

 # use the logger, for example at info level:
 logger.info("Starting task ...")

The important point is that the name of the logger begins with
"MDAnalysis.".

.. _logging to multiple destinations:
   http://docs.python.org/library/logging.html?#logging-to-multiple-destinations

Note
----
The :mod:`logging` module in the standard library contains in depth
documentation about using logging.


Convenience functions
---------------------

Two convenience functions at the top level make it easy to start and
stop the default *MDAnalysis* logger.

.. autofunction:: MDAnalysis.start_logging
.. autofunction:: MDAnalysis.stop_logging


Other functions and classes for logging purposes
------------------------------------------------

.. autogenerated, see Online Docs

"""
from __future__ import print_function, division, absolute_import

import sys
import logging
import re
import warnings

from tqdm.auto import tqdm

from .. import version
from .util import deprecate


[docs]def start_logging(logfile="MDAnalysis.log", version=version.__version__): """Start logging of messages to file and console. The default logfile is named `MDAnalysis.log` and messages are logged with the tag *MDAnalysis*. """ create("MDAnalysis", logfile=logfile) logging.getLogger("MDAnalysis").info( "MDAnalysis %s STARTED logging to %r", version, logfile)
[docs]def stop_logging(): """Stop logging to logfile and console.""" logger = logging.getLogger("MDAnalysis") logger.info("MDAnalysis STOPPED logging") clear_handlers(logger) # this _should_ do the job...
[docs]def create(logger_name="MDAnalysis", logfile="MDAnalysis.log"): """Create a top level logger. - The file logger logs everything (including DEBUG). - The console logger only logs INFO and above. Logging to a file and the console as described under `logging to multiple destinations`_. The top level logger of MDAnalysis is named *MDAnalysis*. Note that we are configuring this logger with console output. If a root logger also does this then we will get two output lines to the console. .. _logging to multiple destinations: http://docs.python.org/library/logging.html?#logging-to-multiple-destinations """ logger = logging.getLogger(logger_name) logger.setLevel(logging.DEBUG) # handler that writes to logfile logfile_handler = logging.FileHandler(logfile) logfile_formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s') logfile_handler.setFormatter(logfile_formatter) logger.addHandler(logfile_handler) # define a Handler which writes INFO messages or higher to the sys.stderr console_handler = logging.StreamHandler() console_handler.setLevel(logging.INFO) # set a format which is simpler for console use formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s') console_handler.setFormatter(formatter) logger.addHandler(console_handler) return logger
[docs]def clear_handlers(logger): """clean out handlers in the library top level logger (only important for reload/debug cycles...) """ for h in logger.handlers: logger.removeHandler(h)
[docs]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 """
[docs] def emit(self, record): pass
@deprecate(release="1.0.1", remove="2.0.0") def echo(s='', replace=False, newline=True): r"""Simple string output that immediately prints to the console. The string `s` is modified according to the keyword arguments and then printed to :const:`sys.stderr`, which is immediately flushed. Parameters ---------- s : str The string to output. replace : bool If ``True``, the string will be printed on top of the current line. In practice, ``\r`` is added at the beginning of the string. newline : bool If ``True``, a newline is added at the end of the string. """ if replace: s = '\r' + s if newline: end='\n' else: end='' print(s, file=sys.stderr, end=end) sys.stderr.flush() def _new_format(template, variables): """Format a string that follows the `{}`-based syntax.""" return template.format(**variables) def _legacy_format(template, variables): """Format a string that follows the `%`-based syntax.""" return template % variables def _guess_string_format(template): """Guess if the template follow `{}`-based or `%`-based syntax.""" match = re.search(r'%\((step|numsteps|percentage)\)', template) if match is None: return _new_format else: return _legacy_format
[docs]class ProgressMeter(object): r"""Simple progress meter (Deprecated) ..Warning: This class is deprecated and will be removed in version 2.0. Please use :class:`MDAnalysis.lib.log.ProgressBar` instead. The :class:`ProgressMeter` class can be used to show running progress such as frames processed or percentage done to give the user feedback on the duration and progress of a task. It is structures as a class that is customized on instantation (e.g., using a custom `format` string and the expected total number of frames to be processed). Within a processing loop, call :meth:`echo` with the current frame number to print the output to stderr. Parameters ---------- numsteps: int total number of steps interval: int only calculate and print progress every `interval` steps [10] format: str a format string with Python variable interpolation. Allowed values: * *step*: current step * *numsteps*: total number of steps as supplied in *numsteps* * *percentage*: percentage of total The last call to :meth:`ProgressMeter.print` will automatically issue a newline ``\n``. If *format* is ``None`` then the default is used:: Step {step:5d}/{numsteps} [{percentage:5.1f}%] offset: int number to add to *step*; e.g. if *step* is 0-based (as in MDAnalysis) then one should set *offset* = 1; for 1-based steps, choose 0. [1] verbose: bool If ``False``, disable all output, ``True`` print all messages as specified, [``True``] dynamic: bool If ``True``, each line will be printed on top of the previous one. This is done by prepedind the format with ``\r``. [``True``] format_handling: str how to handle the format string. Allowed values are: * *new*: the format string uses {}-based formating * *legacy*: the format string uses %-basedd formating * *auto*: default, try to guess how the format string should be handled Examples -------- The typical use case is to show progress as frames of a trajectory are processed:: u = Universe(PSF, DCD) pm = ProgressMeter(u.trajectory.n_frames, interval=100) for ts in u.trajectory: pm.echo(ts.frame) ... For a trajectory with 10000 frames this will produce output such as :: Step 100/10000 [ 1.0%] Step 200/10000 [ 2.0%] ... The default *format* string is:: Step {step:5d}/{numsteps} [{percentage:5.1f}%] By default, each line of the progress meter is displayed on top of the previous one. To prevent this behaviour, set the `dynamic` keyword to ``False``. It is possible to embed (almost) arbitrary additional data in the format string, for example a current RMSD value:: format_line = "RMSD {rmsd:5.2f} at {step:5d}/{numsteps} [{percentage:5.1f}%]" pm = ProgressMeter(u.trajectory.n_frames, interval=100, format=format_line) for ts in u.trajectory: pm.echo(ts.frame, rmsd=current_rmsd) ... This will print something like:: RMSD 1.02 at 100/10000 [ 1.0%] RMSD 1.89 at 200/10000 [ 2.0%] ... .. versionchanged:: 0.8 Keyword argument *quiet* was added. .. versionchanged:: 0.16 Keyword argument *dynamic* replaces ``\r`` in the format. .. deprecated:: 0.16 Keyword argument *quiet* is deprecated in favor of *verbose*. .. deprecated:: 1.0 This class is deprecated in favor of :class:`ProgressBar`. """ def __init__(self, numsteps, format=None, interval=10, offset=1, verbose=True, dynamic=True, format_handling='auto'): warnings.warn( "This class is deprecated as of MDAnalysis version 1.0. " "It will be removed in MDAnalysis version 2.0. " "Please use MDAnalysis.lib.log.ProgressBar instead.", category=DeprecationWarning ) self.numsteps = numsteps self.interval = int(interval) self.offset = int(offset) self.verbose = verbose self.dynamic = dynamic self.numouts = -1 if format is None: format = "Step {step:5d}/{numsteps} [{percentage:5.1f}%]" self.format_handler = _new_format else: if format_handling == 'auto': self.format_handler = _guess_string_format(format) else: self.format_handler = {'new': _new_format, 'legacy': _legacy_format}[format_handling] self.format = format self.step = 0 self.percentage = 0.0 assert numsteps > 0, "numsteps step must be >0" assert interval > 0, "interval step must be >0"
[docs] def update(self, step, **kwargs): """Update the state of the ProgressMeter. *kwargs* are additional attributes that can be references in the format string. """ self.step = step + self.offset self.percentage = 100. * self.step / self.numsteps for k, v in kwargs.items(): setattr(self, k, v) self.numouts += 1
[docs] def echo(self, step, **kwargs): """Print the state to stderr, but only every *interval* steps. 1) calls :meth:`~ProgressMeter.update` 2) writes step and percentage to stderr with :func:`echo`, using the format string (in :attr:`ProgressMeter.format`) The last step is always shown, even if not on an *interval*, and a carriage return is replaced with a new line for a cleaner display. *kwargs* are additional attributes that can be references in the format string. .. Note:: If *verbose* = ``False`` has been set in the constructor or if :attr:`ProgressMeter.verbose` has been set to ``False``, then no messages will be printed. """ if not self.verbose: return self.update(step, **kwargs) format = self.format newline = not self.dynamic if self.step == self.numsteps: newline = True elif self.numouts % self.interval == 0: pass else: return echo(self.format_handler(format, vars(self)), replace=self.dynamic, newline=newline)
[docs]class ProgressBar(tqdm): r"""Display a visual progress bar and time estimate. The :class:`ProgressBar` decorates an iterable object, returning an iterator which acts exactly like the original iterable, but prints a dynamically updating progressbar every time a value is requested. See the example below for how to use it when iterating over the frames of a trajectory. Parameters ---------- iterable : iterable, optional Iterable to decorate with a progressbar. Leave blank to manually manage the updates. verbose : bool, optional If ``True`` (the default) then show the progress bar, *unless* the `disable` keyword is set to ``True`` (`disable` takes precedence over `verbose`). If `verbose` is set to ``None`` then the progress bar is displayed (like ``True``), *unless* this is a non-TTY output device (see `disable`). desc : str, optional Prefix for the progressbar. total : int or float, optional The number of expected iterations. If unspecified, ``len(iterable)`` is used if possible. If ``float("inf")`` or as a last resort, only basic progress statistics are displayed (no ETA, no progressbar). leave : bool, optional If [default: ``True``], keeps all traces of the progressbar upon termination of iteration. If ``None``, will leave only if `position` is 0. file : :class:`io.TextIOWrapper` or :class:`io.StringIO`, optional Specifies where to output the progress messages (default: :data:`sys.stderr`). Uses :meth:`file.write` and :meth:`file.flush` methods. For encoding, see `write_bytes`. ncols : int, optional The width of the entire output message. If specified, dynamically resizes the progressbar to stay within this bound. If unspecified, attempts to use environment width. The fallback is a meter width of 10 and no limit for the counter and statistics. If 0, will not print any meter (only stats). mininterval : float, optional Minimum progress display update interval [default: 0.1] seconds. maxinterval : float, optional Maximum progress display update interval [default: 10] seconds. Automatically adjusts `miniters` to correspond to `mininterval` after long display update lag. Only works if `dynamic_miniters` or monitor thread is enabled. miniters : int or float, optional Minimum progress display update interval, in iterations. If 0 and `dynamic_miniters`, will automatically adjust to equal `mininterval` (more CPU efficient, good for tight loops). If > 0, will skip display of specified number of iterations. Tweak this and `mininterval` to get very efficient loops. If your progress is erratic with both fast and slow iterations (network, skipping items, etc) you should set miniters=1. ascii : bool or str, optional If unspecified or ``False``, use unicode (smooth blocks) to fill the meter. The fallback is to use ASCII characters " 123456789#". disable : bool, optional Whether to disable the entire progressbar wrapper [default: ``False``]. If set to None, disable on non-TTY. unit : str, optional String that will be used to define the unit of each iteration [default: it]. unit_scale : bool or int or float, optional If 1 or True, the number of iterations will be reduced/scaled automatically and a metric prefix following the International System of Units standard will be added (kilo, mega, etc.) [default: ``False``]. If any other non-zero number, will scale `total` and `n`. dynamic_ncols : bool, optional If set, constantly alters `ncols` and `nrows` to the environment (allowing for window resizes) [default: ``False``]. smoothing : float, optional Exponential moving average smoothing factor for speed estimates (ignored in GUI mode). Ranges from 0 (average speed) to 1 (current/instantaneous speed) [default: 0.3]. bar_format : str, optional Specify a custom bar string formatting. May impact performance. [default: ``'{l_bar}{bar}{r_bar}'``], where ``l_bar='{desc}: {percentage:3.0f}%|'`` and ``r_bar='| {n_fmt}/{total_fmt} [{elapsed}<{remaining}, {rate_fmt}{postfix}]'`` Possible vars: l_bar, bar, r_bar, n, n_fmt, total, total_fmt, percentage, elapsed, elapsed_s, ncols, nrows, desc, unit, rate, rate_fmt, rate_noinv, rate_noinv_fmt, rate_inv, rate_inv_fmt, postfix, unit_divisor, remaining, remaining_s. Note that a trailing ": " is automatically removed after {desc} if the latter is empty. initial : int or float, optional The initial counter value. Useful when restarting a progress bar [default: 0]. If using :class:`float`, consider specifying ``{n:.3f}`` or similar in `bar_format`, or specifying `unit_scale`. position : int, optional Specify the line offset to print this bar (starting from 0) Automatic if unspecified. Useful to manage multiple bars at once (e.g., from threads). postfix : dict or \*, optional Specify additional stats to display at the end of the bar. Calls ``set_postfix(**postfix)`` if possible (:class:`dict`). unit_divisor : float, optional [default: 1000], ignored unless `unit_scale` is ``True``. write_bytes : bool, optional If (default: ``None``) and `file` is unspecified, bytes will be written in Python 2. If `True` will also write bytes. In all other cases will default to unicode. lock_args : tuple, optional Passed to `refresh` for intermediate output (initialisation, iterating, and updating). nrows : int, optional The screen height. If specified, hides nested bars outside this bound. If unspecified, attempts to use environment height. The fallback is 20. Returns ------- out : decorated iterator. Example ------- To get a progress bar when analyzing a trajectory:: from MDAnalysis.lib.log import ProgressBar ... for ts in ProgressBar(u.trajectory): # perform analysis will produce something similar to :: 30%|███████████ | 3/10 [00:13<00:30, 4.42s/it] in a terminal or Jupyter notebook. See Also -------- The :class:`ProgressBar` is derived from :class:`tqdm.auto.tqdm`; see the `tqdm documentation`_ for further details on how to use it. .. _`tqdm documentation`: https://tqdm.github.io/ """ def __init__(self, *args, **kwargs): """""" # ^^^^ keep the empty doc string to avoid Sphinx doc errors with the # original doc string from tqdm.auto.tqdm verbose = kwargs.pop('verbose', True) # disable: Whether to disable the entire progressbar wrapper [default: False]. # If set to None, disable on non-TTY. # disable should be the opposite of verbose unless it's None disable = verbose if verbose is None else not verbose # disable should take precedence over verbose if both are set kwargs['disable'] = kwargs.pop('disable', disable) super(ProgressBar, self).__init__(*args, **kwargs)