From 13416825b188ff60e6c0d9162e138579233a43cf Mon Sep 17 00:00:00 2001 From: Robert Resch Date: Tue, 29 Oct 2024 11:28:40 +0100 Subject: [PATCH] Go2rtc server start is waiting until we got the api listen stdout line (#129391) --- homeassistant/components/go2rtc/server.py | 37 ++++++--- tests/components/go2rtc/conftest.py | 40 ++++++--- tests/components/go2rtc/test_server.py | 99 ++++++++++++++--------- 3 files changed, 121 insertions(+), 55 deletions(-) diff --git a/homeassistant/components/go2rtc/server.py b/homeassistant/components/go2rtc/server.py index d2b9d49e992..3846284de92 100644 --- a/homeassistant/components/go2rtc/server.py +++ b/homeassistant/components/go2rtc/server.py @@ -5,9 +5,12 @@ import logging from tempfile import NamedTemporaryFile from homeassistant.core import HomeAssistant +from homeassistant.exceptions import HomeAssistantError _LOGGER = logging.getLogger(__name__) _TERMINATE_TIMEOUT = 5 +_SETUP_TIMEOUT = 30 +_SUCCESSFUL_BOOT_MESSAGE = "INF [api] listen addr=127.0.0.1:1984" # Default configuration for HA # - Api is listening only on localhost @@ -34,14 +37,6 @@ def _create_temp_file() -> str: return file.name -async def _log_output(process: asyncio.subprocess.Process) -> None: - """Log the output of the process.""" - assert process.stdout is not None - - async for line in process.stdout: - _LOGGER.debug(line[:-1].decode().strip()) - - class Server: """Go2rtc server.""" @@ -50,12 +45,15 @@ class Server: self._hass = hass self._binary = binary self._process: asyncio.subprocess.Process | None = None + self._startup_complete = asyncio.Event() async def start(self) -> None: """Start the server.""" _LOGGER.debug("Starting go2rtc server") config_file = await self._hass.async_add_executor_job(_create_temp_file) + self._startup_complete.clear() + self._process = await asyncio.create_subprocess_exec( self._binary, "-c", @@ -66,9 +64,30 @@ class Server: ) self._hass.async_create_background_task( - _log_output(self._process), "Go2rtc log output" + self._log_output(self._process), "Go2rtc log output" ) + try: + async with asyncio.timeout(_SETUP_TIMEOUT): + await self._startup_complete.wait() + except TimeoutError as err: + msg = "Go2rtc server didn't start correctly" + _LOGGER.exception(msg) + await self.stop() + raise HomeAssistantError("Go2rtc server didn't start correctly") from err + + async def _log_output(self, process: asyncio.subprocess.Process) -> None: + """Log the output of the process.""" + assert process.stdout is not None + + async for line in process.stdout: + msg = line[:-1].decode().strip() + _LOGGER.debug(msg) + if not self._startup_complete.is_set() and msg.endswith( + _SUCCESSFUL_BOOT_MESSAGE + ): + self._startup_complete.set() + async def stop(self) -> None: """Stop the server.""" if self._process: diff --git a/tests/components/go2rtc/conftest.py b/tests/components/go2rtc/conftest.py index 2dcca40cc87..b299c28c557 100644 --- a/tests/components/go2rtc/conftest.py +++ b/tests/components/go2rtc/conftest.py @@ -35,17 +35,39 @@ def ws_client() -> Generator[Mock]: @pytest.fixture -def server_start() -> Generator[AsyncMock]: - """Mock start of a go2rtc server.""" - with ( - patch(f"{GO2RTC_PATH}.server.asyncio.create_subprocess_exec") as mock_subproc, - patch( - f"{GO2RTC_PATH}.server.Server.start", wraps=Server.start, autospec=True - ) as mock_server_start, - ): +def server_stdout() -> list[str]: + """Server stdout lines.""" + return [ + "09:00:03.466 INF go2rtc platform=linux/amd64 revision=780f378 version=1.9.5", + "09:00:03.466 INF config path=/tmp/go2rtc.yaml", + "09:00:03.467 INF [rtsp] listen addr=:8554", + "09:00:03.467 INF [api] listen addr=127.0.0.1:1984", + "09:00:03.467 INF [webrtc] listen addr=:8555/tcp", + ] + + +@pytest.fixture +def mock_create_subprocess(server_stdout: list[str]) -> Generator[AsyncMock]: + """Mock create_subprocess_exec.""" + with patch(f"{GO2RTC_PATH}.server.asyncio.create_subprocess_exec") as mock_subproc: subproc = AsyncMock() subproc.terminate = Mock() + subproc.kill = Mock() + subproc.returncode = None + # Simulate process output + subproc.stdout.__aiter__.return_value = iter( + [f"{entry}\n".encode() for entry in server_stdout] + ) mock_subproc.return_value = subproc + yield mock_subproc + + +@pytest.fixture +def server_start(mock_create_subprocess: AsyncMock) -> Generator[AsyncMock]: + """Mock start of a go2rtc server.""" + with patch( + f"{GO2RTC_PATH}.server.Server.start", wraps=Server.start, autospec=True + ) as mock_server_start: yield mock_server_start @@ -61,7 +83,7 @@ def server_stop() -> Generator[AsyncMock]: @pytest.fixture -def server(server_start, server_stop) -> Generator[AsyncMock]: +def server(server_start: AsyncMock, server_stop: AsyncMock) -> Generator[AsyncMock]: """Mock a go2rtc server.""" with patch(f"{GO2RTC_PATH}.Server", wraps=Server) as mock_server: yield mock_server diff --git a/tests/components/go2rtc/test_server.py b/tests/components/go2rtc/test_server.py index 5517062b29a..99d4f2f3237 100644 --- a/tests/components/go2rtc/test_server.py +++ b/tests/components/go2rtc/test_server.py @@ -4,12 +4,13 @@ import asyncio from collections.abc import Generator import logging import subprocess -from unittest.mock import MagicMock, Mock, patch +from unittest.mock import AsyncMock, MagicMock, Mock, patch import pytest from homeassistant.components.go2rtc.server import Server from homeassistant.core import HomeAssistant +from homeassistant.exceptions import HomeAssistantError TEST_BINARY = "/bin/go2rtc" @@ -31,37 +32,18 @@ def mock_tempfile() -> Generator[Mock]: yield file -@pytest.fixture -def mock_process() -> Generator[MagicMock]: - """Fixture to mock subprocess.Popen.""" - with patch( - "homeassistant.components.go2rtc.server.asyncio.create_subprocess_exec" - ) as mock_popen: - mock_popen.return_value.terminate = MagicMock() - mock_popen.return_value.kill = MagicMock() - mock_popen.return_value.returncode = None - yield mock_popen - - async def test_server_run_success( - mock_process: MagicMock, + mock_create_subprocess: AsyncMock, + server_stdout: list[str], server: Server, caplog: pytest.LogCaptureFixture, mock_tempfile: Mock, ) -> None: """Test that the server runs successfully.""" - # Simulate process output - mock_process.return_value.stdout.__aiter__.return_value = iter( - [ - b"log line 1\n", - b"log line 2\n", - ] - ) - await server.start() # Check that Popen was called with the right arguments - mock_process.assert_called_once_with( + mock_create_subprocess.assert_called_once_with( TEST_BINARY, "-c", "test.yaml", @@ -83,7 +65,7 @@ webrtc: """) # Check that server read the log lines - for entry in ("log line 1", "log line 2"): + for entry in server_stdout: assert ( "homeassistant.components.go2rtc.server", logging.DEBUG, @@ -91,31 +73,74 @@ webrtc: ) in caplog.record_tuples await server.stop() - mock_process.return_value.terminate.assert_called_once() + mock_create_subprocess.return_value.terminate.assert_called_once() @pytest.mark.usefixtures("mock_tempfile") -async def test_server_run_process_timeout( - mock_process: MagicMock, server: Server +async def test_server_timeout_on_stop( + mock_create_subprocess: MagicMock, server: Server ) -> None: """Test server run where the process takes too long to terminate.""" - mock_process.return_value.stdout.__aiter__.return_value = iter( - [ - b"log line 1\n", - ] - ) + # Start server thread + await server.start() async def sleep() -> None: await asyncio.sleep(1) # Simulate timeout - mock_process.return_value.wait.side_effect = sleep + mock_create_subprocess.return_value.wait.side_effect = sleep with patch("homeassistant.components.go2rtc.server._TERMINATE_TIMEOUT", new=0.1): - # Start server thread - await server.start() await server.stop() # Ensure terminate and kill were called due to timeout - mock_process.return_value.terminate.assert_called_once() - mock_process.return_value.kill.assert_called_once() + mock_create_subprocess.return_value.terminate.assert_called_once() + mock_create_subprocess.return_value.kill.assert_called_once() + + +@pytest.mark.parametrize( + "server_stdout", + [ + [ + "09:00:03.466 INF go2rtc platform=linux/amd64 revision=780f378 version=1.9.5", + "09:00:03.466 INF config path=/tmp/go2rtc.yaml", + ] + ], +) +@pytest.mark.usefixtures("mock_tempfile") +async def test_server_failed_to_start( + mock_create_subprocess: MagicMock, + server_stdout: list[str], + server: Server, + caplog: pytest.LogCaptureFixture, +) -> None: + """Test server, where an exception is raised if the expected log entry was not received until the timeout.""" + with ( + patch("homeassistant.components.go2rtc.server._SETUP_TIMEOUT", new=0.1), + pytest.raises(HomeAssistantError, match="Go2rtc server didn't start correctly"), + ): + await server.start() + + # Verify go2rtc binary stdout was logged + for entry in server_stdout: + assert ( + "homeassistant.components.go2rtc.server", + logging.DEBUG, + entry, + ) in caplog.record_tuples + + assert ( + "homeassistant.components.go2rtc.server", + logging.ERROR, + "Go2rtc server didn't start correctly", + ) in caplog.record_tuples + + # Check that Popen was called with the right arguments + mock_create_subprocess.assert_called_once_with( + TEST_BINARY, + "-c", + "test.yaml", + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, + close_fds=False, + )