From 8f942050143e2acdd7e73a2445835bc7317c9eb6 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sun, 2 Jun 2024 05:36:25 -0500 Subject: [PATCH] Include a traceback for non-strict event loop blocking detection (#118620) --- homeassistant/helpers/frame.py | 8 ++++---- homeassistant/util/loop.py | 13 ++++++++----- tests/common.py | 2 ++ tests/helpers/test_frame.py | 6 +++--- tests/test_loader.py | 4 ++-- tests/util/test_loop.py | 11 +++++++++++ 6 files changed, 30 insertions(+), 14 deletions(-) diff --git a/homeassistant/helpers/frame.py b/homeassistant/helpers/frame.py index 3046b718489..e8ba6ba0c07 100644 --- a/homeassistant/helpers/frame.py +++ b/homeassistant/helpers/frame.py @@ -31,17 +31,17 @@ class IntegrationFrame: integration: str module: str | None relative_filename: str - _frame: FrameType + frame: FrameType @cached_property def line_number(self) -> int: """Return the line number of the frame.""" - return self._frame.f_lineno + return self.frame.f_lineno @cached_property def filename(self) -> str: """Return the filename of the frame.""" - return self._frame.f_code.co_filename + return self.frame.f_code.co_filename @cached_property def line(self) -> str: @@ -119,7 +119,7 @@ def get_integration_frame(exclude_integrations: set | None = None) -> Integratio integration=integration, module=found_module, relative_filename=found_frame.f_code.co_filename[index:], - _frame=found_frame, + frame=found_frame, ) diff --git a/homeassistant/util/loop.py b/homeassistant/util/loop.py index cba9f7c3900..64be00cfe35 100644 --- a/homeassistant/util/loop.py +++ b/homeassistant/util/loop.py @@ -7,6 +7,7 @@ import functools import linecache import logging import threading +import traceback from typing import Any from homeassistant.core import async_get_hass_or_none @@ -54,12 +55,14 @@ def raise_for_blocking_call( if not strict_core: _LOGGER.warning( "Detected blocking call to %s with args %s in %s, " - "line %s: %s inside the event loop", + "line %s: %s inside the event loop\n" + "Traceback (most recent call last):\n%s", func.__name__, mapped_args.get("args"), offender_filename, offender_lineno, offender_line, + "".join(traceback.format_stack(f=offender_frame)), ) return @@ -79,10 +82,9 @@ def raise_for_blocking_call( ) _LOGGER.warning( - ( - "Detected blocking call to %s inside the event loop by %sintegration '%s' " - "at %s, line %s: %s (offender: %s, line %s: %s), please %s" - ), + "Detected blocking call to %s inside the event loop by %sintegration '%s' " + "at %s, line %s: %s (offender: %s, line %s: %s), please %s\n" + "Traceback (most recent call last):\n%s", func.__name__, "custom " if integration_frame.custom_integration else "", integration_frame.integration, @@ -93,6 +95,7 @@ def raise_for_blocking_call( offender_lineno, offender_line, report_issue, + "".join(traceback.format_stack(f=integration_frame.frame)), ) if strict: diff --git a/tests/common.py b/tests/common.py index 6e7cf1b21f3..897a28fbffd 100644 --- a/tests/common.py +++ b/tests/common.py @@ -1689,8 +1689,10 @@ def help_test_all(module: ModuleType) -> None: def extract_stack_to_frame(extract_stack: list[Mock]) -> FrameType: """Convert an extract stack to a frame list.""" stack = list(extract_stack) + _globals = globals() for frame in stack: frame.f_back = None + frame.f_globals = _globals frame.f_code.co_filename = frame.filename frame.f_lineno = int(frame.lineno) diff --git a/tests/helpers/test_frame.py b/tests/helpers/test_frame.py index 904bed965c8..e6251963d36 100644 --- a/tests/helpers/test_frame.py +++ b/tests/helpers/test_frame.py @@ -17,7 +17,7 @@ async def test_extract_frame_integration( integration_frame = frame.get_integration_frame() assert integration_frame == frame.IntegrationFrame( custom_integration=False, - _frame=mock_integration_frame, + frame=mock_integration_frame, integration="hue", module=None, relative_filename="homeassistant/components/hue/light.py", @@ -42,7 +42,7 @@ async def test_extract_frame_resolve_module( assert integration_frame == frame.IntegrationFrame( custom_integration=True, - _frame=ANY, + frame=ANY, integration="test_integration_frame", module="custom_components.test_integration_frame", relative_filename="custom_components/test_integration_frame/__init__.py", @@ -98,7 +98,7 @@ async def test_extract_frame_integration_with_excluded_integration( assert integration_frame == frame.IntegrationFrame( custom_integration=False, - _frame=correct_frame, + frame=correct_frame, integration="mdns", module=None, relative_filename="homeassistant/components/mdns/light.py", diff --git a/tests/test_loader.py b/tests/test_loader.py index b2ca8cbd397..fa4a3a14cef 100644 --- a/tests/test_loader.py +++ b/tests/test_loader.py @@ -1271,7 +1271,7 @@ async def test_hass_components_use_reported( ) integration_frame = frame.IntegrationFrame( custom_integration=True, - _frame=mock_integration_frame, + frame=mock_integration_frame, integration="test_integration_frame", module="custom_components.test_integration_frame", relative_filename="custom_components/test_integration_frame/__init__.py", @@ -1969,7 +1969,7 @@ async def test_hass_helpers_use_reported( """Test that use of hass.components is reported.""" integration_frame = frame.IntegrationFrame( custom_integration=True, - _frame=mock_integration_frame, + frame=mock_integration_frame, integration="test_integration_frame", module="custom_components.test_integration_frame", relative_filename="custom_components/test_integration_frame/__init__.py", diff --git a/tests/util/test_loop.py b/tests/util/test_loop.py index c3cfb3d0f06..506614d7631 100644 --- a/tests/util/test_loop.py +++ b/tests/util/test_loop.py @@ -27,6 +27,7 @@ async def test_raise_for_blocking_call_async_non_strict_core( """Test non_strict_core raise_for_blocking_call detects from event loop without integration context.""" haloop.raise_for_blocking_call(banned_function, strict_core=False) assert "Detected blocking call to banned_function" in caplog.text + assert "Traceback (most recent call last)" in caplog.text async def test_raise_for_blocking_call_async_integration( @@ -130,6 +131,11 @@ async def test_raise_for_blocking_call_async_integration_non_strict( "please create a bug report at https://github.com/home-assistant/core/issues?" "q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+hue%22" in caplog.text ) + assert "Traceback (most recent call last)" in caplog.text + assert ( + 'File "/home/paulus/homeassistant/components/hue/light.py", line 23' + in caplog.text + ) async def test_raise_for_blocking_call_async_custom( @@ -182,6 +188,11 @@ async def test_raise_for_blocking_call_async_custom( "please create a bug report at https://github.com/home-assistant/core/issues?" "q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+hue%22" ) in caplog.text + assert "Traceback (most recent call last)" in caplog.text + assert ( + 'File "/home/paulus/config/custom_components/hue/light.py", line 23' + in caplog.text + ) async def test_raise_for_blocking_call_sync(