From 6fbe31023f4bdc4f18e9ad8b14b33c1bdccf9eb8 Mon Sep 17 00:00:00 2001 From: voith Date: Mon, 19 Sep 2016 02:34:09 +0530 Subject: [PATCH] added tests for formatters --- frontera/logger/formatters/json.py | 16 +-- requirements/logging.txt | 1 + requirements/tests.txt | 1 + setup.py | 5 +- tests/test_formatters.py | 164 +++++++++++++++++++++++++++++ tests/utils.py | 54 ++++++++++ 6 files changed, 225 insertions(+), 16 deletions(-) create mode 100644 tests/test_formatters.py create mode 100644 tests/utils.py diff --git a/frontera/logger/formatters/json.py b/frontera/logger/formatters/json.py index 07510ee31..3efe1f24c 100644 --- a/frontera/logger/formatters/json.py +++ b/frontera/logger/formatters/json.py @@ -1,21 +1,7 @@ from __future__ import absolute_import from pythonjsonlogger.jsonlogger import JsonFormatter - -import datetime -from json import JSONEncoder - - -class DateTimeEncoder(JSONEncoder): - def default(self, obj): - if isinstance(obj, datetime.datetime): - return obj.isoformat() - elif isinstance(obj, datetime.date): - return obj.isoformat() - elif isinstance(obj, datetime.timedelta): - return (datetime.datetime.min + obj).time().isoformat() - else: - return super(DateTimeEncoder, self).default(obj) +from frontera.utils.encoders import DateTimeEncoder class JSONFormatter(JsonFormatter): diff --git a/requirements/logging.txt b/requirements/logging.txt index 3f4270d74..48b90f75c 100644 --- a/requirements/logging.txt +++ b/requirements/logging.txt @@ -1 +1,2 @@ colorlog>=2.4.0 +python-json-logger>=0.1.5 diff --git a/requirements/tests.txt b/requirements/tests.txt index 61abb3617..00c113ce0 100644 --- a/requirements/tests.txt +++ b/requirements/tests.txt @@ -10,3 +10,4 @@ msgpack-python kafka-python<=0.9.5 pytest-cov happybase>=1.0.0 +-r logging.txt diff --git a/setup.py b/setup.py index ceefd62e7..82745848b 100644 --- a/setup.py +++ b/setup.py @@ -54,6 +54,7 @@ ], 'logging': [ 'colorlog>=2.4.0', + 'python-json-logger>=0.1.5' ], 'tldextract': [ 'tldextract>=1.5.1', @@ -80,6 +81,8 @@ "scrapy>=0.24", "tldextract>=1.5.1", "SQLAlchemy>=1.0.0", - "cachetools" + "cachetools", + "colorlog>=2.4.0", + "python-json-logger>=0.1.5" ] ) diff --git a/tests/test_formatters.py b/tests/test_formatters.py new file mode 100644 index 000000000..1eee234bf --- /dev/null +++ b/tests/test_formatters.py @@ -0,0 +1,164 @@ +import unittest +import re +import json +import datetime + +from frontera.logger.formatters.text import DETAILED, SHORT +from frontera.logger.formatters.color import ColorFormatter +from frontera.logger.formatters.json import JSONFormatter +from frontera.logger.formatters import (EVENTS, + CONSOLE, + CONSOLE_MANAGER, + CONSOLE_BACKEND, + CONSOLE_DEBUGGING) +from tests.utils import LoggingCaptureMixin, SetupDefaultLoggingMixin + + +colors = { + 'bold_yellow': '\x1b[01;33m', + 'green': '\x1b[32m', + 'red': '\x1b[31m', + 'reset': '\x1b[0m', + 'white': '\x1b[37m', +} + + +class BaseTestFormatters(SetupDefaultLoggingMixin, LoggingCaptureMixin, unittest.TestCase): + def setUp(self): + super(BaseTestFormatters, self).setUp() + self.default_formatter = self.logger.handlers[0].formatter + + def tearDown(self): + super(BaseTestFormatters, self).setUp() + self.logger.handlers[0].formatter = self.default_formatter + + def setFormatter(self, formatter): + self.logger.handlers[0].setFormatter(formatter) + + +class TestFormatterText(BaseTestFormatters): + + def test_formatter_detailed(self): + self.setFormatter(DETAILED) + self.logger.debug('debug message') + self.assertRegexpMatches(self.logger_output.getvalue(), + r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d+ - frontera - DEBUG - debug message\n') + + def test_formatter_short(self): + self.setFormatter(SHORT) + self.logger.debug('debug message') + self.assertEqual(self.logger_output.getvalue(), '[frontera] DEBUG: debug message\n') + + +class TestFormatterColor(BaseTestFormatters): + + def test_formatter_color(self): + c = ColorFormatter( + format="%(log_color)s [%(name)s] %(message)s", + log_colors={ + "DEBUG": "white", + "INFO": "green", + "ERROR": "red", + }, + log_color_field="levelname") + self.setFormatter(c) + self.logger.debug('debug message') + self.logger.info('info message') + self.logger.error('error message') + self.assertEqual(self.logger_output.getvalue(), + '{white} [frontera] debug message{reset}\n' + '{green} [frontera] info message{reset}\n' + '{red} [frontera] error message{reset}\n'.format(white=colors['white'], + green=colors['green'], + red=colors['red'], + reset=colors['reset'])) + + def test_formatter_color_datefmt(self): + c = ColorFormatter( + format="%(log_color)s %(asctime)s [%(name)s] %(message)s", + log_colors={ + "DEBUG": "white", + "INFO": "green", + "ERROR": "red", + }, + datefmt='%d-%m-%Y %H:%M:%S', + log_color_field="levelname") + self.setFormatter(c) + self.logger.debug('debug message') + self.assertRegexpMatches(self.logger_output.getvalue(), + '{white} \d{{2}}-\d{{2}}-\d{{4}} \d{{2}}:\d{{2}}:\d{{2}} ' + '\\[frontera\\] debug message{reset}\n'.format( + white=re.escape(colors['white']), + reset=re.escape(colors['reset']))) + + +class TestFormatterJson(BaseTestFormatters): + + def setUp(self): + super(TestFormatterJson, self).setUp() + self.setFormatter(JSONFormatter()) + + def test_formatter_json_log_text(self): + self.logger.debug('debug message') + self.assertEqual(json.loads(self.logger_output.getvalue())['message'], 'debug message') + + def test_formatter_json_log_dict(self): + dct_msg = { + 'message': 'debug message', + 'extra': 'value', + } + self.logger.debug(dct_msg) + json_log = json.loads(self.logger_output.getvalue()) + self.assertEqual(json_log.get('message'), 'debug message') + self.assertEqual(json_log.get('extra'), 'value') + + def test_formatter_json_log_datetime_objects(self): + dct_msg = { + 'message': 'debug message', + 'datetime': datetime.datetime(2016, 9, 19, 23, 59), + 'date': datetime.date(2016, 9, 20), + 'timedelta': datetime.datetime(2016, 9, 19, 23, 59) - datetime.datetime(2016, 9, 19, 23, 50), + } + self.logger.debug(dct_msg) + json_log = json.loads(self.logger_output.getvalue()) + self.assertEqual(json_log.get('message'), 'debug message') + self.assertEqual(json_log.get('datetime'), '2016-09-19T23:59:00') + self.assertEqual(json_log.get('date'), '2016-09-20') + self.assertEqual(json_log.get('timedelta'), '00:09:00') + + +class TestFormatterMiscellaneous(BaseTestFormatters): + def test_formatter_events(self): + + self.setFormatter(EVENTS) + self.logger.debug('starting frontier', extra={'event': 'FRONTIER_START'}) + self.assertRegexpMatches(self.logger_output.getvalue(), + r'{bold_yellow}\d{{4}}-\d{{2}}-\d{{2}} \d{{2}}:\d{{2}}:\d{{2}},\d+ ' + r'FRONTIER_START starting frontier{reset}\n'. + format(bold_yellow=re.escape(colors['bold_yellow']), + reset=re.escape(colors['reset']))) + + def test_formatter_console(self): + self.assert_logs(CONSOLE) + + def test_formatter_console_manager(self): + self.assert_logs(CONSOLE_MANAGER) + + def test_formatter_console_backend(self): + self.assert_logs(CONSOLE_BACKEND) + + def test_formatter_console_debugging(self): + self.assert_logs(CONSOLE_DEBUGGING) + + def assert_logs(self, formatter): + self.setFormatter(formatter) + self.logger.debug('debug message') + self.logger.info('info message') + self.logger.error('error message') + self.assertEqual(self.logger_output.getvalue(), + '{white}[frontera] debug message{reset}\n' + '{green}[frontera] info message{reset}\n' + '{red}[frontera] error message{reset}\n'.format(white=colors['white'], + green=colors['green'], + red=colors['red'], + reset=colors['reset'])) diff --git a/tests/utils.py b/tests/utils.py new file mode 100644 index 000000000..44ebd60fb --- /dev/null +++ b/tests/utils.py @@ -0,0 +1,54 @@ +import six +import logging +import logging.config + + +DEFAULT_LOGGING = { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'message': { + 'format': '%(message)s' + } + }, + 'handlers': { + 'console': { + 'level': 'DEBUG', + 'class': 'logging.StreamHandler', + 'formatter': 'message', + } + }, + 'loggers': { + 'frontera': { + 'handlers': ['console'], + 'level': 'DEBUG', + }, + } +} + + +class LoggingCaptureMixin(object): + """ + Capture the output from the 'frontera' logger and store it on the class's + logger_output attribute. + """ + + def setUp(self): + self.logger = logging.getLogger('frontera') + self.old_stream = self.logger.handlers[0].stream + self.logger_output = six.StringIO() + self.logger.handlers[0].stream = self.logger_output + + def tearDown(self): + self.logger.handlers[0].stream = self.old_stream + + +class SetupDefaultLoggingMixin(object): + @classmethod + def setUpClass(cls): + super(SetupDefaultLoggingMixin, cls).setUpClass() + logging.config.dictConfig(DEFAULT_LOGGING) + + @classmethod + def tearDownClass(cls): + super(SetupDefaultLoggingMixin, cls).tearDownClass()