diff --git a/homeassistant/components/system_log/__init__.py b/homeassistant/components/system_log/__init__.py index 0c4270eaeef..2ddf02f76ed 100644 --- a/homeassistant/components/system_log/__init__.py +++ b/homeassistant/components/system_log/__init__.py @@ -1,5 +1,5 @@ """Support for system log.""" -from collections import OrderedDict +from collections import OrderedDict, deque import logging import re import traceback @@ -55,28 +55,21 @@ SERVICE_WRITE_SCHEMA = vol.Schema( def _figure_out_source(record, call_stack, hass): paths = [HOMEASSISTANT_PATH[0], hass.config.config_dir] - try: - # If netdisco is installed check its path too. - # pylint: disable=import-outside-toplevel - from netdisco import __path__ as netdisco_path - paths.append(netdisco_path[0]) - except ImportError: - pass # If a stack trace exists, extract file names from the entire call stack. # The other case is when a regular "log" is made (without an attached # exception). In that case, just use the file where the log was made from. if record.exc_info: - stack = [x[0] for x in traceback.extract_tb(record.exc_info[2])] + stack = [(x[0], x[1]) for x in traceback.extract_tb(record.exc_info[2])] else: index = -1 for i, frame in enumerate(call_stack): - if frame == record.pathname: + if frame[0] == record.pathname: index = i break if index == -1: # For some reason we couldn't find pathname in the stack. - stack = [record.pathname] + stack = [(record.pathname, record.lineno)] else: stack = call_stack[0 : index + 1] @@ -86,11 +79,11 @@ def _figure_out_source(record, call_stack, hass): for pathname in reversed(stack): # Try to match with a file within Home Assistant - match = re.match(paths_re, pathname) + match = re.match(paths_re, pathname[0]) if match: - return match.group(1) + return [match.group(1), pathname[1]] # Ok, we don't know what this is - return record.pathname + return (record.pathname, record.lineno) class LogEntry: @@ -101,7 +94,7 @@ class LogEntry: self.first_occured = self.timestamp = record.created self.name = record.name self.level = record.levelname - self.message = record.getMessage() + self.message = deque([record.getMessage()], maxlen=5) self.exception = "" self.root_cause = None if record.exc_info: @@ -112,14 +105,20 @@ class LogEntry: self.root_cause = str(traceback.extract_tb(tb)[-1]) self.source = source self.count = 1 - - def hash(self): - """Calculate a key for DedupStore.""" - return frozenset([self.name, self.message, self.root_cause]) + self.hash = str([self.name, *self.source, self.root_cause]) def to_dict(self): """Convert object into dict to maintain backward compatibility.""" - return vars(self) + return { + "name": self.name, + "message": list(self.message), + "level": self.level, + "source": self.source, + "timestamp": self.timestamp, + "exception": self.exception, + "count": self.count, + "first_occured": self.first_occured, + } class DedupStore(OrderedDict): @@ -132,12 +131,16 @@ class DedupStore(OrderedDict): def add_entry(self, entry): """Add a new entry.""" - key = str(entry.hash()) + key = entry.hash if key in self: # Update stored entry - self[key].count += 1 - self[key].timestamp = entry.timestamp + existing = self[key] + existing.count += 1 + existing.timestamp = entry.timestamp + + if entry.message[0] not in existing.message: + existing.message.append(entry.message[0]) self.move_to_end(key) else: @@ -172,7 +175,7 @@ class LogErrorHandler(logging.Handler): if record.levelno >= logging.WARN: stack = [] if not record.exc_info: - stack = [f for f, _, _, _ in traceback.extract_stack()] + stack = [(f[0], f[1]) for f in traceback.extract_stack()] entry = LogEntry( record, stack, _figure_out_source(record, stack, self.hass) diff --git a/tests/components/system_log/test_init.py b/tests/components/system_log/test_init.py index 0ad87b59a81..9862260c5f8 100644 --- a/tests/components/system_log/test_init.py +++ b/tests/components/system_log/test_init.py @@ -30,6 +30,9 @@ def _generate_and_log_exception(exception, log): def assert_log(log, exception, message, level): """Assert that specified values are in a specific log entry.""" + if not isinstance(message, list): + message = [message] + assert log["name"] == "test_logger" assert exception in log["exception"] assert message == log["message"] @@ -39,7 +42,7 @@ def assert_log(log, exception, message, level): def get_frame(name): """Get log stack frame.""" - return (name, None, None, None) + return (name, 5, None, None) async def test_normal_logs(hass, hass_client): @@ -134,23 +137,46 @@ async def test_remove_older_logs(hass, hass_client): assert_log(log[1], "", "error message 2", "ERROR") +def log_msg(nr=2): + """Log an error at same line.""" + _LOGGER.error(f"error message %s", nr) + + async def test_dedup_logs(hass, hass_client): """Test that duplicate log entries are dedup.""" - await async_setup_component(hass, system_log.DOMAIN, BASIC_CONFIG) + await async_setup_component(hass, system_log.DOMAIN, {}) _LOGGER.error("error message 1") - _LOGGER.error("error message 2") - _LOGGER.error("error message 2") + log_msg() + log_msg("2-2") _LOGGER.error("error message 3") - log = await get_error_log(hass, hass_client, 2) + log = await get_error_log(hass, hass_client, 3) assert_log(log[0], "", "error message 3", "ERROR") assert log[1]["count"] == 2 - assert_log(log[1], "", "error message 2", "ERROR") + assert_log(log[1], "", ["error message 2", "error message 2-2"], "ERROR") - _LOGGER.error("error message 2") - log = await get_error_log(hass, hass_client, 2) - assert_log(log[0], "", "error message 2", "ERROR") + log_msg() + log = await get_error_log(hass, hass_client, 3) + assert_log(log[0], "", ["error message 2", "error message 2-2"], "ERROR") assert log[0]["timestamp"] > log[0]["first_occured"] + log_msg("2-3") + log_msg("2-4") + log_msg("2-5") + log_msg("2-6") + log = await get_error_log(hass, hass_client, 3) + assert_log( + log[0], + "", + [ + "error message 2-2", + "error message 2-3", + "error message 2-4", + "error message 2-5", + "error message 2-6", + ], + "ERROR", + ) + async def test_clear_logs(hass, hass_client): """Test that the log can be cleared via a service call.""" @@ -218,7 +244,7 @@ async def test_unknown_path(hass, hass_client): _LOGGER.findCaller = MagicMock(return_value=("unknown_path", 0, None, None)) _LOGGER.error("error message") log = (await get_error_log(hass, hass_client, 1))[0] - assert log["source"] == "unknown_path" + assert log["source"] == ["unknown_path", 0] def log_error_from_test_path(path): @@ -250,7 +276,7 @@ async def test_homeassistant_path(hass, hass_client): ): log_error_from_test_path("venv_path/homeassistant/component/component.py") log = (await get_error_log(hass, hass_client, 1))[0] - assert log["source"] == "component/component.py" + assert log["source"] == ["component/component.py", 5] async def test_config_path(hass, hass_client): @@ -259,13 +285,4 @@ async def test_config_path(hass, hass_client): with patch.object(hass.config, "config_dir", new="config"): log_error_from_test_path("config/custom_component/test.py") log = (await get_error_log(hass, hass_client, 1))[0] - assert log["source"] == "custom_component/test.py" - - -async def test_netdisco_path(hass, hass_client): - """Test error logged from netdisco path.""" - await async_setup_component(hass, system_log.DOMAIN, BASIC_CONFIG) - with patch.dict("sys.modules", netdisco=MagicMock(__path__=["venv_path/netdisco"])): - log_error_from_test_path("venv_path/netdisco/disco_component.py") - log = (await get_error_log(hass, hass_client, 1))[0] - assert log["source"] == "disco_component.py" + assert log["source"] == ["custom_component/test.py", 5]