diff --git a/docs/ENVIRONMENT.rst b/docs/ENVIRONMENT.rst index ad7c46b8..4b45798f 100644 --- a/docs/ENVIRONMENT.rst +++ b/docs/ENVIRONMENT.rst @@ -14,10 +14,18 @@ Global/Universal Log --- +- **PATRONI\_LOG\_TYPE**: sets the format of logs. Can be either **plain** or **json**. To use **json** format, you must have the :ref:`jsonlogger ` installed. The default value is **plain**. - **PATRONI\_LOG\_LEVEL**: sets the general logging level. Default value is **INFO** (see `the docs for Python logging `_) - **PATRONI\_LOG\_TRACEBACK\_LEVEL**: sets the level where tracebacks will be visible. Default value is **ERROR**. Set it to **DEBUG** if you want to see tracebacks only if you enable **PATRONI\_LOG\_LEVEL=DEBUG**. -- **PATRONI\_LOG\_FORMAT**: sets the log formatting string. Default value is **%(asctime)s %(levelname)s: %(message)s** (see `the LogRecord attributes `_) +- **PATRONI\_LOG\_FORMAT**: sets the log formatting string. If the log type is **plain**, the log format should be a string. + Refer to `the LogRecord attributes `_ for + available attributes. If the log type is **json**, the log format can be a list in addition to a string. Each list + item should correspond to LogRecord attributes. Be cautious that only the field name is required, and the **%(** + and **)** should be omitted. If you wish to print a log field with a different key name, use a dictionary where + the dictionary key is the log field, and the value is the name of the field you want to be printed in the log. + Default value is **%(asctime)s %(levelname)s: %(message)s** - **PATRONI\_LOG\_DATEFORMAT**: sets the datetime formatting string. (see the `formatTime() documentation `_) +- **PATRONI\_LOG\_STATIC\_FIELDS**: add additional fields to the log. This option is only available when the log type is set to **json**. Example ``PATRONI_LOG_STATIC_FIELDS="{app: patroni}"`` - **PATRONI\_LOG\_MAX\_QUEUE\_SIZE**: Patroni is using two-step logging. Log records are written into the in-memory queue and there is a separate thread which pulls them from the queue and writes to stderr or file. The maximum size of the internal queue is limited by default by **1000** records, which is enough to keep logs for the past 1h20m. - **PATRONI\_LOG\_DIR**: Directory to write application logs to. The directory must exist and be writable by the user executing Patroni. If you set this env variable, the application will retain 4 25MB logs by default. You can tune those retention values with `PATRONI_LOG_FILE_NUM` and `PATRONI_LOG_FILE_SIZE` (see below). - **PATRONI\_LOG\_FILE\_NUM**: The number of application logs to retain. diff --git a/docs/installation.rst b/docs/installation.rst index 3c9dddfa..0870d2a8 100644 --- a/docs/installation.rst +++ b/docs/installation.rst @@ -60,6 +60,8 @@ raft `pysyncobj` module in order to use python Raft implementation as DCS aws `boto3` in order to use AWS callbacks +jsonlogger + `python-json-logger` module in order to enable :ref:`logging ` in json format all all of the above (except psycopg family) psycopg diff --git a/docs/yaml_configuration.rst b/docs/yaml_configuration.rst index a4a33134..92f7445b 100644 --- a/docs/yaml_configuration.rst +++ b/docs/yaml_configuration.rst @@ -11,12 +11,22 @@ Global/Universal - **namespace**: path within the configuration store where Patroni will keep information about the cluster. Default value: "/service" - **scope**: cluster name +.. _log_settings: + Log --- +- **type**: sets the format of logs. Can be either **plain** or **json**. To use **json** format, you must have the :ref:`jsonlogger ` installed. The default value is **plain**. - **level**: sets the general logging level. Default value is **INFO** (see `the docs for Python logging `_) - **traceback\_level**: sets the level where tracebacks will be visible. Default value is **ERROR**. Set it to **DEBUG** if you want to see tracebacks only if you enable **log.level=DEBUG**. -- **format**: sets the log formatting string. Default value is **%(asctime)s %(levelname)s: %(message)s** (see `the LogRecord attributes `_) +- **format**: sets the log formatting string. If the log type is **plain**, the log format should be a string. Refer to + `the LogRecord attributes `_ for + available attributes. If the log type is **json**, the log format can be a list in addition to a string. Each list + item should correspond to LogRecord attributes. Be cautious that only the field name is required, and the **%(** + and **)** should be omitted. If you wish to print a log field with a different key name, use a dictionary where + the dictionary key is the log field, and the value is the name of the field you want to be printed in the log. + Default value is **%(asctime)s %(levelname)s: %(message)s** - **dateformat**: sets the datetime formatting string. (see the `formatTime() documentation `_) +- **static_fields**: add additional fields to the log. This option is only available when the log type is set to **json**. - **max\_queue\_size**: Patroni is using two-step logging. Log records are written into the in-memory queue and there is a separate thread which pulls them from the queue and writes to stderr or file. The maximum size of the internal queue is limited by default by **1000** records, which is enough to keep logs for the past 1h20m. - **dir**: Directory to write application logs to. The directory must exist and be writable by the user executing Patroni. If you set this value, the application will retain 4 25MB logs by default. You can tune those retention values with `file_num` and `file_size` (see below). - **file\_num**: The number of application logs to retain. @@ -26,6 +36,20 @@ Log - **patroni.postmaster: WARNING** - **urllib3: DEBUG** +Here is an example of how to config patroni to log in json format. + +.. code:: YAML + + log: + type: json + format: + - message + - module + - asctime: '@timestamp' + - levelname: level + static_fields: + app: patroni + .. _bootstrap_settings: Bootstrap configuration diff --git a/patroni/config.py b/patroni/config.py index f7d648d5..baca2a00 100644 --- a/patroni/config.py +++ b/patroni/config.py @@ -1,4 +1,5 @@ """Facilities related to Patroni configuration.""" +import re import json import logging import os @@ -534,8 +535,8 @@ class Config(object): _set_section_values('ctl', ['insecure', 'cacert', 'certfile', 'keyfile', 'keyfile_password']) _set_section_values('postgresql', ['listen', 'connect_address', 'proxy_address', 'config_dir', 'data_dir', 'pgpass', 'bin_dir']) - _set_section_values('log', ['level', 'traceback_level', 'format', 'dateformat', 'max_queue_size', - 'dir', 'file_size', 'file_num', 'loggers']) + _set_section_values('log', ['type', 'level', 'traceback_level', 'format', 'dateformat', 'static_fields', + 'max_queue_size', 'dir', 'file_size', 'file_num', 'loggers']) _set_section_values('raft', ['data_dir', 'self_addr', 'partner_addrs', 'password', 'bind_addr']) for binary in ('pg_ctl', 'initdb', 'pg_controldata', 'pg_basebackup', 'postgres', 'pg_isready', 'pg_rewind'): @@ -582,6 +583,12 @@ class Config(object): if value: ret[first][second] = value + logformat = ret.get('log', {}).get('format') + if logformat and not re.search(r'%\(\w+\)', logformat): + logformat = _parse_list(logformat) + if logformat: + ret['log']['format'] = logformat + def _parse_dict(value: str) -> Optional[Dict[str, Any]]: """Parse an YAML dictionary *value* as a :class:`dict`. @@ -597,7 +604,12 @@ class Config(object): logger.exception('Exception when parsing dict %s', value) return None - for first, params in (('restapi', ('http_extra_headers', 'https_extra_headers')), ('log', ('loggers',))): + dict_configs = ( + ('restapi', ('http_extra_headers', 'https_extra_headers')), + ('log', ('static_fields', 'loggers')) + ) + + for first, params in dict_configs: for second in params: value = ret.get(first, {}).pop(second, None) if value: diff --git a/patroni/config_generator.py b/patroni/config_generator.py index 3593bea3..dcb717c2 100644 --- a/patroni/config_generator.py +++ b/patroni/config_generator.py @@ -99,6 +99,7 @@ class AbstractConfigGenerator(abc.ABC): 'listen': cls._IP + ':8008' }, 'log': { + 'type': PatroniLogger.DEFAULT_TYPE, 'level': PatroniLogger.DEFAULT_LEVEL, 'traceback_level': PatroniLogger.DEFAULT_TRACEBACK_LEVEL, 'format': PatroniLogger.DEFAULT_FORMAT, diff --git a/patroni/log.py b/patroni/log.py index 6ac67a17..9d639942 100644 --- a/patroni/log.py +++ b/patroni/log.py @@ -14,6 +14,7 @@ from queue import Queue, Full from threading import Lock, Thread from typing import Any, Dict, List, Optional, Union, TYPE_CHECKING +type_logformat = Union[List[Union[str, Dict[str, Any], Any]], str, Any] _LOGGER = logging.getLogger(__name__) @@ -157,6 +158,7 @@ class PatroniLogger(Thread): .. seealso:: :class:`QueueHandler`: object used for enqueueing messages in-memory. + :cvar DEFAULT_TYPE: default type of log format (``plain``). :cvar DEFAULT_LEVEL: default logging level (``INFO``). :cvar DEFAULT_TRACEBACK_LEVEL: default traceback logging level (``ERROR``). :cvar DEFAULT_FORMAT: default format of log messages (``%(asctime)s %(levelname)s: %(message)s``). @@ -169,6 +171,7 @@ class PatroniLogger(Thread): :ivar log_handler_lock: lock used to modify ``log_handler``. """ + DEFAULT_TYPE = 'plain' DEFAULT_LEVEL = 'INFO' DEFAULT_TRACEBACK_LEVEL = 'ERROR' DEFAULT_FORMAT = '%(asctime)s %(levelname)s: %(message)s' @@ -237,6 +240,150 @@ class PatroniLogger(Thread): logger = self._root_logger.manager.getLogger(name) logger.setLevel(level) + def _is_config_changed(self, config: Dict[str, Any]) -> bool: + """Checks if the given config is different from the current one. + + :param config: ``log`` section from Patroni configuration. + + :returns: ``True`` if the config is changed, ``False`` otherwise. + """ + old_config = self._config or {} + + oldlogtype = old_config.get('type', PatroniLogger.DEFAULT_TYPE) + logtype = config.get('type', PatroniLogger.DEFAULT_TYPE) + + oldlogformat: type_logformat = old_config.get('format', PatroniLogger.DEFAULT_FORMAT) + logformat: type_logformat = config.get('format', PatroniLogger.DEFAULT_FORMAT) + + olddateformat = old_config.get('dateformat') or None + dateformat = config.get('dateformat') or None # Convert empty string to `None` + + old_static_fields = old_config.get('static_fields', {}) + static_fields = config.get('static_fields', {}) + + old_log_config = { + 'type': oldlogtype, + 'format': oldlogformat, + 'dateformat': olddateformat, + 'static_fields': old_static_fields + } + + log_config = { + 'type': logtype, + 'format': logformat, + 'dateformat': dateformat, + 'static_fields': static_fields + } + + return not deep_compare(old_log_config, log_config) + + def _get_plain_formatter(self, logformat: type_logformat, dateformat: Optional[str]) -> logging.Formatter: + """Returns a logging formatter with the specified format and date format. + + .. note:: + If the log format isn't a string, prints a warning message and uses the default log format instead. + + :param logformat: The format of the log messages. + :param dateformat: The format of the timestamp in the log messages. + + :returns: A logging formatter object that can be used to format log records. + """ + + if not isinstance(logformat, str): + _LOGGER.warning('Expected log format to be a string when log type is plain, but got "%s"', type(logformat)) + logformat = PatroniLogger.DEFAULT_FORMAT + + return logging.Formatter(logformat, dateformat) + + def _get_json_formatter(self, logformat: type_logformat, dateformat: Optional[str], + static_fields: Dict[str, Any]) -> logging.Formatter: + """Returns a logging formatter that outputs JSON formatted messages. + + .. note:: + If :mod:`pythonjsonlogger` library is not installed, prints an error message and returns + a plain log formatter instead. + + :param logformat: Specifies the log fields and their key names in the JSON log message. + :param dateformat: The format of the timestamp in the log messages. + :param static_fields: A dictionary of static fields that are added to every log message. + + :returns: A logging formatter object that can be used to format log records as JSON strings. + """ + + if isinstance(logformat, str): + jsonformat = logformat + rename_fields = {} + elif isinstance(logformat, list): + log_fields: List[str] = [] + rename_fields: Dict[str, str] = {} + + for field in logformat: + if isinstance(field, str): + log_fields.append(field) + elif isinstance(field, dict): + for original_field, renamed_field in field.items(): + if isinstance(renamed_field, str): + log_fields.append(original_field) + rename_fields[original_field] = renamed_field + else: + _LOGGER.warning( + 'Expected renamed log field to be a string, but got "%s"', + type(renamed_field) + ) + + else: + _LOGGER.warning( + 'Expected each item of log format to be a string or dictionary, but got "%s"', + type(field) + ) + + if len(log_fields) > 0: + jsonformat = ' '.join([f'%({field})s' for field in log_fields]) + else: + jsonformat = PatroniLogger.DEFAULT_FORMAT + else: + jsonformat = PatroniLogger.DEFAULT_FORMAT + rename_fields = {} + _LOGGER.warning('Expected log format to be a string or a list, but got "%s"', type(logformat)) + + try: + from pythonjsonlogger import jsonlogger + + formatter = jsonlogger.JsonFormatter( + jsonformat, + dateformat, + rename_fields=rename_fields, + static_fields=static_fields + ) + except ImportError as e: + _LOGGER.error('Failed to import "python-json-logger" library. Falling back to the plain logger: %r', e) + formatter = self._get_plain_formatter(jsonformat, dateformat) + + return formatter + + def _get_formatter(self, config: Dict[str, Any]) -> logging.Formatter: + """Returns a logging formatter based on the type of logger in the given configuration. + + :param config: ``log`` section from Patroni configuration. + + :returns: A :class:`logging.Formatter` object that can be used to format log records. + """ + logtype = config.get('type', PatroniLogger.DEFAULT_TYPE) + logformat: type_logformat = config.get('format', PatroniLogger.DEFAULT_FORMAT) + dateformat = config.get('dateformat') or None # Convert empty string to `None` + static_fields = config.get('static_fields', {}) + + if dateformat is not None and not isinstance(dateformat, str): + _LOGGER.warning('Expected log dateformat to be a string, but got "%s"', type(dateformat)) + dateformat = None + + if logtype == 'json': + formatter = self._get_json_formatter(logformat, dateformat, static_fields) + else: + formatter = self._get_plain_formatter(logformat, dateformat) + + return formatter + def reload_config(self, config: Dict[str, Any]) -> None: """Apply log related configuration. @@ -257,34 +404,29 @@ class PatroniLogger(Thread): # show stack traces as ``ERROR`` log messages logging.Logger.exception = error_exception - new_handler = None + handler = self.log_handler + if 'dir' in config: - if not isinstance(self.log_handler, RotatingFileHandler): - new_handler = RotatingFileHandler(os.path.join(config['dir'], __name__)) - handler = new_handler or self.log_handler - if TYPE_CHECKING: # pragma: no cover - assert isinstance(handler, RotatingFileHandler) + if not isinstance(handler, RotatingFileHandler): + handler = RotatingFileHandler(os.path.join(config['dir'], __name__)) + handler.maxBytes = int(config.get('file_size', 25000000)) # pyright: ignore [reportGeneralTypeIssues] handler.backupCount = int(config.get('file_num', 4)) else: - if self.log_handler is None or isinstance(self.log_handler, RotatingFileHandler): - new_handler = logging.StreamHandler() - handler = new_handler or self.log_handler + if not isinstance(handler, logging.StreamHandler): + handler = logging.StreamHandler() - oldlogformat = (self._config or {}).get('format', PatroniLogger.DEFAULT_FORMAT) - logformat = config.get('format', PatroniLogger.DEFAULT_FORMAT) + is_new_handler = handler != self.log_handler - olddateformat = (self._config or {}).get('dateformat') or None - dateformat = config.get('dateformat') or None # Convert empty string to `None` + if (self._is_config_changed(config) or is_new_handler) and handler: + formatter = self._get_formatter(config) + handler.setFormatter(formatter) - if (oldlogformat != logformat or olddateformat != dateformat or new_handler) and handler: - handler.setFormatter(logging.Formatter(logformat, dateformat)) - - if new_handler: + if is_new_handler: with self.log_handler_lock: if self.log_handler: self._old_handlers.append(self.log_handler) - self.log_handler = new_handler + self.log_handler = handler self._config = config.copy() self.update_loggers(config.get('loggers') or {}) diff --git a/patroni/validator.py b/patroni/validator.py index bd69cc0e..70066b9b 100644 --- a/patroni/validator.py +++ b/patroni/validator.py @@ -16,6 +16,49 @@ from .collections import CaseInsensitiveSet from .dcs import dcs_modules from .exceptions import ConfigParseError from .utils import parse_int, split_host_port, data_directory_is_empty, get_major_version +from .log import type_logformat + + +def validate_log_field(field: Union[str, Dict[str, Any], Any]) -> bool: + """Checks if log field is valid. + + :param field: A log field to be validated. + + :returns: ``True`` if the field is either a string or a dictionary with exactly one key + that has string value, ``False`` otherwise. + """ + if isinstance(field, str): + return True + elif isinstance(field, dict): + return len(field) == 1 and isinstance(next(iter(field.values())), str) + return False + + +def validate_log_format(logformat: type_logformat) -> bool: + """Checks if log format is valid. + + :param logformat: A log format to be validated. + + :returns: ``True`` if the log format is either a string or a list of valid log fields. + + :raises: + :exc:`~patroni.exceptions.ConfigParseError`: + * If the logformat is not a string or a list; or + * If the logformat is an empty list; or + * If the log format is a list and it with values that don't pass validation using + :func:`validate_log_field`. + """ + if isinstance(logformat, str): + return True + elif isinstance(logformat, list): + if len(logformat) == 0: + raise ConfigParseError('should contains at least one item') + if not all(map(validate_log_field, logformat)): + raise ConfigParseError('Each item should be a string or a dictionary with string values') + + return True + else: + raise ConfigParseError('Should be a string or a list') def data_directory_empty(data_dir: str) -> bool: @@ -938,11 +981,13 @@ schema = Schema({ "name": str, "scope": str, Optional("log"): { + Optional("type"): EnumValidator(('plain', 'json'), case_sensitive=True, raise_assert=True), Optional("level"): EnumValidator(('DEBUG', 'INFO', 'WARN', 'WARNING', 'ERROR', 'FATAL', 'CRITICAL'), case_sensitive=True, raise_assert=True), Optional("traceback_level"): EnumValidator(('DEBUG', 'ERROR'), raise_assert=True), - Optional("format"): str, + Optional("format"): validate_log_format, Optional("dateformat"): str, + Optional("static_fields"): dict, Optional("max_queue_size"): int, Optional("dir"): str, Optional("file_num"): int, diff --git a/requirements.txt b/requirements.txt index aea3284f..53394d09 100644 --- a/requirements.txt +++ b/requirements.txt @@ -11,3 +11,4 @@ pysyncobj>=0.3.8 cryptography>=1.4 psutil>=2.0.0 ydiff>=1.2.0 +python-json-logger>=2.0.2 diff --git a/setup.py b/setup.py index 5bd9c71f..4e0fc730 100644 --- a/setup.py +++ b/setup.py @@ -25,7 +25,7 @@ KEYWORDS = 'etcd governor patroni postgresql postgres ha haproxy confd' +\ EXTRAS_REQUIRE = {'aws': ['boto3'], 'etcd': ['python-etcd'], 'etcd3': ['python-etcd'], 'consul': ['python-consul'], 'exhibitor': ['kazoo'], 'zookeeper': ['kazoo'], - 'kubernetes': [], 'raft': ['pysyncobj', 'cryptography']} + 'kubernetes': [], 'raft': ['pysyncobj', 'cryptography'], 'jsonlogger': ['python-json-logger']} # Add here all kinds of additional classifiers as defined under # https://pypi.python.org/pypi?%3Aaction=list_classifiers diff --git a/tests/test_config.py b/tests/test_config.py index a02a33fd..7808be6c 100644 --- a/tests/test_config.py +++ b/tests/test_config.py @@ -35,6 +35,7 @@ class TestConfig(unittest.TestCase): 'PATRONI_NAMESPACE': '/patroni/', 'PATRONI_SCOPE': 'batman2', 'PATRONI_LOGLEVEL': 'ERROR', + 'PATRONI_LOG_FORMAT': '["message", {"levelname": "level"}]', 'PATRONI_LOG_LOGGERS': 'patroni.postmaster: WARNING, urllib3: DEBUG', 'PATRONI_LOG_FILE_NUM': '5', 'PATRONI_CITUS_DATABASE': 'citus', diff --git a/tests/test_config_generator.py b/tests/test_config_generator.py index 1b436bb0..c6913da3 100644 --- a/tests/test_config_generator.py +++ b/tests/test_config_generator.py @@ -62,9 +62,10 @@ class TestGenerateConfig(unittest.TestCase): 'scope': self.environ['PATRONI_SCOPE'], 'name': HOSTNAME, 'log': { + 'type': PatroniLogger.DEFAULT_TYPE, + 'format': PatroniLogger.DEFAULT_FORMAT, 'level': PatroniLogger.DEFAULT_LEVEL, 'traceback_level': PatroniLogger.DEFAULT_TRACEBACK_LEVEL, - 'format': PatroniLogger.DEFAULT_FORMAT, 'max_queue_size': PatroniLogger.DEFAULT_MAX_QUEUE_SIZE }, 'restapi': { diff --git a/tests/test_log.py b/tests/test_log.py index ebdb4945..4e35bc1d 100644 --- a/tests/test_log.py +++ b/tests/test_log.py @@ -3,6 +3,8 @@ import os import sys import unittest import yaml +import json +from io import StringIO from mock import Mock, patch from patroni.config import Config @@ -72,3 +74,196 @@ class TestPatroniLogger(unittest.TestCase): _LOG.info('blabla') logger.shutdown() self.assertEqual(logger.records_lost, 0) + + def test_json_list_format(self): + config = { + 'type': 'json', + 'format': [ + {'asctime': '@timestamp'}, + {'levelname': 'level'}, + 'message' + ], + 'static_fields': { + 'app': 'patroni' + } + } + + test_message = 'test json logging in case of list format' + + with patch('sys.stderr', StringIO()) as stderr_output: + logger = PatroniLogger() + logger.reload_config(config) + + _LOG.info(test_message) + target_log = json.loads(stderr_output.getvalue()) + + self.assertIn('@timestamp', target_log) + self.assertEqual(target_log['message'], test_message) + self.assertEqual(target_log['level'], 'INFO') + self.assertEqual(target_log['app'], 'patroni') + self.assertEqual(len(target_log), len(config['format']) + len(config['static_fields'])) + + def test_json_str_format(self): + config = { + 'type': 'json', + 'format': '%(asctime)s %(levelname)s %(message)s', + 'static_fields': { + 'app': 'patroni' + } + } + + test_message = 'test json logging in case of string format' + + with patch('sys.stderr', StringIO()) as stderr_output: + logger = PatroniLogger() + logger.reload_config(config) + + _LOG.info(test_message) + target_log = json.loads(stderr_output.getvalue()) + + self.assertIn('asctime', target_log) + self.assertEqual(target_log['message'], test_message) + self.assertEqual(target_log['levelname'], 'INFO') + self.assertEqual(target_log['app'], 'patroni') + + def test_plain_format(self): + config = { + 'type': 'plain', + 'format': '[%(asctime)s] %(levelname)s %(message)s', + } + + test_message = 'test plain logging' + + with patch('sys.stderr', StringIO()) as stderr_output: + logger = PatroniLogger() + logger.reload_config(config) + + _LOG.info(test_message) + target_log = stderr_output.getvalue() + + self.assertRegex(target_log, fr'^\[.*\] INFO {test_message}$') + + def test_dateformat(self): + config = { + 'format': '[%(asctime)s] %(message)s', + 'dateformat': '%Y-%m-%dT%H:%M:%S' + } + + test_message = 'test date format' + + with patch('sys.stderr', StringIO()) as stderr_output: + logger = PatroniLogger() + logger.reload_config(config) + + _LOG.info(test_message) + target_log = stderr_output.getvalue() + + self.assertRegex(target_log, r'\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\]') + + def test_invalid_dateformat(self): + config = { + 'format': '[%(asctime)s] %(message)s', + 'dateformat': 5 + } + + with self.assertLogs() as captured_log: + logger = PatroniLogger() + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'WARNING') + self.assertRegex( + captured_log_message, + fr'Expected log dateformat to be a string, but got "{type(config["dateformat"])}"' + ) + + def test_invalid_plain_format(self): + config = { + 'type': 'plain', + 'format': ['message'] + } + + with self.assertLogs() as captured_log: + logger = PatroniLogger() + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'WARNING') + self.assertRegex( + captured_log_message, + r'Expected log format to be a string when log type is plain, but got ".*"' + ) + + def test_invalid_json_format(self): + config = { + 'type': 'json', + 'format': { + 'asctime': 'timestamp', + 'message': 'message' + } + } + + with self.assertLogs() as captured_log: + logger = PatroniLogger() + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'WARNING') + self.assertRegex( + captured_log_message, + r'Expected log format to be a string or a list, but got ".*"' + ) + + with self.assertLogs() as captured_log: + config['format'] = ['message', ['levelname']] + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'WARNING') + self.assertRegex( + captured_log_message, + r'Expected each item of log format to be a string or dictionary, but got ".*"' + ) + + with self.assertLogs() as captured_log: + config['format'] = [ + 'message', + {'asctime': ['timestamp']} + ] + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'WARNING') + self.assertRegex( + captured_log_message, + r'Expected renamed log field to be a string, but got ".*"' + ) + + @patch('pythonjsonlogger.jsonlogger.JsonFormatter', side_effect=ImportError) + def test_fail_to_import_python_json_logger(self, _): + config = { + 'type': 'json' + } + + with self.assertLogs() as captured_log: + logger = PatroniLogger() + logger.reload_config(config) + + captured_log_level = captured_log.records[0].levelname + captured_log_message = captured_log.records[0].message + + self.assertEqual(captured_log_level, 'ERROR') + self.assertRegex( + captured_log_message, + r'Failed to import "python-json-logger" library. Falling back to the plain logger' + ) diff --git a/tests/test_validator.py b/tests/test_validator.py index d5e82992..f70b387b 100644 --- a/tests/test_validator.py +++ b/tests/test_validator.py @@ -14,6 +14,7 @@ config = { "name": "string", "scope": "string", "log": { + "type": "plain", "level": "DEBUG", "traceback_level": "DEBUG", "format": "%(asctime)s %(levelname)s: %(message)s", @@ -371,3 +372,37 @@ class TestValidator(unittest.TestCase): c["tags"]["failover_priority"] = -6 errors = schema(c) self.assertIn('tags.failover_priority -6 didn\'t pass validation: Wrong value', errors) + + def test_json_log_format(self, *args): + c = copy.deepcopy(config) + c["log"]["type"] = "json" + c["log"]["format"] = {"levelname": "level"} + errors = schema(c) + self.assertIn( + 'log.format {\'levelname\': \'level\'} didn\'t pass validation: Should be a string or a list', + errors + ) + + c = copy.deepcopy(config) + c["log"]["type"] = "json" + c["log"]["format"] = [{"levelname": []}] + errors = schema(c) + self.assertIn( + ' '.join([ + 'log.format [{\'levelname\': []}] didn\'t pass validation:', + 'Each item should be a string or a dictionary with string values' + ]), + errors + ) + + c = copy.deepcopy(config) + c["log"]["type"] = "json" + c["log"]["format"] = [[]] + errors = schema(c) + self.assertIn( + ' '.join([ + 'log.format [[]] didn\'t pass validation:', + 'Each item should be a string or a dictionary with string values' + ]), + errors + )