def test_delegating_other_process(self):
"""Test delegating a call from another process
"""
called = [0]
called_from = []
def target():
"""Target function"""
called[0] += 1
called_from.append(os.getpid())
delegated = DelegateCall(target)
def process_target():
"""Sub-process
"""
delegated()
process = multiprocessing.Process(target=process_target)
self.assertEqual(called[0], 0)
process.start()
process.join()
delegated.join()
self.assertEqual(called[0], 1)
self.assertEqual(called_from[0], os.getpid())
def __init__(self,
filename,
level=logging.DEBUG,
no_backups=0):
"""Initializer
"""
# Init base class
super(MPRotLogHandler, self).__init__(level=level)
# Check if we need to roll_over later
roll_over_file = os.path.isfile(filename)
# Prepare the formatter
file_formatter = ColorFormatter(
FILE_FORMAT, False)
# Setup the actual handler for the log files
self._file_handler = logging.handlers.RotatingFileHandler(
filename=filename,
backupCount=no_backups)
self._file_handler.setLevel(level)
self.setFormatter(file_formatter)
if roll_over_file:
self._file_handler.doRollover()
# Emit messages in the main process
self._delegate_emit = DelegateCall(self._file_handler.emit)
def test_delegating_other_process(self):
"""Test delegating a call from another process
"""
called = [0]
called_from = []
def target():
"""Target function"""
called[0] += 1
called_from.append(os.getpid())
delegated = DelegateCall(target)
def process_target():
"""Sub-process
"""
delegated()
process = multiprocessing.Process(target=process_target)
self.assertEqual(called[0], 0)
process.start()
process.join()
delegated.join()
self.assertEqual(called[0], 1)
self.assertEqual(called_from[0], os.getpid())
def test_delegating_same_process(self):
"""Test delegating a call from the same process
"""
called = [0]
def target():
"""Target function"""
called[0] += 1
delegated = DelegateCall(target)
self.assertEqual(called[0], 0)
delegated()
delegated.join()
self.assertEqual(called[0], 1)
def test_delegating_same_process(self):
"""Test delegating a call from the same process
"""
called = [0]
def target():
"""Target function"""
called[0] += 1
delegated = DelegateCall(target)
self.assertEqual(called[0], 0)
delegated()
delegated.join()
self.assertEqual(called[0], 1)
def __init__(self,
console_level=logging.INFO,
filename=None,
file_level=logging.DEBUG,
no_backups=5):
"""Initializer
Creates a logger that logs messages at or above the console_level
(by default logging.INFO) to stderr. If a filename is given,
messages at or above the file level (by default logging.DEBUG)
will be logged to the file with the specified name. If no_backups
is larger than 0, the file will be rotated at every call of init.
"""
# Container and aggregator for the timings
self.timings = OrderedDict()
self._delegate_process_timings = DelegateCall(self._process_timings)
super(TimingLogger, self).__init__(console_level,
filename,
file_level,
no_backups)
def test_delegating_exception(self):
"""Test delegating a call from the same process with an exception
"""
called = [0]
_buf_out = StringIO()
buf_err = StringIO()
with stdout_err_redirector(_buf_out, buf_err):
def target():
"""Target function"""
called[0] += 1
raise RuntimeError()
delegated = DelegateCall(target)
self.assertEqual(called[0], 0)
delegated()
delegated.join()
self.assertEqual(called[0], 1)
self.assertRegexpMatches(buf_err.getvalue(), 'RuntimeError')
def test_delegating_exception(self):
"""Test delegating a call from the same process with an exception
"""
called = [0]
_buf_out = StringIO()
buf_err = StringIO()
with stdout_err_redirector(_buf_out, buf_err):
def target():
"""Target function"""
called[0] += 1
raise RuntimeError()
delegated = DelegateCall(target)
self.assertEqual(called[0], 0)
delegated()
delegated.join()
self.assertEqual(called[0], 1)
self.assertRegexpMatches(buf_err.getvalue(), 'RuntimeError')
class TimingLogger(Logger):
"""Provides a logger with a `timed` context.
Calling code in the `timed` context will collect execution timing
statistics.
"""
def __init__(self,
console_level=logging.INFO,
filename=None,
file_level=logging.DEBUG,
no_backups=5):
"""Initializer
Creates a logger that logs messages at or above the console_level
(by default logging.INFO) to stderr. If a filename is given,
messages at or above the file level (by default logging.DEBUG)
will be logged to the file with the specified name. If no_backups
is larger than 0, the file will be rotated at every call of init.
"""
# Container and aggregator for the timings
self.timings = OrderedDict()
self._delegate_process_timings = DelegateCall(self._process_timings)
super(TimingLogger, self).__init__(console_level,
filename,
file_level,
no_backups)
@contextmanager
def timed(self, msg='', level=logging.DEBUG, save_result=True):
"""Timer to be used in a with block. If the level is not None, logs
the timing at the specified level. If save_result is True,
captures the result in the timings dictionary.
"""
# At the start of the with block
start = datetime.now()
yield
# After leaving the with block
stop = datetime.now()
elapsed_time = (stop - start).total_seconds()
# Log if necessary
if level is not None:
self.log(level,
msg + " took %0.6fs" % elapsed_time)
# Save result if necessary
if save_result:
self._delegate_process_timings((msg, elapsed_time))
def print_timings(self):
"""Prints a summary of the timings collected with 'timed'.
"""
# Make sure the delegated calls are done
self._delegate_process_timings.join()
if len(self.timings.items()) > 0:
# Announce timings
printers.print_blue( # pylint: disable=no-member
"Timing Summary:")
# Iterate over all saved timings
for msg, times in self.timings.items():
no_timings = len(times)
if no_timings > 1:
times_array = np.array(times)
message = ("\t'%s' (timed %d times): "
"total = %0.6fs, "
"min = %0.6fs, max = %0.6fs, median = %0.6fs"
% (msg,
no_timings,
np.sum(times_array),
np.min(times_array),
np.max(times_array),
np.median(times_array)))
else:
message = "\t'%s': %0.6fs" % (msg, times[0])
print(message)
else:
printers.print_blue( # pylint: disable=no-member
"No timings stored...")
def _process_timings(self, data):
"""Aggregates the timing data in the dict
"""
# Destructure the data
msg, elapsed_time = data
# Save the result
if msg not in self.timings:
self.timings[msg] = [elapsed_time]
else:
self.timings[msg].append(elapsed_time)
def close(self):
"""Make sure the delegated calls are all done...
"""
self._delegate_process_timings.join()
super(TimingLogger, self).close()
class MPRotLogHandler(logging.Handler):
"""Multiprocessing-safe handler for rotating log files
"""
def __init__(self,
filename,
level=logging.DEBUG,
no_backups=0):
"""Initializer
"""
# Init base class
super(MPRotLogHandler, self).__init__(level=level)
# Check if we need to roll_over later
roll_over_file = os.path.isfile(filename)
# Prepare the formatter
file_formatter = ColorFormatter(
FILE_FORMAT, False)
# Setup the actual handler for the log files
self._file_handler = logging.handlers.RotatingFileHandler(
filename=filename,
backupCount=no_backups)
self._file_handler.setLevel(level)
self.setFormatter(file_formatter)
if roll_over_file:
self._file_handler.doRollover()
# Emit messages in the main process
self._delegate_emit = DelegateCall(self._file_handler.emit)
def setFormatter(self, formatter):
"""Overload the setFormatter method"""
super(MPRotLogHandler, self).setFormatter(formatter)
self._file_handler.setFormatter(formatter)
def close(self):
self._delegate_emit.join()
self._file_handler.close()
super(MPRotLogHandler, self).close()
def _serializable_record(self, record):
"""Ensures that exc_info and args are serializable by converting
everything to a string.
"""
if record.name:
record.name = str(record.name)
if record.args:
record.msg = record.msg % record.args
record.args = None
if record.exc_info:
record.exc_text = self.format(record)
record.exc_info = None
return record
def emit(self, record):
"""Emits logged message by delegating it
"""
try:
formated = self._serializable_record(record)
self._delegate_emit(formated)
except (KeyboardInterrupt, SystemExit):
raise
# This should really catch every other exception!
except Exception: # pylint: disable=broad-except
self.handleError(record)
