Update system log grouping (#32367)

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
-
+        self.hash = str([self.name, *self.source, self.root_cause])
-    def hash(self):
-        """Calculate a key for DedupStore."""
-        return frozenset([self.name, self.message, 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
+            existing = self[key]
-            self[key].timestamp = entry.timestamp
+            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)

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")
+    log_msg()
-    _LOGGER.error("error message 2")
+    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_msg()
-    log = await get_error_log(hass, hass_client, 2)
+    log = await get_error_log(hass, hass_client, 3)
-    assert_log(log[0], "", "error message 2", "ERROR")
+    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"
+    assert log["source"] == ["custom_component/test.py", 5]
-
-
-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"