From 0c3ccabfb1bbbc2f3492bc3621c8f1fb30b464ef Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 3 Apr 2024 20:35:44 -1000 Subject: [PATCH] Speed up logger setup (#114610) * Speed up logger setup Preload core.logger and avoid saving it until after startup * add comment about 180s * Adjust grammar --------- Co-authored-by: Martin Hjelmare --- homeassistant/bootstrap.py | 1 + homeassistant/components/logger/helpers.py | 16 +++++++++++++--- tests/components/logger/test_init.py | 15 ++++++++++++++- 3 files changed, 28 insertions(+), 4 deletions(-) diff --git a/homeassistant/bootstrap.py b/homeassistant/bootstrap.py index 97bdd615d69..373c5c0f38c 100644 --- a/homeassistant/bootstrap.py +++ b/homeassistant/bootstrap.py @@ -223,6 +223,7 @@ SETUP_ORDER = ( # If they do not exist they will not be loaded # PRELOAD_STORAGE = [ + "core.logger", "core.network", "http.auth", "image", diff --git a/homeassistant/components/logger/helpers.py b/homeassistant/components/logger/helpers.py index a527a081fca..034266428a3 100644 --- a/homeassistant/components/logger/helpers.py +++ b/homeassistant/components/logger/helpers.py @@ -28,6 +28,16 @@ from .const import ( STORAGE_VERSION, ) +SAVE_DELAY = 15.0 +# At startup, we want to save after a long delay to avoid +# saving while the system is still starting up. If the system +# for some reason restarts quickly, it will still be written +# at the final write event. In most cases we expect startup +# to happen in less than 180 seconds, but if it takes longer +# it's likely delayed because of remote I/O and not local +# I/O so it's fine to save at that point. +SAVE_DELAY_LONG = 180.0 + @callback def async_get_domain_config(hass: HomeAssistant) -> LoggerDomainConfig: @@ -148,7 +158,7 @@ class LoggerSettings: for domain, settings in stored_log_config.items() } } - await self._store.async_save(self._async_data_to_save()) + self.async_save(SAVE_DELAY_LONG) @callback def _async_data_to_save(self) -> dict[str, dict[str, dict[str, str]]]: @@ -164,9 +174,9 @@ class LoggerSettings: } @callback - def async_save(self) -> None: + def async_save(self, delay: float = SAVE_DELAY) -> None: """Save settings.""" - self._store.async_delay_save(self._async_data_to_save, 15) + self._store.async_delay_save(self._async_data_to_save, delay) @callback def _async_get_logger_logs(self) -> dict[str, int]: diff --git a/tests/components/logger/test_init.py b/tests/components/logger/test_init.py index 3e30ea0ead0..d6df1f92a72 100644 --- a/tests/components/logger/test_init.py +++ b/tests/components/logger/test_init.py @@ -1,6 +1,7 @@ """The tests for the Logger component.""" from collections import defaultdict +import datetime import logging from typing import Any from unittest.mock import Mock, patch @@ -9,8 +10,12 @@ import pytest from homeassistant.components import logger from homeassistant.components.logger import LOGSEVERITY +from homeassistant.components.logger.helpers import SAVE_DELAY_LONG from homeassistant.core import HomeAssistant from homeassistant.setup import async_setup_component +from homeassistant.util import dt as dt_util + +from tests.common import async_fire_time_changed HASS_NS = "unused.homeassistant" COMPONENTS_NS = f"{HASS_NS}.components" @@ -403,7 +408,7 @@ async def test_log_once_removed_from_store( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test logs with persistence "once" are removed from the store at startup.""" - hass_storage["core.logger"] = { + store_contents = { "data": { "logs": { ZONE_NS: {"type": "module", "level": "DEBUG", "persistence": "once"} @@ -412,7 +417,15 @@ async def test_log_once_removed_from_store( "key": "core.logger", "version": 1, } + hass_storage["core.logger"] = store_contents assert await async_setup_component(hass, "logger", {}) + assert hass_storage["core.logger"]["data"] == store_contents["data"] + + async_fire_time_changed( + hass, dt_util.utcnow() + datetime.timedelta(seconds=SAVE_DELAY_LONG) + ) + await hass.async_block_till_done() + assert hass_storage["core.logger"]["data"] == {"logs": {}}