Repository: zalando/patroni
Pull request #3008 (2024-01-16 15:09:10)

Improve logging for Pg param change
* Convert old value to a human-readable format
* Add log line about pg_controldata/global config mismatch that causes pending restart flag to be set

Effectively is a preparation for https://github.com/zalando/patroni/pull/2978

coveralls: ## Pull Request Test Coverage Report for [Build 7543680107](https://coveralls.io/builds/65098967)


* **0** of **0**   changed or added relevant lines in **0** files are covered.
* No unchanged relevant lines lost coverage.
* Overall coverage decreased (**-0.006%**) to **99.802%**

---



|  Totals | [![Coverage Status](https://coveralls.io/builds/65098967/badge)](https://coveralls.io/builds/65098967) |
| :-- | --: |
| Change from base [Build 7539724004](https://coveralls.io/builds/65091330): |  -0.006% |
| Covered Lines: | 13578 |
| Relevant Lines: | 13605 |

---
##### 💛  - [Coveralls](https://coveralls.io)


Patch:
diff --git a/patroni/log.py b/patroni/log.py
index 9d639942..beaacf4e 100644
--- a/patroni/log.py
+++ b/patroni/log.py
@@ -9,11 +9,13 @@ import sys
 
 from copy import deepcopy
 from logging.handlers import RotatingFileHandler
-from patroni.utils import deep_compare
 from queue import Queue, Full
 from threading import Lock, Thread
 
 from typing import Any, Dict, List, Optional, Union, TYPE_CHECKING
+
+from .utils import deep_compare
+
 type_logformat = Union[List[Union[str, Dict[str, Any], Any]], str, Any]
 
 _LOGGER = logging.getLogger(__name__)
@@ -349,17 +351,18 @@ class PatroniLogger(Thread):
         try:
             from pythonjsonlogger import jsonlogger
 
-            formatter = jsonlogger.JsonFormatter(
+            return 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)
+            _LOGGER.error('Failed to import "python-json-logger" library: %r. Falling back to the plain logger', e)
+        except Exception as e:
+            _LOGGER.error('Failed to initialize JsonFormatter: %r. Falling back to the plain logger', e)
 
-        return formatter
+        return self._get_plain_formatter(jsonformat, dateformat)
 
     def _get_formatter(self, config: Dict[str, Any]) -> logging.Formatter:
         """Returns a logging formatter based on the type of logger in the given configuration.
@@ -412,9 +415,10 @@ class PatroniLogger(Thread):
 
                 handler.maxBytes = int(config.get('file_size', 25000000))  # pyright: ignore [reportGeneralTypeIssues]
                 handler.backupCount = int(config.get('file_num', 4))
-            else:
-                if not isinstance(handler, logging.StreamHandler):
-                    handler = logging.StreamHandler()
+            # we can't use `if not isinstance(handler, logging.StreamHandler)` below,
+            # because RotatingFileHandler is a child of StreamHandler!!!
+            elif handler is None or isinstance(handler, RotatingFileHandler):
+                handler = logging.StreamHandler()
 
             is_new_handler = handler != self.log_handler
 
diff --git a/patroni/postgresql/config.py b/patroni/postgresql/config.py
index fd5edae7..51e83cf8 100644
--- a/patroni/postgresql/config.py
+++ b/patroni/postgresql/config.py
@@ -17,7 +17,8 @@ from ..collections import CaseInsensitiveDict, CaseInsensitiveSet
 from ..dcs import Leader, Member, RemoteMember, slot_name_from_member_name
 from ..exceptions import PatroniFatalException, PostgresConnectionException
 from ..file_perm import pg_perm
-from ..utils import compare_values, parse_bool, parse_int, split_host_port, uri, validate_directory, is_subpath
+from ..utils import (compare_values, maybe_convert_from_base_unit, parse_bool, parse_int,
+                     split_host_port, uri, validate_directory, is_subpath)
 from ..validator import IntValidator, EnumValidator
 
 if TYPE_CHECKING:  # pragma: no cover
@@ -1102,27 +1103,29 @@ class ConfigHandler(object):
                         new_value = changes.pop(r[0])
                         if new_value is None or not compare_values(r[3], r[2], r[1], new_value):
                             conf_changed = True
+                            old_value = maybe_convert_from_base_unit(r[1], r[3], r[2])
                             if r[4] == 'postmaster':
                                 pending_restart = True
-                                logger.info('Changed %s from %s to %s (restart might be required)',
-                                            r[0], r[1], new_value)
+                                logger.info("Changed %s from '%s' to '%s' (restart might be required)",
+                                            r[0], old_value, new_value)
                                 if config.get('use_unix_socket') and r[0] == 'unix_socket_directories'\
                                         or r[0] in ('listen_addresses', 'port'):
                                     local_connection_address_changed = True
                             else:
-                                logger.info('Changed %s from %s to %s', r[0], r[1], new_value)
+                                logger.info("Changed %s from '%s' to '%s'", r[0], old_value, new_value)
                         elif r[0] in self._server_parameters \
                                 and not compare_values(r[3], r[2], r[1], self._server_parameters[r[0]]):
                             # Check if any parameter was set back to the current pg_settings value
                             # We can use pg_settings value here, as it is proved to be equal to new_value
-                            logger.info('Changed %s from %s to %s', r[0], self._server_parameters[r[0]], r[1])
+                            logger.info("Changed %s from '%s' to '%s'", r[0], self._server_parameters[r[0]], new_value)
                             conf_changed = True
                 for param, value in changes.items():
                     if '.' in param:
-                        # Check that user-defined-paramters have changed (parameters with period in name)
+                        # Check that user-defined-parameters have changed (parameters with period in name)
                         if value is None or param not in self._server_parameters \
                                 or str(value) != str(self._server_parameters[param]):
-                            logger.info('Changed %s from %s to %s', param, self._server_parameters.get(param), value)
+                            logger.info("Changed %s from '%s' to '%s'",
+                                        param, self._server_parameters.get(param), value)
                             conf_changed = True
                     elif param in server_parameters:
                         logger.warning('Removing invalid parameter `%s` from postgresql.parameters', param)
@@ -1228,6 +1231,8 @@ class ConfigHandler(object):
             cvalue = parse_int(data[cname])
             if cvalue is not None and value is not None and cvalue > value:
                 effective_configuration[name] = cvalue
+                logger.info("%s value in pg_controldata: %d, in the global configuration: %d."
+                            " pg_controldata value will be used. Setting 'Pending restart' flag", name, cvalue, value)
                 self._postgresql.set_pending_restart(True)
 
         # If we are using custom bootstrap with PITR it could fail when values like max_connections
diff --git a/patroni/utils.py b/patroni/utils.py
index 2b1ded5b..f1da0dff 100644
--- a/patroni/utils.py
+++ b/patroni/utils.py
@@ -10,6 +10,7 @@
 :var WHITESPACE_RE: regular expression to match whitespace characters
 """
 import errno
+import itertools
 import logging
 import os
 import platform
@@ -24,6 +25,7 @@ from shlex import split
 
 from typing import Any, Callable, Dict, Iterator, List, Optional, Union, Tuple, Type, TYPE_CHECKING
 
+from collections import OrderedDict
 from dateutil import tz
 from json import JSONDecoder
 from urllib3.response import HTTPResponse
@@ -46,6 +48,37 @@ DBL_RE = re.compile(r'^[-+]?[0-9]*\.?[0-9]+([eE][-+]?[0-9]+)?')
 WHITESPACE_RE = re.compile(r'[ \t\n\r]*', re.VERBOSE | re.MULTILINE | re.DOTALL)
 
 
+def get_conversion_table(base_unit: str) -> Dict[str, Dict[str, Union[int, float]]]:
+    """Get conversion table for the specified base unit.
+
+    If no conversion table exists for the passed unit, return an empty :class:`OrderedDict`.
+
+    :param base_unit: unit to choose the conversion table for.
+
+    :returns: :class:`OrderedDict` object.
+    """
+    memory_unit_conversion_table: Dict[str, Dict[str, Union[int, float]]] = OrderedDict([
+        ('TB', {'B': 1024**4, 'kB': 1024**3, 'MB': 1024**2}),
+        ('GB', {'B': 1024**3, 'kB': 1024**2, 'MB': 1024}),
+        ('MB', {'B': 1024**2, 'kB': 1024, 'MB': 1}),
+        ('kB', {'B': 1024, 'kB': 1, 'MB': 1024**-1}),
+        ('B', {'B': 1, 'kB': 1024**-1, 'MB': 1024**-2})
+    ])
+    time_unit_conversion_table: Dict[str, Dict[str, Union[int, float]]] = OrderedDict([
+        ('d', {'ms': 1000 * 60**2 * 24, 's': 60**2 * 24, 'min': 60 * 24}),
+        ('h', {'ms': 1000 * 60**2, 's': 60**2, 'min': 60}),
+        ('min', {'ms': 1000 * 60, 's': 60, 'min': 1}),
+        ('s', {'ms': 1000, 's': 1, 'min': 60**-1}),
+        ('ms', {'ms': 1, 's': 1000**-1, 'min': 1 / (1000 * 60)}),
+        ('us', {'ms': 1000**-1, 's': 1000**-2, 'min': 1 / (1000**2 * 60)})
+    ])
+    if base_unit in ('B', 'kB', 'MB'):
+        return memory_unit_conversion_table
+    elif base_unit in ('ms', 's', 'min'):
+        return time_unit_conversion_table
+    return OrderedDict()
+
+
 def deep_compare(obj1: Dict[Any, Union[Any, Dict[Any, Any]]], obj2: Dict[Any, Union[Any, Dict[Any, Any]]]) -> bool:
     """Recursively compare two dictionaries to check if they are equal in terms of keys and values.
 
@@ -272,33 +305,152 @@ def convert_to_base_unit(value: Union[int, float], unit: str, base_unit: Optiona
         >>> convert_to_base_unit(1, 'GB', '512 MB') is None
         True
     """
-    convert: Dict[str, Dict[str, Union[int, float]]] = {
-        'B': {'B': 1, 'kB': 1024, 'MB': 1024 * 1024, 'GB': 1024 * 1024 * 1024, 'TB': 1024 * 1024 * 1024 * 1024},
-        'kB': {'B': 1.0 / 1024, 'kB': 1, 'MB': 1024, 'GB': 1024 * 1024, 'TB': 1024 * 1024 * 1024},
-        'MB': {'B': 1.0 / (1024 * 1024), 'kB': 1.0 / 1024, 'MB': 1, 'GB': 1024, 'TB': 1024 * 1024},
-        'ms': {'us': 1.0 / 1000, 'ms': 1, 's': 1000, 'min': 1000 * 60, 'h': 1000 * 60 * 60, 'd': 1000 * 60 * 60 * 24},
-        's': {'us': 1.0 / (1000 * 1000), 'ms': 1.0 / 1000, 's': 1, 'min': 60, 'h': 60 * 60, 'd': 60 * 60 * 24},
-        'min': {'us': 1.0 / (1000 * 1000 * 60), 'ms': 1.0 / (1000 * 60), 's': 1.0 / 60, 'min': 1, 'h': 60, 'd': 60 * 24}
-    }
+    base_value, base_unit = strtol(base_unit, False)
+    if TYPE_CHECKING:  # pragma: no cover
+        assert isinstance(base_value, int)
 
-    round_order = {
-        'TB': 'GB', 'GB': 'MB', 'MB': 'kB', 'kB': 'B',
-        'd': 'h', 'h': 'min', 'min': 's', 's': 'ms', 'ms': 'us'
-    }
+    convert_tbl = get_conversion_table(base_unit)
+    # {'TB': 'GB', 'GB': 'MB', ...}
+    round_order = dict(zip(convert_tbl, itertools.islice(convert_tbl, 1, None)))
+    if unit in convert_tbl and base_unit in convert_tbl[unit]:
+        value *= convert_tbl[unit][base_unit] / float(base_value)
+        if unit in round_order:
+            multiplier = convert_tbl[round_order[unit]][base_unit]
+            value = round(value / float(multiplier)) * multiplier
+        return value
 
-    if base_unit and base_unit not in convert:
-        base_value, base_unit = strtol(base_unit, False)
-    else:
-        base_value = 1
 
-    if base_value is not None and base_unit in convert and unit in convert[base_unit]:
-        value *= convert[base_unit][unit] / float(base_value)
+def convert_int_from_base_unit(base_value: int, base_unit: Optional[str]) -> Optional[str]:
+    """Convert an integer value in some base unit to a human-friendly unit.
 
-        if unit in round_order:
-            multiplier = convert[base_unit][round_order[unit]]
-            value = round(value / float(multiplier)) * multiplier
+    The output unit is chosen so that it's the greatest unit that can represent
+    the value without loss.
 
-        return value
+    :param base_value: value to be converted from a base unit
+    :param base_unit: unit of *value*. Should be one of the base units (case sensitive):
+
+            * For space: ``B``, ``kB``, ``MB``;
+            * For time: ``ms``, ``s``, ``min``.
+
+    :returns: :class:`str` value representing *base_value* converted from *base_unit* to the greatest
+        possible human-friendly unit, or ``None`` if conversion failed.
+
+    :Example:
+
+        >>> convert_int_from_base_unit(1024, 'kB')
+        '1MB'
+
+        >>> convert_int_from_base_unit(1025, 'kB')
+        '1025kB'
+
+        >>> convert_int_from_base_unit(4, '256MB')
+        '1GB'
+
+        >>> convert_int_from_base_unit(4, '256 MB') is None
+        True
+
+        >>> convert_int_from_base_unit(1024, 'KB') is None
+        True
+    """
+    base_value_mult, base_unit = strtol(base_unit, False)
+    if TYPE_CHECKING:  # pragma: no cover
+        assert isinstance(base_value_mult, int)
+    base_value *= base_value_mult
+
+    convert_tbl = get_conversion_table(base_unit)
+    for unit in convert_tbl:
+        multiplier = convert_tbl[unit][base_unit]
+        if multiplier <= 1.0 or base_value % multiplier == 0:
+            return str(round(base_value / multiplier)) + unit
+
+
+def convert_real_from_base_unit(base_value: float, base_unit: Optional[str]) -> Optional[str]:
+    """Convert an floating-point value in some base unit to a human-friendly unit.
+
+    Same as :func:`convert_int_from_base_unit`, except we have to do the math a bit differently,
+    and there's a possibility that we don't find any exact divisor.
+
+    :param base_value: value to be converted from a base unit
+    :param base_unit: unit of *value*. Should be one of the base units (case sensitive):
+
+            * For space: ``B``, ``kB``, ``MB``;
+            * For time: ``ms``, ``s``, ``min``.
+
+    :returns: :class:`str` value representing *base_value* converted from *base_unit* to the greatest
+        possible human-friendly unit, or ``None`` if conversion failed.
+
+    :Example:
+
+        >>> convert_real_from_base_unit(5, 'ms')
+        '5ms'
+
+        >>> convert_real_from_base_unit(2.5, 'ms')
+        '2500us'
+
+        >>> convert_real_from_base_unit(4.0, '256MB')
+        '1GB'
+
+        >>> convert_real_from_base_unit(4.0, '256 MB') is None
+        True
+    """
+    base_value_mult, base_unit = strtol(base_unit, False)
+    if TYPE_CHECKING:  # pragma: no cover
+        assert isinstance(base_value_mult, int)
+    base_value *= base_value_mult
+
+    result = None
+    convert_tbl = get_conversion_table(base_unit)
+    for unit in convert_tbl:
+        value = base_value / convert_tbl[unit][base_unit]
+        result = f'{value:g}{unit}'
+        if value > 0 and abs((round(value) / value) - 1.0) <= 1e-8:
+            break
+    return result
+
+
+def maybe_convert_from_base_unit(base_value: str, vartype: str, base_unit: Optional[str]) -> str:
+    """Try to convert integer or real value in a base unit to a human-readable unit.
+
+    Value is passed as a string. If parsing or subsequent conversion fails, the original
+    value is returned.
+
+    :param base_value: value to be converted from a base unit.
+    :param vartype: the target type to parse *base_value* before converting (``integer``
+        or ``real`` is expected, any other type results in return value being equal to the
+        *base_value* string).
+    :param base_unit: unit of *value*. Should be one of the base units (case sensitive):
+
+            * For space: ``B``, ``kB``, ``MB``;
+            * For time: ``ms``, ``s``, ``min``.
+
+    :returns: :class:`str` value representing *base_value* converted from *base_unit* to the greatest
+        possible human-friendly unit, or *base_value* string if conversion failed.
+
+    :Example:
+
+        >>> maybe_convert_from_base_unit('5', 'integer', 'ms')
+        '5ms'
+
+        >>> maybe_convert_from_base_unit('4.2', 'real', 'ms')
+        '4200us'
+
+        >>> maybe_convert_from_base_unit('on', 'bool', None)
+        'on'
+
+        >>> maybe_convert_from_base_unit('', 'integer', '256MB')
+        ''
+    """
+    converters: Dict[str, Tuple[Callable[[str, Optional[str]], Union[int, float, str, None]],
+                                Callable[[Any, Optional[str]], Optional[str]]]] = {
+        'integer': (parse_int, convert_int_from_base_unit),
+        'real': (parse_real, convert_real_from_base_unit),
+        'default': (lambda v, _: v, lambda v, _: v)
+    }
+    parser, converter = converters.get(vartype, converters['default'])
+    parsed_value = parser(base_value, None)
+    if parsed_value:
+        return converter(parsed_value, base_unit) or base_value
+    return base_value
 
 
 def parse_int(value: Any, base_unit: Optional[str] = None) -> Optional[int]:
diff --git a/patroni/validator.py b/patroni/validator.py
index 70066b9b..a2818a11 100644
--- a/patroni/validator.py
+++ b/patroni/validator.py
@@ -52,9 +52,9 @@ def validate_log_format(logformat: type_logformat) -> bool:
         return True
     elif isinstance(logformat, list):
         if len(logformat) == 0:
-            raise ConfigParseError('should contains at least one item')
+            raise ConfigParseError('should contain 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')
+            raise ConfigParseError('each item should be a string or a dictionary with string values')
 
         return True
     else:


Test patch:
diff --git a/tests/test_log.py b/tests/test_log.py
index 4e35bc1d..48020ff4 100644
--- a/tests/test_log.py
+++ b/tests/test_log.py
@@ -3,7 +3,6 @@ import os
 import sys
 import unittest
 import yaml
-import json
 from io import StringIO
 
 from mock import Mock, patch
@@ -11,6 +10,16 @@ from patroni.config import Config
 from patroni.log import PatroniLogger
 from queue import Queue, Full
 
+try:
+    from pythonjsonlogger import jsonlogger
+
+    jsonlogger.JsonFormatter(None, None, rename_fields={}, static_fields={})
+    json_formatter_is_available = True
+
+    import json  # we need json.loads() function
+except Exception:
+    json_formatter_is_available = False
+
 _LOG = logging.getLogger(__name__)
 
 
@@ -95,13 +104,14 @@ class TestPatroniLogger(unittest.TestCase):
             logger.reload_config(config)
 
             _LOG.info(test_message)
-            target_log = json.loads(stderr_output.getvalue())
+            if json_formatter_is_available:
+                target_log = json.loads(stderr_output.getvalue().split('\n')[-2])
 
-        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']))
+                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 = {
@@ -119,12 +129,13 @@ class TestPatroniLogger(unittest.TestCase):
             logger.reload_config(config)
 
             _LOG.info(test_message)
-            target_log = json.loads(stderr_output.getvalue())
+            if json_formatter_is_available:
+                target_log = json.loads(stderr_output.getvalue().split('\n')[-2])
 
-        self.assertIn('asctime', target_log)
-        self.assertEqual(target_log['message'], test_message)
-        self.assertEqual(target_log['levelname'], 'INFO')
-        self.assertEqual(target_log['app'], 'patroni')
+                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 = {
@@ -215,13 +226,10 @@ class TestPatroniLogger(unittest.TestCase):
             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 ".*"'
-            )
+            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']]
+            config['format'] = [['levelname']]
             logger.reload_config(config)
 
             captured_log_level = captured_log.records[0].levelname
@@ -234,30 +242,36 @@ class TestPatroniLogger(unittest.TestCase):
             )
 
         with self.assertLogs() as captured_log:
-            config['format'] = [
-                'message',
-                {'asctime': ['timestamp']}
-            ]
+            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 ".*"')
+
+    def test_fail_to_use_python_json_logger(self):
+        with self.assertLogs() as captured_log:
+            logger = PatroniLogger()
+            with patch('builtins.__import__', Mock(side_effect=ImportError)):
+                logger.reload_config({'type': 'json'})
+
+            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'Expected renamed log field to be a string, but got ".*"'
+                r'Failed to import "python-json-logger" library: .*. Falling back to the plain logger'
             )
 
-    @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)
+            pythonjsonlogger = Mock()
+            pythonjsonlogger.jsonlogger.JsonFormatter = Mock(side_effect=Exception)
+            with patch('builtins.__import__', Mock(return_value=pythonjsonlogger)):
+                logger.reload_config({'type': 'json'})
 
             captured_log_level = captured_log.records[0].levelname
             captured_log_message = captured_log.records[0].message
@@ -265,5 +279,5 @@ class TestPatroniLogger(unittest.TestCase):
             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'
+                r'Failed to initialize JsonFormatter: .*. Falling back to the plain logger'
             )
diff --git a/tests/test_postgresql.py b/tests/test_postgresql.py
index aebffc43..59c9eb59 100644
--- a/tests/test_postgresql.py
+++ b/tests/test_postgresql.py
@@ -606,9 +606,9 @@ class TestPostgresql(BaseTestPostgresql):
         config['parameters']['max_worker_processes'] *= 2
         with patch('patroni.postgresql.Postgresql._query', Mock(side_effect=[GET_PG_SETTINGS_RESULT, [(1,)]])):
             self.p.reload_config(config)
-            self.assertEqual(mock_info.call_args_list[0][0], ('Changed %s from %s to %s (restart might be required)',
-                                                              'max_worker_processes', str(init_max_worker_processes),
-                                                              config['parameters']['max_worker_processes']))
+            self.assertEqual(mock_info.call_args_list[0][0],
+                             ("Changed %s from '%s' to '%s' (restart might be required)", 'max_worker_processes',
+                              str(init_max_worker_processes), config['parameters']['max_worker_processes']))
             self.assertEqual(mock_info.call_args_list[1][0], ('Reloading PostgreSQL configuration.',))
             self.assertEqual(self.p.pending_restart, True)
 
@@ -617,9 +617,9 @@ class TestPostgresql(BaseTestPostgresql):
         # Reset to the initial value without restart
         config['parameters']['max_worker_processes'] = init_max_worker_processes
         self.p.reload_config(config)
-        self.assertEqual(mock_info.call_args_list[0][0], ('Changed %s from %s to %s', 'max_worker_processes',
+        self.assertEqual(mock_info.call_args_list[0][0], ("Changed %s from '%s' to '%s'", 'max_worker_processes',
                                                           init_max_worker_processes * 2,
-                                                          str(config['parameters']['max_worker_processes'])))
+                                                          config['parameters']['max_worker_processes']))
         self.assertEqual(mock_info.call_args_list[1][0], ('Reloading PostgreSQL configuration.',))
         self.assertEqual(self.p.pending_restart, False)
 
@@ -628,20 +628,21 @@ class TestPostgresql(BaseTestPostgresql):
         # User-defined parameter changed (removed)
         config['parameters'].pop('f.oo')
         self.p.reload_config(config)
-        self.assertEqual(mock_info.call_args_list[0][0], ('Changed %s from %s to %s', 'f.oo', 'bar', None))
+        self.assertEqual(mock_info.call_args_list[0][0], ("Changed %s from '%s' to '%s'", 'f.oo', 'bar', None))
         self.assertEqual(mock_info.call_args_list[1][0], ('Reloading PostgreSQL configuration.',))
         self.assertEqual(self.p.pending_restart, False)
 
         mock_info.reset_mock()
 
         # Non-postmaster parameter change
-        config['parameters']['autovacuum'] = 'off'
+        config['parameters']['vacuum_cost_delay'] = 2.5
         self.p.reload_config(config)
-        self.assertEqual(mock_info.call_args_list[0][0], ("Changed %s from %s to %s", 'autovacuum', 'on', 'off'))
+        self.assertEqual(mock_info.call_args_list[0][0],
+                         ("Changed %s from '%s' to '%s'", 'vacuum_cost_delay', '200ms', 2.5))
         self.assertEqual(mock_info.call_args_list[1][0], ('Reloading PostgreSQL configuration.',))
         self.assertEqual(self.p.pending_restart, False)
 
-        config['parameters']['autovacuum'] = 'on'
+        config['parameters']['vacuum_cost_delay'] = 200
         mock_info.reset_mock()
 
         # Remove invalid parameter
@@ -832,6 +833,11 @@ class TestPostgresql(BaseTestPostgresql):
             self.assertFalse(self.p.start())
             mock_logger.warning.assert_not_called()
             self.assertTrue(self.p.pending_restart)
+            mock_logger.info.assert_called_once()
+            self.assertEqual(mock_logger.info.call_args[0],
+                             ("%s value in pg_controldata: %d, in the global configuration: %d."
+                              " pg_controldata value will be used. Setting 'Pending restart' flag",
+                              'max_wal_senders', 10, 5))
 
     @patch('os.path.exists', Mock(return_value=True))
     @patch('os.path.isfile', Mock(return_value=False))
diff --git a/tests/test_validator.py b/tests/test_validator.py
index f70b387b..1c000c1c 100644
--- a/tests/test_validator.py
+++ b/tests/test_validator.py
@@ -378,31 +378,23 @@ class TestValidator(unittest.TestCase):
         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
-        )
+        self.assertIn("log.format {'levelname': 'level'} didn't pass validation: Should be a string or a list", errors)
+
+        c["log"]["format"] = []
+        errors = schema(c)
+        self.assertIn("log.format [] didn't pass validation: should contain at least one item", 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
-        )
+        self.assertIn("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
-        )
+        self.assertIn("log.format [[]] didn't pass validation: "
+                      "each item should be a string or a dictionary with string values", errors)
+
+        c["log"]["format"] = ['foo']
+        errors = schema(c)
+        output = "\n".join(errors)
+        self.assertEqual(['postgresql.bin_dir', 'raft.bind_addr', 'raft.self_addr'], parse_output(output))