def test_config_file_exception(self, config, path):
"""Test other errors (e.g. /dev/log permission)."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = OSError
self._mock_logger()
LogManager.load_config_file('existent_file')
self._assert_string_in_logs('Using default Python logging config')
def test_set_debug_mode_with_false(self, config, path, parser):
"""Test set_debug_mode with debug = False."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = OSError
self._mock_logger()
LogManager.load_config_file('existent_file', debug=False)
parser.set.assert_not_called()
def test_custom_formatter(path, parser):
"""Should use a custom formatter instead of Python's default."""
path.return_value.exists.return_value = False
# Make sure we have the custome formatter section
parser.__contains__.return_value = True
handler = Mock()
LogManager.add_handler(handler)
handler.setFormatter.assert_called_once()
def test_parent_handler_usage():
"""Existent logger should use a new handler."""
# First, get a child logger.
old_logger = logging.getLogger('non-root logger')
# Then, add a new handler.
new_handler = Mock(level=logging.DEBUG)
LogManager.add_handler(new_handler)
old_logger.setLevel(logging.DEBUG)
old_logger.debug('Handler should receive me.')
new_handler.handle.assert_called_once()
def test_no_syslog(self, path, config, parser):
"""Must log when there's no syslog and try again without it."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = [OSError, None]
parser.__contains__.return_value = True # must have syslog section
self._mock_logger()
LogManager.load_config_file('existent_file')
self._assert_string_in_logs('Trying to disable syslog')
parser.remove_section.assert_called_once_with('handler_syslog')
self._assert_string_in_logs('Logging config file "%s" loaded '
'successfully.')
def test_no_syslog(self, path, config, parser):
"""Must log when there's no syslog and try again without it."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = [OSError, None]
parser.__contains__.return_value = True # must have syslog section
self._mock_logger()
LogManager.load_config_file('existent_file')
self._assert_string_in_logs('Trying to disable syslog')
parser.remove_section.assert_called_once_with('handler_syslog')
self._assert_string_in_logs('Logging config file "%s" loaded '
'successfully.')
def test_handler_filter(self):
"""Should not log harmless werkzeug "session is disconnected" msg."""
logging.root.handlers = []
handler = Mock(level=logging.WARNING)
LogManager.add_handler(handler)
# Message based on the log output that ends with traceback plaintext as
# seen in site-packages/werkzeug/serving.py:225 of Werkzeug==0.12.1
msg = "lorem ipsum KeyError: 'Session is disconnected'"
logger = logging.getLogger('werkzeug')
logger.setLevel(logging.ERROR)
with patch.object(handler, 'emit'):
logger.error('lorem ipsum %s', msg)
self.assertEqual(0, handler.emit.call_count)
def test_set_debug_mode(self, config, path, parser):
"""Test set_debug_mode with debug = True."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = OSError
self._mock_logger()
LogManager.load_config_file('existent_file', debug=True)
expected_message = 'Setting log configuration with debug mode.'
self._assert_string_in_logs(expected_message)
parser.set('logger_root', 'level', 'DEBUG')
parser.set.assert_called_with('logger_root', 'level', 'DEBUG')
parser.set('logger_api_server', 'level', 'DEBUG')
parser.set.assert_called_with('logger_api_server', 'level', 'DEBUG')
def test_set_debug_mode(self, config, path, parser):
"""Test set_debug_mode with debug = True."""
path.return_value.exists.return_value = True
config.fileConfig.side_effect = OSError
self._mock_logger()
LogManager.load_config_file('existent_file', debug=True)
expected_message = 'Setting log configuration with debug mode.'
self._assert_string_in_logs(expected_message)
parser.set('logger_root', 'level', 'DEBUG')
parser.set.assert_called_with('logger_root', 'level', 'DEBUG')
parser.set('logger_api_server', 'level', 'DEBUG')
parser.set.assert_called_with('logger_api_server', 'level', 'DEBUG')
def test_handler_filter(self):
"""Should not log harmless werkzeug "session is disconnected" msg."""
logging.root.handlers = []
handler = Mock(level=logging.WARNING)
LogManager.add_handler(handler)
# Message based on the log output that ends with traceback plaintext as
# seen in lib/python3.6/site-packages/werkzeug/serving.py:225 of
# Werkzeug==0.12.1
msg = "lorem ipsum KeyError: 'Session is disconnected'"
logger = logging.getLogger('werkzeug')
logger.setLevel(logging.ERROR)
with patch.object(handler, 'emit'):
logger.error('lorem ipsum %s', msg)
self.assertEqual(0, handler.emit.call_count)
def test_custom_formatter(path, parser):
"""Should use a custom formatter instead of Python's default."""
path.return_value.exists.return_value = False
# Make sure we have the custome formatter section
parser.__contains__.return_value = True
# Make 'parser' behave as a dict, this is necessary because the _PARSER
# is being patched returning a MagicMock (inside add_handler) and in
# 'logging' module (python 3.8) the 'Formatter' class includes a
# 'validate' method that breaks when receives a MagicMock object.
format_dict = {'formatter_console': {'format': None}}
parser.__getitem__.side_effect = format_dict.__getitem__
handler = Mock()
LogManager.add_handler(handler)
handler.setFormatter.assert_called_once()
def test_no_requests_logging(self):
"""Should not log web requests to avoid an infinite logging loop.
Do not log any level below warning.
"""
# Save original state
handlers_bak = copy(logging.root.handlers)
logging.root.handlers = []
socket = Mock()
LogManager.enable_websocket(socket)
# Lower logger level simulating logging.ini config
web_logger = logging.getLogger('werkzeug')
web_logger.setLevel(logging.DEBUG)
web_logger.info('should not log')
self.assertEqual(0, socket.call_count)
web_logger.warning('should log')
self.assertEqual(1, socket.emit.call_count)
# Restore original state
logging.root.handlers = handlers_bak
def toggle_debug(self, name=None):
"""Enable/disable logging debug messages to a given logger name.
If the name parameter is not specified the debug will be
enabled/disabled following the initial config file. It will decide
to enable/disable using the 'kytos' name to find the current
logger level.
Obs: To disable the debug the logging will be set to NOTSET
Args:
name(text): Full hierarchy Logger name. Ex: "kytos.core.controller"
"""
if name and name not in logging.root.manager.loggerDict:
# A Logger name that is not declared in logging will raise an error
# otherwise logging would create a new Logger.
raise ValueError(f"Invalid logger name: {name}")
if not name:
# Logger name not specified.
level = logging.getLogger('kytos').getEffectiveLevel()
enable_debug = level != logging.DEBUG
# Enable/disable default Loggers
LogManager.load_config_file(self.options.logging, enable_debug)
return
# Get effective logger level for the name
level = logging.getLogger(name).getEffectiveLevel()
logger = logging.getLogger(name)
if level == logging.DEBUG:
# disable debug
logger.setLevel(logging.NOTSET)
else:
# enable debug
logger.setLevel(logging.DEBUG)
def enable_logs(self):
"""Register kytos log and enable the logs."""
LogManager.load_config_file(self.options.logging, self.options.debug)
LogManager.enable_websocket(self.api_server.server)
self.log = logging.getLogger(__name__)
def test_non_existent_config_file(self, path):
"""If config file doesn't exist, warn instead of raising exception."""
self._mock_logger()
path.return_value.exists.return_value = False
LogManager.load_config_file('non_existent_file')
self._assert_string_in_logs('Log config file "%s" does not exist.')
def test_add_websocket(self):
"""A stream should be used in a handler added to the root logger."""
socket = Mock()
handler = LogManager.enable_websocket(socket)
self.assertIn(handler, logging.root.handlers)
def test_add_websocket(self):
"""A stream should be used in a handler added to the root logger."""
socket = Mock()
handler = LogManager.enable_websocket(socket)
self.assertIn(handler, logging.root.handlers)
def test_add_handler_to_root(self):
"""Handler should be added to root logger."""
handler = Mock()
LogManager.add_handler(handler)
self.assertIn(handler, logging.root.handlers)
def test_add_handler_to_root(self):
"""Handler should be added to root logger."""
handler = Mock()
LogManager.add_handler(handler)
self.assertIn(handler, logging.root.handlers)
def test_non_existent_config_file(self, path):
"""If config file doesn't exist, warn instead of raising exception."""
self._mock_logger()
path.return_value.exists.return_value = False
LogManager.load_config_file('non_existent_file')
self._assert_string_in_logs('Log config file "%s" does not exist.')
def enable_logs(self):
"""Register kytos log and enable the logs."""
LogManager.load_config_file(self.options.logging, self.options.debug)
LogManager.enable_websocket(self.api_server.server)
self.log = logging.getLogger("controller")
