developer.intra2net.com Git - pyi2ncommon/blob - test/test_log_helpers.py

   1 #!/usr/bin/env python3
   2
   3 """
   4 Test log_helpers.
   5
   6 .. codeauthor:: Intra2net AG <info@intra2net.com>
   7 """
   8
   9 import sys
  10 import unittest
  11 import logging
  12 from tempfile import mkstemp
  13 import os
  14 from os.path import isfile, basename
  15 import re
  16
  17 from src import log_helpers
  18
  19
  20 class LogHelperTest(unittest.TestCase):
  21
  22     def setUp(self):
  23         """Create temp file to write log to."""
  24         descriptor, self.temp_name = mkstemp(
  25             prefix='pyi2ncommon-test-log-helpers-', suffix='.log', text=True)
  26         self.temp_handle = os.fdopen(descriptor, 'at')
  27
  28     def tearDown(self):
  29         """Remove temp log file."""
  30         self.temp_handle.close()
  31         if isfile(self.temp_name):
  32             os.unlink(self.temp_name)
  33
  34     def get_logger_name(self):
  35         """Return a unique name for a logger."""
  36         return 'logtest-' + basename(self.temp_name)
  37
  38     def check_expected_contents(self, expected_contents):
  39         """
  40         Helper for other tests: open temp file, compare contents.
  41
  42         Ignores timestamp and line numbers
  43         """
  44         self.temp_handle.close()
  45         with open(self.temp_name, 'rt') as log_reader:
  46             for line_no, (actual_line, expect_line) in \
  47                     enumerate(zip(log_reader, expected_contents.splitlines())):
  48                 if re.match(r'\d{1,2}:\d{2}:\d{2}:\d{3}\s+', actual_line):
  49                     cmp_line = actual_line[13:].rstrip()
  50                 elif re.match(r'\s*File ".+", line \d+, in .+', actual_line):
  51                     cmp_line = '  TRACEBACK LINE REPLACED'
  52                 else:
  53                     cmp_line = actual_line.rstrip()
  54                 self.assertEqual(cmp_line, expect_line)
  55
  56     def test_short_level_format(self):
  57         """Tests that calls to :py:class:`ShortLevelFormatter` do not fail."""
  58         logger = logging.getLogger(self.get_logger_name())
  59         logger.setLevel(logging.DEBUG)
  60         handler = logging.StreamHandler(self.temp_handle)
  61         handler.setLevel(logging.DEBUG)
  62         formatter = log_helpers.ShortLevelFormatter(
  63             '%(asctime)s:%(msecs)03d %(shortlevel)s| %(msg)s'
  64             '   [regular levelname=%(levelname)s]',
  65             datefmt='%H:%M:%S')
  66         handler.setFormatter(formatter)
  67         logger.addHandler(handler)
  68
  69         # 'application' code
  70         logger.debug('debug message')
  71         logger.info('info message')
  72         logger.warning('warn message')
  73         logger.error('error message')
  74         logger.critical('critical message')
  75         logger.log(15, 'unknown level')
  76         logger.log(logging.NOTSET, 'level not set')
  77
  78         # add notice level
  79         notice = (logging.INFO + logging.WARNING)//2
  80         formatter.add_level(notice, 'note')
  81         logger.log(notice, 'more important than info but no warning nor error')
  82
  83         # try if exception formatting still works:
  84         try:
  85             logger.info('this is what an exception looks like:')
  86             impossible_result = 1/0
  87             logger.critical('just divided 1/0! The result is {0}'
  88                             .format(impossible_result))
  89         except ZeroDivisionError:
  90             logger.exception('1/0 still does not work!', exc_info=True)
  91
  92         # done
  93         logger.info('done testing')
  94
  95         # now check the file
  96         expected_contents = \
  97             'dbug| debug message   [regular levelname=DEBUG]\n' \
  98             'info| info message   [regular levelname=INFO]\n' \
  99             'warn| warn message   [regular levelname=WARNING]\n' \
 100             'err | error message   [regular levelname=ERROR]\n' \
 101             'crit| critical message   [regular levelname=CRITICAL]\n' \
 102             '????| unknown level   [regular levelname=Level 15]\n' \
 103             'note| more important than info but no warning nor error   [regular levelname=NOTICE]\n' \
 104             'info| this is what an exception looks like:   [regular levelname=INFO]\n' \
 105             'err | 1/0 still does not work!   [regular levelname=ERROR]\n' \
 106             'Traceback (most recent call last):\n' \
 107             '  TRACEBACK LINE REPLACED\n' \
 108             '    impossible_result = 1/0\n' \
 109             'ZeroDivisionError: division by zero\n' \
 110             'info| done testing   [regular levelname=INFO]\n'
 111         self.check_expected_contents(expected_contents)
 112
 113     def test_get_logger(self):
 114         log = log_helpers.get_logger('logger_test')
 115         log2 = log_helpers.get_logger('logger_test')
 116         self.assertEqual(log, log2)
 117
 118     def test_interesting_lines(self):
 119         log = log_helpers.get_logger(self.get_logger_name(),
 120                                      streams=self.temp_handle)
 121         for idx in range(20):
 122             log.log_count_if_interesting(idx)
 123
 124         expected_contents = 'info| Counter is at 1\n' \
 125                             'info| Counter is at 2\n' \
 126                             'info| Counter is at 3\n' \
 127                             'info| Counter is at 6\n' \
 128                             'info| Counter is at 10\n'
 129         self.check_expected_contents(expected_contents)
 130
 131     def test_error_in_formatting(self):
 132         """Ensure that forgotten args to not raise err but issue warning."""
 133         self.check_expected_contents(expected_contents)
 134
 135     def test_error_in_formatting(self):
 136         """Ensure that forgotten args to not raise err but issue warning."""
 137         log = log_helpers.get_logger(self.get_logger_name(),
 138                                      streams=self.temp_handle)
 139         log.warn('forgot to add argument {} and {1} and {cnf} to format string')
 140         log.warn('wrong number {} of arguments {}', 1)
 141
 142         expected_contents = \
 143             'warn| [LOG ARGS!] forgot to add argument {} and {1} and {cnf} ' \
 144             'to format string\n' \
 145             'warn| [LOG ARGS!] wrong number {} of arguments {}\n'
 146         self.check_expected_contents(expected_contents)
 147
 148
 149 if __name__ == '__main__':
 150     unittest.main()