1# -*- Mode: python; tab-width: 4; indent-tabs-mode:nil; coding:utf-8 -*- 2# vim: tabstop=4 expandtab shiftwidth=4 softtabstop=4 3# 4# MDAnalysis --- https://www.mdanalysis.org 5# Copyright (c) 2006-2017 The MDAnalysis Development Team and contributors 6# (see the file AUTHORS for the full list of names) 7# 8# Released under the GNU Public Licence, v2 or any higher version 9# 10# Please cite your use of MDAnalysis in published work: 11# 12# R. J. Gowers, M. Linke, J. Barnoud, T. J. E. Reddy, M. N. Melo, S. L. Seyler, 13# D. L. Dotson, J. Domanski, S. Buchoux, I. M. Kenney, and O. Beckstein. 14# MDAnalysis: A Python package for the rapid analysis of molecular dynamics 15# simulations. In S. Benthall and S. Rostrup editors, Proceedings of the 15th 16# Python in Science Conference, pages 102-109, Austin, TX, 2016. SciPy. 17# 18# N. Michaud-Agrawal, E. J. Denning, T. B. Woolf, and O. Beckstein. 19# MDAnalysis: A Toolkit for the Analysis of Molecular Dynamics Simulations. 20# J. Comput. Chem. 32 (2011), 2319--2327, doi:10.1002/jcc.21787 21# 22 23 24"""Setting up logging --- :mod:`MDAnalysis.lib.log` 25==================================================== 26 27Configure logging for MDAnalysis. Import this module if logging is 28desired in application code. 29 30Logging to a file and the console is set up by default as described 31under `logging to multiple destinations`_. 32 33The top level logger of the library is named *MDAnalysis* by 34convention; a simple logger that writes to the console and logfile can 35be created with the :func:`create` function. This only has to be done 36*once*. For convenience, the default MDAnalysis logger can be created 37with :func:`MDAnalysis.start_logging`:: 38 39 import MDAnalysis 40 MDAnalysis.start_logging() 41 42Once this has been done, MDAnalysis will write messages to the logfile 43(named `MDAnalysis.log` by default but this can be changed with the 44optional argument to :func:`~MDAnalysis.start_logging`). 45 46Any code can log to the MDAnalysis logger by using :: 47 48 import logging 49 logger = logging.getLogger('MDAnalysis.MODULENAME') 50 51 # use the logger, for example at info level: 52 logger.info("Starting task ...") 53 54The important point is that the name of the logger begins with 55"MDAnalysis.". 56 57.. _logging to multiple destinations: 58 http://docs.python.org/library/logging.html?#logging-to-multiple-destinations 59 60Note 61---- 62The :mod:`logging` module in the standard library contains in depth 63documentation about using logging. 64 65 66Convenience functions 67--------------------- 68 69Two convenience functions at the top level make it easy to start and 70stop the default *MDAnalysis* logger. 71 72.. autofunction:: MDAnalysis.start_logging 73.. autofunction:: MDAnalysis.stop_logging 74 75 76Other functions and classes for logging purposes 77------------------------------------------------ 78 79.. autogenerated, see Online Docs 80 81""" 82from __future__ import print_function, division, absolute_import 83 84import sys 85import logging 86import re 87import warnings 88 89from .. import version 90 91 92def start_logging(logfile="MDAnalysis.log", version=version.__version__): 93 """Start logging of messages to file and console. 94 95 The default logfile is named `MDAnalysis.log` and messages are 96 logged with the tag *MDAnalysis*. 97 """ 98 create("MDAnalysis", logfile=logfile) 99 logging.getLogger("MDAnalysis").info( 100 "MDAnalysis %s STARTED logging to %r", version, logfile) 101 102 103def stop_logging(): 104 """Stop logging to logfile and console.""" 105 logger = logging.getLogger("MDAnalysis") 106 logger.info("MDAnalysis STOPPED logging") 107 clear_handlers(logger) # this _should_ do the job... 108 109 110def create(logger_name="MDAnalysis", logfile="MDAnalysis.log"): 111 """Create a top level logger. 112 113 - The file logger logs everything (including DEBUG). 114 - The console logger only logs INFO and above. 115 116 Logging to a file and the console as described under `logging to 117 multiple destinations`_. 118 119 The top level logger of MDAnalysis is named *MDAnalysis*. Note 120 that we are configuring this logger with console output. If a root 121 logger also does this then we will get two output lines to the 122 console. 123 124 .. _logging to multiple destinations: 125 http://docs.python.org/library/logging.html?#logging-to-multiple-destinations 126 """ 127 128 logger = logging.getLogger(logger_name) 129 130 logger.setLevel(logging.DEBUG) 131 132 # handler that writes to logfile 133 logfile_handler = logging.FileHandler(logfile) 134 logfile_formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s') 135 logfile_handler.setFormatter(logfile_formatter) 136 logger.addHandler(logfile_handler) 137 138 # define a Handler which writes INFO messages or higher to the sys.stderr 139 console_handler = logging.StreamHandler() 140 console_handler.setLevel(logging.INFO) 141 # set a format which is simpler for console use 142 formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s') 143 console_handler.setFormatter(formatter) 144 logger.addHandler(console_handler) 145 146 return logger 147 148 149def clear_handlers(logger): 150 """clean out handlers in the library top level logger 151 152 (only important for reload/debug cycles...) 153 154 """ 155 for h in logger.handlers: 156 logger.removeHandler(h) 157 158 159class NullHandler(logging.Handler): 160 """Silent Handler. 161 162 Useful as a default:: 163 164 h = NullHandler() 165 logging.getLogger("MDAnalysis").addHandler(h) 166 del h 167 168 see the advice on logging and libraries in 169 http://docs.python.org/library/logging.html?#configuring-logging-for-a-library 170 """ 171 def emit(self, record): 172 pass 173 174 175def echo(s='', replace=False, newline=True): 176 r"""Simple string output that immediately prints to the console. 177 178 The string `s` is modified according to the keyword arguments and then 179 printed to :const:`sys.stderr`, which is immediately flushed. 180 181 Parameters 182 ---------- 183 s : str 184 The string to output. 185 replace : bool 186 If ``True``, the string will be printed on top of the current line. In 187 practice, ``\r`` is added at the beginning of the string. 188 newline : bool 189 If ``True``, a newline is added at the end of the string. 190 191 """ 192 if replace: 193 s = '\r' + s 194 if newline: 195 end='\n' 196 else: 197 end='' 198 print(s, file=sys.stderr, end=end) 199 sys.stderr.flush() 200 201 202def _new_format(template, variables): 203 """Format a string that follows the {}-based syntax. 204 """ 205 return template.format(**variables) 206 207 208def _legacy_format(template, variables): 209 """Format a string that follows the %-based syntax. 210 """ 211 return template % variables 212 213 214def _guess_string_format(template): 215 """Guess if the template follow {}-based or %-based syntax. 216 """ 217 match = re.search(r'%\((step|numsteps|percentage)\)', template) 218 if match is None: 219 return _new_format 220 else: 221 return _legacy_format 222 223 224class ProgressMeter(object): 225 r"""Simple progress meter 226 227 The :class:`ProgressMeter` class can be used to show running progress such 228 as frames processed or percentage done to give the user feedback on the 229 duration and progress of a task. It is structures as a class that is 230 customized on instantation (e.g., using a custom `format` string and the 231 expected total number of frames to be processed). Within a processing loop, 232 call :meth:`echo` with the current frame number to print the output to 233 stderr. 234 235 Parameters 236 ---------- 237 numsteps: int 238 total number of steps 239 interval: int 240 only calculate and print progress every `interval` steps [10] 241 format: str 242 a format string with Python variable interpolation. Allowed 243 values: 244 245 * *step*: current step 246 * *numsteps*: total number of steps as supplied in *numsteps* 247 * *percentage*: percentage of total 248 249 The last call to :meth:`ProgressMeter.print` will automatically 250 issue a newline ``\n``. 251 252 If *format* is ``None`` then the default is used:: 253 254 Step {step:5d}/{numsteps} [{percentage:5.1f}%] 255 256 offset: int 257 number to add to *step*; e.g. if *step* is 0-based (as in MDAnalysis) 258 then one should set *offset* = 1; for 1-based steps, choose 0. [1] 259 verbose: bool 260 If ``False``, disable all output, ``True`` print all messages as 261 specified, [``True``] 262 dynamic: bool 263 If ``True``, each line will be printed on top of the previous one. 264 This is done by prepedind the format with ``\r``. [``True``] 265 format_handling: str 266 how to handle the format string. Allowed values are: 267 268 * *new*: the format string uses {}-based formating 269 * *legacy*: the format string uses %-basedd formating 270 * *auto*: default, try to guess how the format string should be 271 handled 272 273 274 Examples 275 -------- 276 The typical use case is to show progress as frames of a trajectory are 277 processed:: 278 279 u = Universe(PSF, DCD) 280 pm = ProgressMeter(u.trajectory.n_frames, interval=100) 281 for ts in u.trajectory: 282 pm.echo(ts.frame) 283 ... 284 285 For a trajectory with 10000 frames this will produce output such 286 as :: 287 288 Step 100/10000 [ 1.0%] 289 Step 200/10000 [ 2.0%] 290 ... 291 292 The default *format* string is:: 293 294 Step {step:5d}/{numsteps} [{percentage:5.1f}%] 295 296 By default, each line of the progress meter is displayed on top of the 297 previous one. To prevent this behaviour, set the `dynamic` keyword to 298 ``False``. 299 300 It is possible to embed (almost) arbitrary additional data in the 301 format string, for example a current RMSD value:: 302 303 format_line = "RMSD {rmsd:5.2f} at {step:5d}/{numsteps} [{percentage:5.1f}%]" 304 pm = ProgressMeter(u.trajectory.n_frames, 305 interval=100, format=format_line) 306 for ts in u.trajectory: 307 pm.echo(ts.frame, rmsd=current_rmsd) 308 ... 309 310 This will print something like:: 311 312 RMSD 1.02 at 100/10000 [ 1.0%] 313 RMSD 1.89 at 200/10000 [ 2.0%] 314 ... 315 316 .. versionchanged:: 0.8 317 Keyword argument *quiet* was added. 318 319 .. versionchanged:: 0.16 320 Keyword argument *dynamic* replaces ``\r`` in the format. 321 322 .. deprecated:: 0.16 323 Keyword argument *quiet* is deprecated in favor of *verbose*. 324 325 """ 326 327 def __init__(self, numsteps, format=None, interval=10, offset=1, 328 verbose=True, dynamic=True, 329 format_handling='auto'): 330 self.numsteps = numsteps 331 self.interval = int(interval) 332 self.offset = int(offset) 333 self.verbose = verbose 334 self.dynamic = dynamic 335 self.numouts = -1 336 337 if format is None: 338 format = "Step {step:5d}/{numsteps} [{percentage:5.1f}%]" 339 self.format_handler = _new_format 340 else: 341 if format_handling == 'auto': 342 self.format_handler = _guess_string_format(format) 343 else: 344 self.format_handler = {'new': _new_format, 345 'legacy': _legacy_format}[format_handling] 346 self.format = format 347 self.step = 0 348 self.percentage = 0.0 349 assert numsteps > 0, "numsteps step must be >0" 350 assert interval > 0, "interval step must be >0" 351 352 def update(self, step, **kwargs): 353 """Update the state of the ProgressMeter. 354 355 *kwargs* are additional attributes that can be references in 356 the format string. 357 """ 358 self.step = step + self.offset 359 self.percentage = 100. * self.step / self.numsteps 360 for k, v in kwargs.items(): 361 setattr(self, k, v) 362 363 self.numouts += 1 364 365 def echo(self, step, **kwargs): 366 """Print the state to stderr, but only every *interval* steps. 367 368 1) calls :meth:`~ProgressMeter.update` 369 2) writes step and percentage to stderr with :func:`echo`, 370 using the format string (in :attr:`ProgressMeter.format`) 371 372 The last step is always shown, even if not on an *interval*, and a 373 carriage return is replaced with a new line for a cleaner display. 374 375 *kwargs* are additional attributes that can be references in 376 the format string. 377 378 .. Note:: If *verbose* = ``False`` has been set in the 379 constructor or if :attr:`ProgressMeter.verbose` has 380 been set to ``False``, then no messages will be 381 printed. 382 """ 383 if not self.verbose: 384 return 385 self.update(step, **kwargs) 386 format = self.format 387 newline = not self.dynamic 388 if self.step == self.numsteps: 389 newline = True 390 elif self.numouts % self.interval == 0: 391 pass 392 else: 393 return 394 echo(self.format_handler(format, vars(self)), 395 replace=self.dynamic, newline=newline) 396