Merge pull request #2753 from avaris/log-dict

Fix dictionary logging in formatter
This commit is contained in:
Justin Mayer 2020-05-10 07:32:54 +02:00 committed by GitHub
commit ca1c58e201
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
3 changed files with 108 additions and 43 deletions

View file

@ -2,6 +2,7 @@ import logging
import os
import sys
from collections import defaultdict
from collections.abc import Mapping
__all__ = [
'init'
@ -18,9 +19,10 @@ class BaseFormatter(logging.Formatter):
record.__dict__['customlevelname'] = customlevel
# format multiline messages 'nicely' to make it clear they are together
record.msg = record.msg.replace('\n', '\n | ')
record.args = tuple(arg.replace('\n', '\n | ') if
isinstance(arg, str) else
arg for arg in record.args)
if not isinstance(record.args, Mapping):
record.args = tuple(arg.replace('\n', '\n | ') if
isinstance(arg, str) else
arg for arg in record.args)
return super().format(record)
def formatException(self, ei):

View file

@ -208,6 +208,15 @@ class LogCountHandler(BufferingHandler):
(level is None or l.levelno == level)
])
def count_formatted_logs(self, msg=None, level=None):
return len([
l
for l
in self.buffer
if (msg is None or re.search(msg, self.format(l))) and
(level is None or l.levelno == level)
])
class LoggedTestCase(unittest.TestCase):
"""A test case that captures log messages."""

View file

@ -1,6 +1,7 @@
import logging
import unittest
from collections import defaultdict
from contextlib import contextmanager
from pelican import log
from pelican.tests.support import LogCountHandler
@ -11,6 +12,7 @@ class TestLog(unittest.TestCase):
super().setUp()
self.logger = logging.getLogger(__name__)
self.handler = LogCountHandler()
self.handler.setFormatter(log.get_formatter())
self.logger.addHandler(self.handler)
def tearDown(self):
@ -24,55 +26,107 @@ class TestLog(unittest.TestCase):
log.LimitFilter._threshold = 5
log.LimitFilter._group_count = defaultdict(int)
@contextmanager
def reset_logger(self):
try:
yield None
finally:
self._reset_limit_filter()
self.handler.flush()
def test_log_formatter(self):
counter = self.handler.count_formatted_logs
with self.reset_logger():
# log simple case
self.logger.warning('Log %s', 'test')
self.assertEqual(
counter('Log test', logging.WARNING),
1)
with self.reset_logger():
# log multiline message
self.logger.warning('Log\n%s', 'test')
# Log
# | test
self.assertEqual(
counter('Log', logging.WARNING),
1)
self.assertEqual(
counter(' | test', logging.WARNING),
1)
with self.reset_logger():
# log multiline argument
self.logger.warning('Log %s', 'test1\ntest2')
# Log test1
# | test2
self.assertEqual(
counter('Log test1', logging.WARNING),
1)
self.assertEqual(
counter(' | test2', logging.WARNING),
1)
with self.reset_logger():
# log single list
self.logger.warning('Log %s', ['foo', 'bar'])
self.assertEqual(
counter(r"Log \['foo', 'bar'\]", logging.WARNING),
1)
with self.reset_logger():
# log single dict
self.logger.warning('Log %s', {'foo': 1, 'bar': 2})
self.assertEqual(
# dict order is not guaranteed
counter(r"Log {'.*': \d, '.*': \d}", logging.WARNING),
1)
def test_log_filter(self):
def do_logging():
for i in range(5):
self.logger.warning('Log %s', i)
self.logger.warning('Another log %s', i)
# no filter
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
5)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
self.handler.flush()
self._reset_limit_filter()
with self.reset_logger():
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
5)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
# filter by template
log.LimitFilter._ignore.add((logging.WARNING, 'Log %s'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
0)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
self.handler.flush()
self._reset_limit_filter()
with self.reset_logger():
log.LimitFilter._ignore.add((logging.WARNING, 'Log %s'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
0)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
# filter by exact message
log.LimitFilter._ignore.add((logging.WARNING, 'Log 3'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
4)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
self.handler.flush()
self._reset_limit_filter()
with self.reset_logger():
log.LimitFilter._ignore.add((logging.WARNING, 'Log 3'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
4)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
5)
# filter by both
log.LimitFilter._ignore.add((logging.WARNING, 'Log 3'))
log.LimitFilter._ignore.add((logging.WARNING, 'Another log %s'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
4)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
0)
self.handler.flush()
self._reset_limit_filter()
with self.reset_logger():
log.LimitFilter._ignore.add((logging.WARNING, 'Log 3'))
log.LimitFilter._ignore.add((logging.WARNING, 'Another log %s'))
do_logging()
self.assertEqual(
self.handler.count_logs('Log \\d', logging.WARNING),
4)
self.assertEqual(
self.handler.count_logs('Another log \\d', logging.WARNING),
0)