diff --git a/homeassistant/components/profiler/__init__.py b/homeassistant/components/profiler/__init__.py index fab6932edd2..b838f67d02e 100644 --- a/homeassistant/components/profiler/__init__.py +++ b/homeassistant/components/profiler/__init__.py @@ -1,6 +1,8 @@ """The profiler integration.""" import asyncio +from contextlib import suppress from datetime import timedelta +from functools import _lru_cache_wrapper import logging import reprlib import sys @@ -9,6 +11,7 @@ import time import traceback from typing import Any, cast +from lru import LRU # pylint: disable=no-name-in-module import voluptuous as vol from homeassistant.components import persistent_notification @@ -27,9 +30,21 @@ SERVICE_MEMORY = "memory" SERVICE_START_LOG_OBJECTS = "start_log_objects" SERVICE_STOP_LOG_OBJECTS = "stop_log_objects" SERVICE_DUMP_LOG_OBJECTS = "dump_log_objects" +SERVICE_LRU_STATS = "lru_stats" SERVICE_LOG_THREAD_FRAMES = "log_thread_frames" SERVICE_LOG_EVENT_LOOP_SCHEDULED = "log_event_loop_scheduled" +_LRU_CACHE_WRAPPER_OBJECT = _lru_cache_wrapper.__name__ + +_KNOWN_LRU_CLASSES = ( + "EventDataManager", + "EventTypeManager", + "StatesMetaManager", + "StateAttributesManager", + "StatisticsMetaManager", + "DomainData", + "IntegrationMatcher", +) SERVICES = ( SERVICE_START, @@ -37,6 +52,7 @@ SERVICES = ( SERVICE_START_LOG_OBJECTS, SERVICE_STOP_LOG_OBJECTS, SERVICE_DUMP_LOG_OBJECTS, + SERVICE_LRU_STATS, SERVICE_LOG_THREAD_FRAMES, SERVICE_LOG_EVENT_LOOP_SCHEDULED, ) @@ -47,6 +63,7 @@ CONF_SECONDS = "seconds" LOG_INTERVAL_SUB = "log_interval_subscription" + _LOGGER = logging.getLogger(__name__) @@ -123,6 +140,52 @@ async def async_setup_entry(hass: HomeAssistant, entry: ConfigEntry) -> bool: notification_id="profile_object_dump", ) + def _get_function_absfile(func: Any) -> str: + """Get the absolute file path of a function.""" + import inspect # pylint: disable=import-outside-toplevel + + abs_file = "unknown" + with suppress(Exception): + abs_file = inspect.getabsfile(func) + return abs_file + + def _lru_stats(call: ServiceCall) -> None: + """Log the stats of all lru caches.""" + # Imports deferred to avoid loading modules + # in memory since usually only one part of this + # integration is used at a time + import objgraph # pylint: disable=import-outside-toplevel + + for lru in objgraph.by_type(_LRU_CACHE_WRAPPER_OBJECT): + lru = cast(_lru_cache_wrapper, lru) + _LOGGER.critical( + "Cache stats for lru_cache %s at %s: %s", + lru.__wrapped__, + _get_function_absfile(lru.__wrapped__), + lru.cache_info(), + ) + + for _class in _KNOWN_LRU_CLASSES: + for class_with_lru_attr in objgraph.by_type(_class): + for maybe_lru in class_with_lru_attr.__dict__.values(): + if isinstance(maybe_lru, LRU): + _LOGGER.critical( + "Cache stats for LRU %s at %s: %s", + type(class_with_lru_attr), + _get_function_absfile(class_with_lru_attr), + maybe_lru.get_stats(), + ) + + persistent_notification.create( + hass, + ( + "LRU cache states have been dumped to the log. See [the" + " logs](/config/logs) to review the stats." + ), + title="LRU stats completed", + notification_id="profile_lru_stats", + ) + async def _async_dump_thread_frames(call: ServiceCall) -> None: """Log all thread frames.""" frames = sys._current_frames() # pylint: disable=protected-access @@ -202,6 +265,13 @@ async def async_setup_entry(hass: HomeAssistant, entry: ConfigEntry) -> bool: schema=vol.Schema({vol.Required(CONF_TYPE): str}), ) + async_register_admin_service( + hass, + DOMAIN, + SERVICE_LRU_STATS, + _lru_stats, + ) + async_register_admin_service( hass, DOMAIN, @@ -323,4 +393,4 @@ def _log_objects(*_): # integration is used at a time import objgraph # pylint: disable=import-outside-toplevel - _LOGGER.critical("Memory Growth: %s", objgraph.growth(limit=100)) + _LOGGER.critical("Memory Growth: %s", objgraph.growth(limit=1000)) diff --git a/homeassistant/components/profiler/services.yaml b/homeassistant/components/profiler/services.yaml index 8d9ae35ed10..1105842891f 100644 --- a/homeassistant/components/profiler/services.yaml +++ b/homeassistant/components/profiler/services.yaml @@ -51,6 +51,9 @@ dump_log_objects: example: State selector: text: +lru_stats: + name: Log LRU stats + description: Log the stats of all lru caches. log_thread_frames: name: Log thread frames description: Log the current frames for all threads. diff --git a/tests/components/profiler/test_init.py b/tests/components/profiler/test_init.py index 0f46f306fef..2c283463b62 100644 --- a/tests/components/profiler/test_init.py +++ b/tests/components/profiler/test_init.py @@ -1,9 +1,11 @@ """Test the Profiler config flow.""" from datetime import timedelta +from functools import lru_cache import os import sys from unittest.mock import patch +from lru import LRU # pylint: disable=no-name-in-module import py import pytest @@ -12,6 +14,7 @@ from homeassistant.components.profiler import ( SERVICE_DUMP_LOG_OBJECTS, SERVICE_LOG_EVENT_LOOP_SCHEDULED, SERVICE_LOG_THREAD_FRAMES, + SERVICE_LRU_STATS, SERVICE_MEMORY, SERVICE_START, SERVICE_START_LOG_OBJECTS, @@ -228,3 +231,32 @@ async def test_log_scheduled( assert await hass.config_entries.async_unload(entry.entry_id) await hass.async_block_till_done() + + +async def test_lru_stats(hass: HomeAssistant, caplog: pytest.LogCaptureFixture) -> None: + """Test logging lru stats.""" + + entry = MockConfigEntry(domain=DOMAIN) + entry.add_to_hass(hass) + + assert await hass.config_entries.async_setup(entry.entry_id) + await hass.async_block_till_done() + + @lru_cache(maxsize=1) + def _dummy_test_lru_stats(): + return 1 + + class DomainData: + def __init__(self): + self._data = LRU(1) + + domain_data = DomainData() + assert hass.services.has_service(DOMAIN, SERVICE_LRU_STATS) + + await hass.services.async_call(DOMAIN, SERVICE_LRU_STATS, blocking=True) + + assert "DomainData" in caplog.text + assert "(0, 0)" in caplog.text + assert "_dummy_test_lru_stats" in caplog.text + assert "CacheInfo" in caplog.text + del domain_data