Avoid expensive inspect calls in config validators (#112085)

* Avoid expensive inspect calls in config validators

inspect has a performance problem https://github.com/python/cpython/issues/92041

We now avoid calling inspect unless we are going to log

* remove unused

* reduce

* get_integration_logger

homeassistant/helpers/config_validation.py

@@ -10,7 +10,6 @@ from datetime import (
     timedelta,
 )
 from enum import Enum, StrEnum
-import inspect
 import logging
 from numbers import Number
 import os
@@ -103,6 +102,7 @@ import homeassistant.util.dt as dt_util
 from homeassistant.util.yaml.objects import NodeStrClass
 
 from . import script_variables as script_variables_helper, template as template_helper
+from .frame import get_integration_logger
 
 TIME_PERIOD_ERROR = "offset {} should be format 'HH:MM', 'HH:MM:SS' or 'HH:MM:SS.F'"
 
@@ -890,24 +890,17 @@ def _deprecated_or_removed(
         - No warning if neither key nor replacement_key are provided
             - Adds replacement_key with default value in this case
     """
-    module = inspect.getmodule(inspect.stack(context=0)[2].frame)
-    if module is not None:
-        module_name = module.__name__
-    else:
-        # If Python is unable to access the sources files, the call stack frame
-        # will be missing information, so let's guard.
-        # https://github.com/home-assistant/core/issues/24982
-        module_name = __name__
-    if option_removed:
-        logger_func = logging.getLogger(module_name).error
-        option_status = "has been removed"
-    else:
-        logger_func = logging.getLogger(module_name).warning
-        option_status = "is deprecated"
 
     def validator(config: dict) -> dict:
         """Check if key is in config and log warning or error."""
         if key in config:
+            if option_removed:
+                level = logging.ERROR
+                option_status = "has been removed"
+            else:
+                level = logging.WARNING
+                option_status = "is deprecated"
+
             try:
                 near = (
                     f"near {config.__config_file__}"  # type: ignore[attr-defined]
@@ -928,7 +921,7 @@ def _deprecated_or_removed(
             if raise_if_present:
                 raise vol.Invalid(warning % arguments)
 
-            logger_func(warning, *arguments)
+            get_integration_logger(__name__).log(level, warning, *arguments)
             value = config[key]
             if replacement_key or option_removed:
                 config.pop(key)
@@ -1112,19 +1105,9 @@ def expand_condition_shorthand(value: Any | None) -> Any:
 def empty_config_schema(domain: str) -> Callable[[dict], dict]:
     """Return a config schema which logs if there are configuration parameters."""
 
-    module = inspect.getmodule(inspect.stack(context=0)[2].frame)
-    if module is not None:
-        module_name = module.__name__
-    else:
-        # If Python is unable to access the sources files, the call stack frame
-        # will be missing information, so let's guard.
-        # https://github.com/home-assistant/core/issues/24982
-        module_name = __name__
-    logger_func = logging.getLogger(module_name).error
-
     def validator(config: dict) -> dict:
         if domain in config and config[domain]:
-            logger_func(
+            get_integration_logger(__name__).error(
                 (
                     "The %s integration does not support any configuration parameters, "
                     "got %s. Please remove the configuration parameters from your "
@@ -1146,16 +1129,6 @@ def _no_yaml_config_schema(
 ) -> Callable[[dict], dict]:
     """Return a config schema which logs if attempted to setup from YAML."""
 
-    module = inspect.getmodule(inspect.stack(context=0)[2].frame)
-    if module is not None:
-        module_name = module.__name__
-    else:
-        # If Python is unable to access the sources files, the call stack frame
-        # will be missing information, so let's guard.
-        # https://github.com/home-assistant/core/issues/24982
-        module_name = __name__
-    logger_func = logging.getLogger(module_name).error
-
     def raise_issue() -> None:
         # pylint: disable-next=import-outside-toplevel
         from .issue_registry import IssueSeverity, async_create_issue
@@ -1176,7 +1149,7 @@ def _no_yaml_config_schema(
 
     def validator(config: dict) -> dict:
         if domain in config:
-            logger_func(
+            get_integration_logger(__name__).error(
                 (
                     "The %s integration does not support YAML setup, please remove it "
                     "from your configuration file"

homeassistant/helpers/frame.py

@@ -34,6 +34,26 @@ class IntegrationFrame:
     relative_filename: str
 
 
+def get_integration_logger(fallback_name: str) -> logging.Logger:
+    """Return a logger by checking the current integration frame.
+
+    If Python is unable to access the sources files, the call stack frame
+    will be missing information, so let's guard by requiring a fallback name.
+    https://github.com/home-assistant/core/issues/24982
+    """
+    try:
+        integration_frame = get_integration_frame()
+    except MissingIntegrationFrame:
+        return logging.getLogger(fallback_name)
+
+    if integration_frame.custom_integration:
+        logger_name = f"custom_components.{integration_frame.integration}"
+    else:
+        logger_name = f"homeassistant.components.{integration_frame.integration}"
+
+    return logging.getLogger(logger_name)
+
+
 def get_integration_frame(exclude_integrations: set | None = None) -> IntegrationFrame:
     """Return the frame, integration and integration path of the current stack frame."""
     found_frame = None

tests/helpers/test_config_validation.py

@@ -2,6 +2,7 @@
 from collections import OrderedDict
 from datetime import date, datetime, timedelta
 import enum
+import logging
 import os
 from socket import _GLOBAL_DEFAULT_TIMEOUT
 from unittest.mock import Mock, patch
@@ -986,7 +987,11 @@ def test_deprecated_with_default(caplog: pytest.LogCaptureFixture, schema) -> No
     deprecated_schema = vol.All(cv.deprecated("mars", default=False), schema)
 
     test_data = {"mars": True}
-    output = deprecated_schema(test_data.copy())
+    with patch(
+        "homeassistant.helpers.config_validation.get_integration_logger",
+        return_value=logging.getLogger(__name__),
+    ):
+        output = deprecated_schema(test_data.copy())
     assert len(caplog.records) == 1
     assert caplog.records[0].name == __name__
     assert (
@@ -1062,21 +1067,19 @@ def test_deprecated_with_replacement_key_and_default(
 
 
 def test_deprecated_cant_find_module() -> None:
-    """Test if the current module cannot be inspected."""
+    """Test if the current module cannot be found."""
-    with patch("inspect.getmodule", return_value=None):
+    # This used to raise.
-        # This used to raise.
+    cv.deprecated(
-        cv.deprecated(
+        "mars",
-            "mars",
+        replacement_key="jupiter",
-            replacement_key="jupiter",
+        default=False,
-            default=False,
+    )
-        )
 
-    with patch("inspect.getmodule", return_value=None):
+    # This used to raise.
-        # This used to raise.
+    cv.removed(
-        cv.removed(
+        "mars",
-            "mars",
+        default=False,
-            default=False,
+    )
-        )
 
 
 def test_deprecated_or_removed_logger_with_config_attributes(
@@ -1551,8 +1554,7 @@ def test_empty_schema(caplog: pytest.LogCaptureFixture) -> None:
 
 def test_empty_schema_cant_find_module() -> None:
     """Test if the current module cannot be inspected."""
-    with patch("inspect.getmodule", return_value=None):
+    cv.empty_config_schema("test_domain")({"test_domain": {"foo": "bar"}})
-        cv.empty_config_schema("test_domain")({"test_domain": {"foo": "bar"}})
 
 
 def test_config_entry_only_schema(
@@ -1582,10 +1584,7 @@ def test_config_entry_only_schema(
 
 def test_config_entry_only_schema_cant_find_module() -> None:
     """Test if the current module cannot be inspected."""
-    with patch("inspect.getmodule", return_value=None):
+    cv.config_entry_only_config_schema("test_domain")({"test_domain": {"foo": "bar"}})
-        cv.config_entry_only_config_schema("test_domain")(
-            {"test_domain": {"foo": "bar"}}
-        )
 
 
 def test_config_entry_only_schema_no_hass(

tests/helpers/test_frame.py

@@ -22,6 +22,14 @@ async def test_extract_frame_integration(
     )
 
 
+async def test_get_integration_logger(
+    caplog: pytest.LogCaptureFixture, mock_integration_frame: Mock
+) -> None:
+    """Test extracting the current frame to get the logger."""
+    logger = frame.get_integration_logger(__name__)
+    assert logger.name == "homeassistant.components.hue"
+
+
 async def test_extract_frame_resolve_module(
     hass: HomeAssistant, enable_custom_integrations
 ) -> None:
@@ -39,6 +47,17 @@ async def test_extract_frame_resolve_module(
     )
 
 
+async def test_get_integration_logger_resolve_module(
+    hass: HomeAssistant, enable_custom_integrations
+) -> None:
+    """Test getting the logger from integration context."""
+    from custom_components.test_integration_frame import call_get_integration_logger
+
+    logger = call_get_integration_logger(__name__)
+
+    assert logger.name == "custom_components.test_integration_frame"
+
+
 async def test_extract_frame_integration_with_excluded_integration(
     caplog: pytest.LogCaptureFixture,
 ) -> None:
@@ -102,6 +121,30 @@ async def test_extract_frame_no_integration(caplog: pytest.LogCaptureFixture) ->
         frame.get_integration_frame()
 
 
+async def test_get_integration_logger_no_integration(
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Test getting fallback logger without integration context."""
+    with patch(
+        "homeassistant.helpers.frame.extract_stack",
+        return_value=[
+            Mock(
+                filename="/home/paulus/homeassistant/core.py",
+                lineno="23",
+                line="do_something()",
+            ),
+            Mock(
+                filename="/home/paulus/aiohue/lights.py",
+                lineno="2",
+                line="something()",
+            ),
+        ],
+    ):
+        logger = frame.get_integration_logger(__name__)
+
+    assert logger.name == __name__
+
+
 @patch.object(frame, "_REPORTED_INTEGRATIONS", set())
 async def test_prevent_flooding(
     hass: HomeAssistant, caplog: pytest.LogCaptureFixture, mock_integration_frame: Mock

tests/testing_config/custom_components/test_integration_frame/__init__.py

@@ -1,8 +1,15 @@
 """An integration which calls helpers.frame.get_integration_frame."""
 
+import logging
+
 from homeassistant.helpers import frame
 
 
+def call_get_integration_logger(fallback_name: str) -> logging.Logger:
+    """Call get_integration_logger."""
+    return frame.get_integration_logger(fallback_name)
+
+
 def call_get_integration_frame() -> frame.IntegrationFrame:
     """Call get_integration_frame."""
     return frame.get_integration_frame()