Warn ontime.sleep in event loop (#63766)

Co-authored-by: Martin Hjelmare <marhje52@gmail.com>

homeassistant/block_async_io.py

@@ -1,14 +1,18 @@
-"""Block I/O being done in asyncio."""
+"""Block blocking calls being done in asyncio."""
 from http.client import HTTPConnection
+import time
 
 from .util.async_ import protect_loop
 
 
 def enable() -> None:
-    """Enable the detection of I/O in the event loop."""
+    """Enable the detection of blocking calls in the event loop."""
     # Prevent urllib3 and requests doing I/O in event loop
     HTTPConnection.putrequest = protect_loop(HTTPConnection.putrequest)  # type: ignore
 
+    # Prevent sleeping in event loop. Non-strict since 2022.02
+    time.sleep = protect_loop(time.sleep, strict=False)
+
     # Currently disabled. pytz doing I/O when getting timezone.
     # Prevent files being opened inside the event loop
     # builtins.open = protect_loop(builtins.open)

homeassistant/util/async_.py

@@ -88,8 +88,8 @@ def run_callback_threadsafe(
     return future
 
 
-def check_loop() -> None:
+def check_loop(strict: bool = True) -> None:
-    """Warn if called inside the event loop."""
+    """Warn if called inside the event loop. Raise if `strict` is True."""
     try:
         get_running_loop()
         in_loop = True
@@ -116,7 +116,8 @@ def check_loop() -> None:
     # Did not source from integration? Hard error.
     if found_frame is None:
         raise RuntimeError(
-            "Detected I/O inside the event loop. This is causing stability issues. Please report issue"
+            "Detected blocking call inside the event loop. "
+            "This is causing stability issues. Please report issue"
         )
 
     start = index + len(path)
@@ -130,25 +131,28 @@ def check_loop() -> None:
         extra = ""
 
     _LOGGER.warning(
-        "Detected I/O inside the event loop. This is causing stability issues. Please report issue%s for %s doing I/O at %s, line %s: %s",
+        "Detected blocking call inside the event loop. This is causing stability issues. "
+        "Please report issue%s for %s doing blocking calls at %s, line %s: %s",
         extra,
         integration,
         found_frame.filename[index:],
         found_frame.lineno,
         found_frame.line.strip(),
     )
-    raise RuntimeError(
+    if strict:
-        f"I/O must be done in the executor; Use `await hass.async_add_executor_job()` "
+        raise RuntimeError(
-        f"at {found_frame.filename[index:]}, line {found_frame.lineno}: {found_frame.line.strip()}"
+            "Blocking calls must be done in the executor or a separate thread; "
-    )
+            "Use `await hass.async_add_executor_job()` "
+            f"at {found_frame.filename[index:]}, line {found_frame.lineno}: {found_frame.line.strip()}"
+        )
 
 
-def protect_loop(func: Callable) -> Callable:
+def protect_loop(func: Callable, strict: bool = True) -> Callable:
     """Protect function from running in event loop."""
 
     @functools.wraps(func)
     def protected_loop_func(*args, **kwargs):  # type: ignore
-        check_loop()
+        check_loop(strict=strict)
         return func(*args, **kwargs)
 
     return protected_loop_func

tests/util/test_async.py

@@ -77,7 +77,7 @@ async def test_check_loop_async():
 
 
 async def test_check_loop_async_integration(caplog):
-    """Test check_loop detects when called from event loop from integration context."""
+    """Test check_loop detects and raises when called from event loop from integration context."""
     with pytest.raises(RuntimeError), patch(
         "homeassistant.util.async_.extract_stack",
         return_value=[
@@ -100,7 +100,40 @@ async def test_check_loop_async_integration(caplog):
     ):
         hasync.check_loop()
     assert (
-        "Detected I/O inside the event loop. This is causing stability issues. Please report issue for hue doing I/O at homeassistant/components/hue/light.py, line 23: self.light.is_on"
+        "Detected blocking call inside the event loop. This is causing stability issues. "
+        "Please report issue for hue doing blocking calls at "
+        "homeassistant/components/hue/light.py, line 23: self.light.is_on"
+        in caplog.text
+    )
+
+
+async def test_check_loop_async_integration_non_strict(caplog):
+    """Test check_loop detects when called from event loop from integration context."""
+    with patch(
+        "homeassistant.util.async_.extract_stack",
+        return_value=[
+            Mock(
+                filename="/home/paulus/homeassistant/core.py",
+                lineno="23",
+                line="do_something()",
+            ),
+            Mock(
+                filename="/home/paulus/homeassistant/components/hue/light.py",
+                lineno="23",
+                line="self.light.is_on",
+            ),
+            Mock(
+                filename="/home/paulus/aiohue/lights.py",
+                lineno="2",
+                line="something()",
+            ),
+        ],
+    ):
+        hasync.check_loop(strict=False)
+    assert (
+        "Detected blocking call inside the event loop. This is causing stability issues. "
+        "Please report issue for hue doing blocking calls at "
+        "homeassistant/components/hue/light.py, line 23: self.light.is_on"
         in caplog.text
     )
 
@@ -129,24 +162,25 @@ async def test_check_loop_async_custom(caplog):
     ):
         hasync.check_loop()
     assert (
-        "Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for hue doing I/O at custom_components/hue/light.py, line 23: self.light.is_on"
+        "Detected blocking call inside the event loop. This is causing stability issues. "
-        in caplog.text
+        "Please report issue to the custom component author for hue doing blocking calls "
+        "at custom_components/hue/light.py, line 23: self.light.is_on" in caplog.text
     )
 
 
 def test_check_loop_sync(caplog):
     """Test check_loop does nothing when called from thread."""
     hasync.check_loop()
-    assert "Detected I/O inside the event loop" not in caplog.text
+    assert "Detected blocking call inside the event loop" not in caplog.text
 
 
 def test_protect_loop_sync():
     """Test protect_loop calls check_loop."""
-    calls = []
+    func = Mock()
-    with patch("homeassistant.util.async_.check_loop") as mock_loop:
+    with patch("homeassistant.util.async_.check_loop") as mock_check_loop:
-        hasync.protect_loop(calls.append)(1)
+        hasync.protect_loop(func)(1, test=2)
-    assert len(mock_loop.mock_calls) == 1
+    mock_check_loop.assert_called_once_with(strict=True)
-    assert calls == [1]
+    func.assert_called_once_with(1, test=2)
 
 
 async def test_gather_with_concurrency():