logger.py 5.0 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156
  1. """
  2. Helpers for logging.
  3. This module needs much love to become useful.
  4. """
  5. # Author: Gael Varoquaux <gael dot varoquaux at normalesup dot org>
  6. # Copyright (c) 2008 Gael Varoquaux
  7. # License: BSD Style, 3 clauses.
  8. from __future__ import print_function
  9. import time
  10. import sys
  11. import os
  12. import shutil
  13. import logging
  14. import pprint
  15. from .disk import mkdirp
  16. def _squeeze_time(t):
  17. """Remove .1s to the time under Windows: this is the time it take to
  18. stat files. This is needed to make results similar to timings under
  19. Unix, for tests
  20. """
  21. if sys.platform.startswith('win'):
  22. return max(0, t - .1)
  23. else:
  24. return t
  25. def format_time(t):
  26. t = _squeeze_time(t)
  27. return "%.1fs, %.1fmin" % (t, t / 60.)
  28. def short_format_time(t):
  29. t = _squeeze_time(t)
  30. if t > 60:
  31. return "%4.1fmin" % (t / 60.)
  32. else:
  33. return " %5.1fs" % (t)
  34. def pformat(obj, indent=0, depth=3):
  35. if 'numpy' in sys.modules:
  36. import numpy as np
  37. print_options = np.get_printoptions()
  38. np.set_printoptions(precision=6, threshold=64, edgeitems=1)
  39. else:
  40. print_options = None
  41. out = pprint.pformat(obj, depth=depth, indent=indent)
  42. if print_options:
  43. np.set_printoptions(**print_options)
  44. return out
  45. ###############################################################################
  46. # class `Logger`
  47. ###############################################################################
  48. class Logger(object):
  49. """ Base class for logging messages.
  50. """
  51. def __init__(self, depth=3):
  52. """
  53. Parameters
  54. ----------
  55. depth: int, optional
  56. The depth of objects printed.
  57. """
  58. self.depth = depth
  59. def warn(self, msg):
  60. logging.warning("[%s]: %s" % (self, msg))
  61. def debug(self, msg):
  62. # XXX: This conflicts with the debug flag used in children class
  63. logging.debug("[%s]: %s" % (self, msg))
  64. def format(self, obj, indent=0):
  65. """Return the formatted representation of the object."""
  66. return pformat(obj, indent=indent, depth=self.depth)
  67. ###############################################################################
  68. # class `PrintTime`
  69. ###############################################################################
  70. class PrintTime(object):
  71. """ Print and log messages while keeping track of time.
  72. """
  73. def __init__(self, logfile=None, logdir=None):
  74. if logfile is not None and logdir is not None:
  75. raise ValueError('Cannot specify both logfile and logdir')
  76. # XXX: Need argument docstring
  77. self.last_time = time.time()
  78. self.start_time = self.last_time
  79. if logdir is not None:
  80. logfile = os.path.join(logdir, 'joblib.log')
  81. self.logfile = logfile
  82. if logfile is not None:
  83. mkdirp(os.path.dirname(logfile))
  84. if os.path.exists(logfile):
  85. # Rotate the logs
  86. for i in range(1, 9):
  87. try:
  88. shutil.move(logfile + '.%i' % i,
  89. logfile + '.%i' % (i + 1))
  90. except:
  91. "No reason failing here"
  92. # Use a copy rather than a move, so that a process
  93. # monitoring this file does not get lost.
  94. try:
  95. shutil.copy(logfile, logfile + '.1')
  96. except:
  97. "No reason failing here"
  98. try:
  99. with open(logfile, 'w') as logfile:
  100. logfile.write('\nLogging joblib python script\n')
  101. logfile.write('\n---%s---\n' % time.ctime(self.last_time))
  102. except:
  103. """ Multiprocessing writing to files can create race
  104. conditions. Rather fail silently than crash the
  105. computation.
  106. """
  107. # XXX: We actually need a debug flag to disable this
  108. # silent failure.
  109. def __call__(self, msg='', total=False):
  110. """ Print the time elapsed between the last call and the current
  111. call, with an optional message.
  112. """
  113. if not total:
  114. time_lapse = time.time() - self.last_time
  115. full_msg = "%s: %s" % (msg, format_time(time_lapse))
  116. else:
  117. # FIXME: Too much logic duplicated
  118. time_lapse = time.time() - self.start_time
  119. full_msg = "%s: %.2fs, %.1f min" % (msg, time_lapse,
  120. time_lapse / 60)
  121. print(full_msg, file=sys.stderr)
  122. if self.logfile is not None:
  123. try:
  124. with open(self.logfile, 'a') as f:
  125. print(full_msg, file=f)
  126. except:
  127. """ Multiprocessing writing to files can create race
  128. conditions. Rather fail silently than crash the
  129. calculation.
  130. """
  131. # XXX: We actually need a debug flag to disable this
  132. # silent failure.
  133. self.last_time = time.time()