Logbook speedup (#18376)

* filter logbook results by entity_id prior to instantiating them

* include by default, pass pep8

* pass pylint

* use entityfilter, update tests

homeassistant/components/logbook.py

@@ -317,43 +317,90 @@ def humanify(hass, events):
                 }
 
 
+def _get_related_entity_ids(session, entity_filter):
+    from homeassistant.components.recorder.models import States
+    from homeassistant.components.recorder.util import \
+        RETRIES, QUERY_RETRY_WAIT
+    from sqlalchemy.exc import SQLAlchemyError
+    import time
+
+    timer_start = time.perf_counter()
+
+    query = session.query(States).with_entities(States.entity_id).distinct()
+
+    for tryno in range(0, RETRIES):
+        try:
+            result = [
+                row.entity_id for row in query
+                if entity_filter(row.entity_id)]
+
+            if _LOGGER.isEnabledFor(logging.DEBUG):
+                elapsed = time.perf_counter() - timer_start
+                _LOGGER.debug(
+                    'fetching %d distinct domain/entity_id pairs took %fs',
+                    len(result),
+                    elapsed)
+
+            return result
+        except SQLAlchemyError as err:
+            _LOGGER.error("Error executing query: %s", err)
+
+            if tryno == RETRIES - 1:
+                raise
+            else:
+                time.sleep(QUERY_RETRY_WAIT)
+
+
+def _generate_filter_from_config(config):
+    from homeassistant.helpers.entityfilter import generate_filter
+
+    excluded_entities = []
+    excluded_domains = []
+    included_entities = []
+    included_domains = []
+
+    exclude = config.get(CONF_EXCLUDE)
+    if exclude:
+        excluded_entities = exclude.get(CONF_ENTITIES, [])
+        excluded_domains = exclude.get(CONF_DOMAINS, [])
+    include = config.get(CONF_INCLUDE)
+    if include:
+        included_entities = include.get(CONF_ENTITIES, [])
+        included_domains = include.get(CONF_DOMAINS, [])
+
+    return generate_filter(included_domains, included_entities,
+                           excluded_domains, excluded_entities)
+
+
 def _get_events(hass, config, start_day, end_day, entity_id=None):
     """Get events for a period of time."""
     from homeassistant.components.recorder.models import Events, States
     from homeassistant.components.recorder.util import (
         execute, session_scope)
 
+    entities_filter = _generate_filter_from_config(config)
+
     with session_scope(hass=hass) as session:
+        if entity_id is not None:
+            entity_ids = [entity_id.lower()]
+        else:
+            entity_ids = _get_related_entity_ids(session, entities_filter)
+
         query = session.query(Events).order_by(Events.time_fired) \
-            .outerjoin(States, (Events.event_id == States.event_id))  \
+            .outerjoin(States, (Events.event_id == States.event_id)) \
             .filter(Events.event_type.in_(ALL_EVENT_TYPES)) \
             .filter((Events.time_fired > start_day)
                     & (Events.time_fired < end_day)) \
             .filter((States.last_updated == States.last_changed)
-                    | (States.state_id.is_(None)))
+                    | (States.state_id.is_(None))) \
-
+            .filter(States.entity_id.in_(entity_ids))
-        if entity_id is not None:
-            query = query.filter(States.entity_id == entity_id.lower())
 
         events = execute(query)
-    return humanify(hass, _exclude_events(events, config))
+
+    return humanify(hass, _exclude_events(events, entities_filter))
 
 
-def _exclude_events(events, config):
+def _exclude_events(events, entities_filter):
-    """Get list of filtered events."""
-    excluded_entities = []
-    excluded_domains = []
-    included_entities = []
-    included_domains = []
-    exclude = config.get(CONF_EXCLUDE)
-    if exclude:
-        excluded_entities = exclude[CONF_ENTITIES]
-        excluded_domains = exclude[CONF_DOMAINS]
-    include = config.get(CONF_INCLUDE)
-    if include:
-        included_entities = include[CONF_ENTITIES]
-        included_domains = include[CONF_DOMAINS]
-
     filtered_events = []
     for event in events:
         domain, entity_id = None, None
@@ -398,34 +445,12 @@ def _exclude_events(events, config):
             domain = event.data.get(ATTR_DOMAIN)
             entity_id = event.data.get(ATTR_ENTITY_ID)
 
-        if domain or entity_id:
+        if not entity_id and domain:
-            # filter if only excluded is configured for this domain
+            entity_id = "%s." % (domain, )
-            if excluded_domains and domain in excluded_domains and \
+
-                    not included_domains:
+        if not entity_id or entities_filter(entity_id):
-                if (included_entities and entity_id not in included_entities) \
+            filtered_events.append(event)
-                        or not included_entities:
+
-                    continue
-            # filter if only included is configured for this domain
-            elif not excluded_domains and included_domains and \
-                    domain not in included_domains:
-                if (included_entities and entity_id not in included_entities) \
-                        or not included_entities:
-                    continue
-            # filter if included and excluded is configured for this domain
-            elif excluded_domains and included_domains and \
-                    (domain not in included_domains or
-                     domain in excluded_domains):
-                if (included_entities and entity_id not in included_entities) \
-                        or not included_entities or domain in excluded_domains:
-                    continue
-            # filter if only included is configured for this entity
-            elif not excluded_domains and not included_domains and \
-                    included_entities and entity_id not in included_entities:
-                continue
-            # check if logbook entry is excluded for this entity
-            if entity_id in excluded_entities:
-                continue
-        filtered_events.append(event)
     return filtered_events
 
 

homeassistant/components/recorder/migration.py

@@ -218,6 +218,8 @@ def _apply_update(engine, new_version, old_version):
         ])
         _create_index(engine, "states", "ix_states_context_id")
         _create_index(engine, "states", "ix_states_context_user_id")
+    elif new_version == 7:
+        _create_index(engine, "states", "ix_states_entity_id")
     else:
         raise ValueError("No schema migration defined for version {}"
                          .format(new_version))

homeassistant/components/recorder/models.py

@@ -17,7 +17,7 @@ from homeassistant.helpers.json import JSONEncoder
 # pylint: disable=invalid-name
 Base = declarative_base()
 
-SCHEMA_VERSION = 6
+SCHEMA_VERSION = 7
 
 _LOGGER = logging.getLogger(__name__)
 
@@ -71,7 +71,7 @@ class States(Base):   # type: ignore
     __tablename__ = 'states'
     state_id = Column(Integer, primary_key=True)
     domain = Column(String(64))
-    entity_id = Column(String(255))
+    entity_id = Column(String(255), index=True)
     state = Column(String(255))
     attributes = Column(Text)
     event_id = Column(Integer, ForeignKey('events.event_id'), index=True)
@@ -86,7 +86,8 @@ class States(Base):   # type: ignore
         # Used for fetching the state of entities at a specific time
         # (get_states in history.py)
         Index(
-            'ix_states_entity_id_last_updated', 'entity_id', 'last_updated'),)
+            'ix_states_entity_id_last_updated', 'entity_id', 'last_updated'),
+    )
 
     @staticmethod
     def from_event(event):

tests/components/test_logbook.py

@@ -136,8 +136,10 @@ class TestComponentLogbook(unittest.TestCase):
         eventB = self.create_state_changed_event(pointB, entity_id2, 20)
         eventA.data['old_state'] = None
 
-        events = logbook._exclude_events((ha.Event(EVENT_HOMEASSISTANT_STOP),
+        events = logbook._exclude_events(
-                                          eventA, eventB), {})
+            (ha.Event(EVENT_HOMEASSISTANT_STOP),
+             eventA, eventB),
+            logbook._generate_filter_from_config({}))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -158,8 +160,10 @@ class TestComponentLogbook(unittest.TestCase):
         eventB = self.create_state_changed_event(pointB, entity_id2, 20)
         eventA.data['new_state'] = None
 
-        events = logbook._exclude_events((ha.Event(EVENT_HOMEASSISTANT_STOP),
+        events = logbook._exclude_events(
-                                          eventA, eventB), {})
+            (ha.Event(EVENT_HOMEASSISTANT_STOP),
+             eventA, eventB),
+            logbook._generate_filter_from_config({}))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -180,8 +184,10 @@ class TestComponentLogbook(unittest.TestCase):
                                                  {ATTR_HIDDEN: 'true'})
         eventB = self.create_state_changed_event(pointB, entity_id2, 20)
 
-        events = logbook._exclude_events((ha.Event(EVENT_HOMEASSISTANT_STOP),
+        events = logbook._exclude_events(
-                                          eventA, eventB), {})
+            (ha.Event(EVENT_HOMEASSISTANT_STOP),
+             eventA, eventB),
+            logbook._generate_filter_from_config({}))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -207,7 +213,7 @@ class TestComponentLogbook(unittest.TestCase):
                 logbook.CONF_ENTITIES: [entity_id, ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_STOP), eventA, eventB),
-            config[logbook.DOMAIN])
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -233,7 +239,7 @@ class TestComponentLogbook(unittest.TestCase):
                 logbook.CONF_DOMAINS: ['switch', ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_START), eventA, eventB),
-            config[logbook.DOMAIN])
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -270,7 +276,7 @@ class TestComponentLogbook(unittest.TestCase):
                 logbook.CONF_ENTITIES: [entity_id, ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_STOP), eventA, eventB),
-            config[logbook.DOMAIN])
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -296,7 +302,7 @@ class TestComponentLogbook(unittest.TestCase):
                 logbook.CONF_ENTITIES: [entity_id2, ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_STOP), eventA, eventB),
-            config[logbook.DOMAIN])
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -322,7 +328,7 @@ class TestComponentLogbook(unittest.TestCase):
                 logbook.CONF_DOMAINS: ['sensor', ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_START), eventA, eventB),
-            config[logbook.DOMAIN])
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 2 == len(entries)
@@ -356,15 +362,20 @@ class TestComponentLogbook(unittest.TestCase):
                     logbook.CONF_ENTITIES: ['sensor.bli', ]}}})
         events = logbook._exclude_events(
             (ha.Event(EVENT_HOMEASSISTANT_START), eventA1, eventA2, eventA3,
-             eventB1, eventB2), config[logbook.DOMAIN])
+             eventB1, eventB2),
+            logbook._generate_filter_from_config(config[logbook.DOMAIN]))
         entries = list(logbook.humanify(self.hass, events))
 
-        assert 3 == len(entries)
+        assert 5 == len(entries)
         self.assert_entry(entries[0], name='Home Assistant', message='started',
                           domain=ha.DOMAIN)
-        self.assert_entry(entries[1], pointA, 'blu', domain='sensor',
+        self.assert_entry(entries[1], pointA, 'bla', domain='switch',
+                          entity_id=entity_id)
+        self.assert_entry(entries[2], pointA, 'blu', domain='sensor',
                           entity_id=entity_id2)
-        self.assert_entry(entries[2], pointB, 'blu', domain='sensor',
+        self.assert_entry(entries[3], pointB, 'bla', domain='switch',
+                          entity_id=entity_id)
+        self.assert_entry(entries[4], pointB, 'blu', domain='sensor',
                           entity_id=entity_id2)
 
     def test_exclude_auto_groups(self):
@@ -377,7 +388,9 @@ class TestComponentLogbook(unittest.TestCase):
         eventB = self.create_state_changed_event(pointA, entity_id2, 20,
                                                  {'auto': True})
 
-        events = logbook._exclude_events((eventA, eventB), {})
+        events = logbook._exclude_events(
+            (eventA, eventB),
+            logbook._generate_filter_from_config({}))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 1 == len(entries)
@@ -395,7 +408,9 @@ class TestComponentLogbook(unittest.TestCase):
         eventB = self.create_state_changed_event(
             pointA, entity_id2, 20, last_changed=pointA, last_updated=pointB)
 
-        events = logbook._exclude_events((eventA, eventB), {})
+        events = logbook._exclude_events(
+            (eventA, eventB),
+            logbook._generate_filter_from_config({}))
         entries = list(logbook.humanify(self.hass, events))
 
         assert 1 == len(entries)