Skip the sqlite quick_check on clean restarts (#38972)

homeassistant/components/recorder/models.py

@@ -30,11 +30,18 @@ _LOGGER = logging.getLogger(__name__)
 
 DB_TIMEZONE = "+00:00"
 
+TABLE_EVENTS = "events"
+TABLE_STATES = "states"
+TABLE_RECORDER_RUNS = "recorder_runs"
+TABLE_SCHEMA_CHANGES = "schema_changes"
+
+ALL_TABLES = [TABLE_EVENTS, TABLE_STATES, TABLE_RECORDER_RUNS, TABLE_SCHEMA_CHANGES]
+
 
 class Events(Base):  # type: ignore
     """Event history data."""
 
-    __tablename__ = "events"
+    __tablename__ = TABLE_EVENTS
     event_id = Column(Integer, primary_key=True)
     event_type = Column(String(32))
     event_data = Column(Text)
@@ -88,7 +95,7 @@ class Events(Base):  # type: ignore
 class States(Base):  # type: ignore
     """State change history."""
 
-    __tablename__ = "states"
+    __tablename__ = TABLE_STATES
     state_id = Column(Integer, primary_key=True)
     domain = Column(String(64))
     entity_id = Column(String(255))
@@ -153,7 +160,7 @@ class States(Base):  # type: ignore
 class RecorderRuns(Base):  # type: ignore
     """Representation of recorder run."""
 
-    __tablename__ = "recorder_runs"
+    __tablename__ = TABLE_RECORDER_RUNS
     run_id = Column(Integer, primary_key=True)
     start = Column(DateTime(timezone=True), default=dt_util.utcnow)
     end = Column(DateTime(timezone=True))
@@ -191,7 +198,7 @@ class RecorderRuns(Base):  # type: ignore
 class SchemaChanges(Base):  # type: ignore
     """Representation of schema version changes."""
 
-    __tablename__ = "schema_changes"
+    __tablename__ = TABLE_SCHEMA_CHANGES
     change_id = Column(Integer, primary_key=True)
     schema_version = Column(Integer)
     changed = Column(DateTime(timezone=True), default=dt_util.utcnow)

homeassistant/components/recorder/util.py

@@ -1,5 +1,6 @@
 """SQLAlchemy util functions."""
 from contextlib import contextmanager
+from datetime import timedelta
 import logging
 import os
 import time
@@ -9,6 +10,7 @@ from sqlalchemy.exc import OperationalError, SQLAlchemyError
 import homeassistant.util.dt as dt_util
 
 from .const import DATA_INSTANCE, SQLITE_URL_PREFIX
+from .models import ALL_TABLES, process_timestamp
 
 _LOGGER = logging.getLogger(__name__)
 
@@ -16,6 +18,11 @@ RETRIES = 3
 QUERY_RETRY_WAIT = 0.1
 SQLITE3_POSTFIXES = ["", "-wal", "-shm"]
 
+# This is the maximum time after the recorder ends the session
+# before we no longer consider startup to be a "restart" and we
+# should do a check on the sqlite3 database.
+MAX_RESTART_TIME = timedelta(minutes=6)
+
 
 @contextmanager
 def session_scope(*, hass=None, session=None):
@@ -116,13 +123,42 @@ def validate_or_move_away_sqlite_database(dburl: str) -> bool:
     return True
 
 
+def last_run_was_recently_clean(cursor):
+    """Verify the last recorder run was recently clean."""
+
+    cursor.execute("SELECT end FROM recorder_runs ORDER BY start DESC LIMIT 1;")
+    end_time = cursor.fetchone()
+
+    if not end_time or not end_time[0]:
+        return False
+
+    last_run_end_time = process_timestamp(dt_util.parse_datetime(end_time[0]))
+    now = dt_util.utcnow()
+
+    _LOGGER.debug("The last run ended at: %s (now: %s)", last_run_end_time, now)
+
+    if last_run_end_time + MAX_RESTART_TIME < now:
+        return False
+
+    return True
+
+
+def basic_sanity_check(cursor):
+    """Check tables to make sure select does not fail."""
+
+    for table in ALL_TABLES:
+        cursor.execute(f"SELECT * FROM {table} LIMIT 1;")  # sec: not injection
+
+    return True
+
+
 def validate_sqlite_database(dbpath: str) -> bool:
     """Run a quick check on an sqlite database to see if it is corrupt."""
     import sqlite3  # pylint: disable=import-outside-toplevel
 
     try:
         conn = sqlite3.connect(dbpath)
-        conn.cursor().execute("PRAGMA QUICK_CHECK")
+        run_checks_on_open_db(dbpath, conn.cursor())
         conn.close()
     except sqlite3.DatabaseError:
         _LOGGER.exception("The database at %s is corrupt or malformed.", dbpath)
@@ -131,6 +167,20 @@ def validate_sqlite_database(dbpath: str) -> bool:
     return True
 
 
+def run_checks_on_open_db(dbpath, cursor):
+    """Run checks that will generate a sqlite3 exception if there is corruption."""
+    if basic_sanity_check(cursor) and last_run_was_recently_clean(cursor):
+        _LOGGER.debug(
+            "The quick_check will be skipped as the system was restarted cleanly and passed the basic sanity check"
+        )
+        return
+
+    _LOGGER.debug(
+        "A quick_check is being performed on the sqlite3 database at %s", dbpath
+    )
+    cursor.execute("PRAGMA QUICK_CHECK")
+
+
 def _move_away_broken_database(dbfile: str) -> None:
     """Move away a broken sqlite3 database."""
 

tests/components/recorder/test_util.py

@@ -1,10 +1,13 @@
 """Test util methods."""
+from datetime import timedelta
 import os
+import sqlite3
 
 import pytest
 
 from homeassistant.components.recorder import util
 from homeassistant.components.recorder.const import DATA_INSTANCE, SQLITE_URL_PREFIX
+from homeassistant.util import dt as dt_util
 
 from tests.async_mock import MagicMock, patch
 from tests.common import get_test_home_assistant, init_recorder_component
@@ -74,17 +77,81 @@ def test_validate_or_move_away_sqlite_database(hass, tmpdir, caplog):
     util.validate_sqlite_database(test_db_file) is True
 
     assert os.path.exists(test_db_file) is True
-    assert util.validate_or_move_away_sqlite_database(dburl) is True
+    assert util.validate_or_move_away_sqlite_database(dburl) is False
 
     _corrupt_db_file(test_db_file)
 
+    assert util.validate_sqlite_database(dburl) is False
+
     assert util.validate_or_move_away_sqlite_database(dburl) is False
 
     assert "corrupt or malformed" in caplog.text
 
+    assert util.validate_sqlite_database(dburl) is False
+
     assert util.validate_or_move_away_sqlite_database(dburl) is True
 
 
+def test_last_run_was_recently_clean(hass_recorder):
+    """Test we can check if the last recorder run was recently clean."""
+    hass = hass_recorder()
+
+    cursor = hass.data[DATA_INSTANCE].engine.raw_connection().cursor()
+
+    assert util.last_run_was_recently_clean(cursor) is False
+
+    hass.data[DATA_INSTANCE]._close_run()
+
+    assert util.last_run_was_recently_clean(cursor) is True
+
+    thirty_min_future_time = dt_util.utcnow() + timedelta(minutes=30)
+
+    with patch(
+        "homeassistant.components.recorder.dt_util.utcnow",
+        return_value=thirty_min_future_time,
+    ):
+        assert util.last_run_was_recently_clean(cursor) is False
+
+
+def test_basic_sanity_check(hass_recorder):
+    """Test the basic sanity checks with a missing table."""
+    hass = hass_recorder()
+
+    cursor = hass.data[DATA_INSTANCE].engine.raw_connection().cursor()
+
+    assert util.basic_sanity_check(cursor) is True
+
+    cursor.execute("DROP TABLE states;")
+
+    with pytest.raises(sqlite3.DatabaseError):
+        util.basic_sanity_check(cursor)
+
+
+def test_combined_checks(hass_recorder):
+    """Run Checks on the open database."""
+    hass = hass_recorder()
+
+    cursor = hass.data[DATA_INSTANCE].engine.raw_connection().cursor()
+
+    assert util.run_checks_on_open_db("fake_db_path", cursor) is None
+
+    # We are patching recorder.util here in order
+    # to avoid creating the full database on disk
+    with patch("homeassistant.components.recorder.util.last_run_was_recently_clean"):
+        assert util.run_checks_on_open_db("fake_db_path", cursor) is None
+
+    with patch(
+        "homeassistant.components.recorder.util.last_run_was_recently_clean",
+        side_effect=sqlite3.DatabaseError,
+    ), pytest.raises(sqlite3.DatabaseError):
+        util.run_checks_on_open_db("fake_db_path", cursor)
+
+    cursor.execute("DROP TABLE events;")
+
+    with pytest.raises(sqlite3.DatabaseError):
+        util.run_checks_on_open_db("fake_db_path", cursor)
+
+
 def _corrupt_db_file(test_db_file):
     """Corrupt an sqlite3 database file."""
     f = open(test_db_file, "a")