From a7a4875f529db523aff6e2d599b852897d0bb979 Mon Sep 17 00:00:00 2001
From: Pascal Vizeli <pvizeli@syshack.ch>
Date: Mon, 4 Jan 2021 13:10:39 +0100
Subject: [PATCH] Add more debug details to running timeouts (#43644)

Co-authored-by: Franck Nijhof <git@frenck.dev>
---
 homeassistant/bootstrap.py    |  7 +++--
 homeassistant/util/timeout.py | 12 +++++---
 tests/util/test_timeout.py    | 57 +++++++++++++++++++++++++++++++++++
 3 files changed, 70 insertions(+), 6 deletions(-)

diff --git a/homeassistant/bootstrap.py b/homeassistant/bootstrap.py
index bf16c4091f1..0f5bda7fbf2 100644
--- a/homeassistant/bootstrap.py
+++ b/homeassistant/bootstrap.py
@@ -381,7 +381,7 @@ def _get_domains(hass: core.HomeAssistant, config: Dict[str, Any]) -> Set[str]:
 
 
 async def _async_log_pending_setups(
-    domains: Set[str], setup_started: Dict[str, datetime]
+    hass: core.HomeAssistant, domains: Set[str], setup_started: Dict[str, datetime]
 ) -> None:
     """Periodic log of setups that are pending for longer than LOG_SLOW_STARTUP_INTERVAL."""
     while True:
@@ -393,6 +393,7 @@ async def _async_log_pending_setups(
                 "Waiting on integrations to complete setup: %s",
                 ", ".join(remaining),
             )
+        _LOGGER.debug("Running timeout Zones: %s", hass.timeout.zones)
 
 
 async def async_setup_multi_components(
@@ -406,7 +407,9 @@ async def async_setup_multi_components(
         domain: hass.async_create_task(async_setup_component(hass, domain, config))
         for domain in domains
     }
-    log_task = asyncio.create_task(_async_log_pending_setups(domains, setup_started))
+    log_task = asyncio.create_task(
+        _async_log_pending_setups(hass, domains, setup_started)
+    )
     await asyncio.wait(futures.values())
     log_task.cancel()
     errors = [domain for domain in domains if futures[domain].exception()]
diff --git a/homeassistant/util/timeout.py b/homeassistant/util/timeout.py
index 8c3d38a3700..d8fc3e48fe6 100644
--- a/homeassistant/util/timeout.py
+++ b/homeassistant/util/timeout.py
@@ -49,14 +49,14 @@ class _GlobalFreezeContext:
         self._loop.call_soon_threadsafe(self._enter)
         return self
 
-    def __exit__(
+    def __exit__(  # pylint: disable=useless-return
         self,
         exc_type: Type[BaseException],
         exc_val: BaseException,
         exc_tb: TracebackType,
     ) -> Optional[bool]:
         self._loop.call_soon_threadsafe(self._exit)
-        return True
+        return None
 
     def _enter(self) -> None:
         """Run freeze."""
@@ -117,14 +117,14 @@ class _ZoneFreezeContext:
         self._loop.call_soon_threadsafe(self._enter)
         return self
 
-    def __exit__(
+    def __exit__(  # pylint: disable=useless-return
         self,
         exc_type: Type[BaseException],
         exc_val: BaseException,
         exc_tb: TracebackType,
     ) -> Optional[bool]:
         self._loop.call_soon_threadsafe(self._exit)
-        return True
+        return None
 
     def _enter(self) -> None:
         """Run freeze."""
@@ -347,6 +347,10 @@ class _ZoneTimeoutManager:
         self._tasks: List[_ZoneTaskContext] = []
         self._freezes: List[_ZoneFreezeContext] = []
 
+    def __repr__(self) -> str:
+        """Representation of a zone."""
+        return f"<{self.name}: {len(self._tasks)} / {len(self._freezes)}>"
+
     @property
     def name(self) -> str:
         """Return Zone name."""
diff --git a/tests/util/test_timeout.py b/tests/util/test_timeout.py
index edd8f4107a4..39ec8d916bd 100644
--- a/tests/util/test_timeout.py
+++ b/tests/util/test_timeout.py
@@ -266,3 +266,60 @@ async def test_mix_zone_timeout_trigger_global_cool_down():
             pass
 
         await asyncio.sleep(0.2)
+
+
+async def test_simple_zone_timeout_freeze_without_timeout_cleanup(hass):
+    """Test a simple zone timeout freeze on a zone that does not have a timeout set."""
+    timeout = TimeoutManager()
+
+    async def background():
+        async with timeout.async_freeze("test"):
+            await asyncio.sleep(0.4)
+
+    async with timeout.async_timeout(0.1):
+        hass.async_create_task(background())
+        await asyncio.sleep(0.2)
+
+
+async def test_simple_zone_timeout_freeze_without_timeout_cleanup2(hass):
+    """Test a simple zone timeout freeze on a zone that does not have a timeout set."""
+    timeout = TimeoutManager()
+
+    async def background():
+        async with timeout.async_freeze("test"):
+            await asyncio.sleep(0.2)
+
+    with pytest.raises(asyncio.TimeoutError):
+        async with timeout.async_timeout(0.1):
+            hass.async_create_task(background())
+            await asyncio.sleep(0.3)
+
+
+async def test_simple_zone_timeout_freeze_without_timeout_exeption():
+    """Test a simple zone timeout freeze on a zone that does not have a timeout set."""
+    timeout = TimeoutManager()
+
+    with pytest.raises(asyncio.TimeoutError):
+        async with timeout.async_timeout(0.1):
+            try:
+                async with timeout.async_freeze("test"):
+                    raise RuntimeError()
+            except RuntimeError:
+                pass
+
+            await asyncio.sleep(0.4)
+
+
+async def test_simple_zone_timeout_zone_with_timeout_exeption():
+    """Test a simple zone timeout freeze on a zone that does not have a timeout set."""
+    timeout = TimeoutManager()
+
+    with pytest.raises(asyncio.TimeoutError):
+        async with timeout.async_timeout(0.1):
+            try:
+                async with timeout.async_timeout(0.3, "test"):
+                    raise RuntimeError()
+            except RuntimeError:
+                pass
+
+            await asyncio.sleep(0.3)