Log ffmpeg errors for homekit cameras (#46545)

homeassistant/components/homekit/type_cameras.py

@@ -1,8 +1,9 @@
 """Class to hold all camera accessories."""
+import asyncio
 from datetime import timedelta
 import logging
 
-from haffmpeg.core import HAFFmpeg
+from haffmpeg.core import FFMPEG_STDERR, HAFFmpeg
 from pyhap.camera import (
     VIDEO_CODEC_PARAM_LEVEL_TYPES,
     VIDEO_CODEC_PARAM_PROFILE_ID_TYPES,
@@ -114,6 +115,7 @@ RESOLUTIONS = [
 VIDEO_PROFILE_NAMES = ["baseline", "main", "high"]
 
 FFMPEG_WATCH_INTERVAL = timedelta(seconds=5)
+FFMPEG_LOGGER = "ffmpeg_logger"
 FFMPEG_WATCHER = "ffmpeg_watcher"
 FFMPEG_PID = "ffmpeg_pid"
 SESSION_ID = "session_id"
@@ -371,7 +373,12 @@ class Camera(HomeAccessory, PyhapCamera):
         _LOGGER.debug("FFmpeg output settings: %s", output)
         stream = HAFFmpeg(self._ffmpeg.binary)
         opened = await stream.open(
-            cmd=[], input_source=input_source, output=output, stdout_pipe=False
+            cmd=[],
+            input_source=input_source,
+            output=output,
+            extra_cmd="-hide_banner -nostats",
+            stderr_pipe=True,
+            stdout_pipe=False,
         )
         if not opened:
             _LOGGER.error("Failed to open ffmpeg stream")
@@ -386,9 +393,14 @@ class Camera(HomeAccessory, PyhapCamera):
         session_info["stream"] = stream
         session_info[FFMPEG_PID] = stream.process.pid
 
+        stderr_reader = await stream.get_reader(source=FFMPEG_STDERR)
+
         async def watch_session(_):
             await self._async_ffmpeg_watch(session_info["id"])
 
+        session_info[FFMPEG_LOGGER] = asyncio.create_task(
+            self._async_log_stderr_stream(stderr_reader)
+        )
         session_info[FFMPEG_WATCHER] = async_track_time_interval(
             self.hass,
             watch_session,
@@ -397,6 +409,16 @@ class Camera(HomeAccessory, PyhapCamera):
 
         return await self._async_ffmpeg_watch(session_info["id"])
 
+    async def _async_log_stderr_stream(self, stderr_reader):
+        """Log output from ffmpeg."""
+        _LOGGER.debug("%s: ffmpeg: started", self.display_name)
+        while True:
+            line = await stderr_reader.readline()
+            if line == b"":
+                return
+
+            _LOGGER.debug("%s: ffmpeg: %s", self.display_name, line.rstrip())
+
     async def _async_ffmpeg_watch(self, session_id):
         """Check to make sure ffmpeg is still running and cleanup if not."""
         ffmpeg_pid = self.sessions[session_id][FFMPEG_PID]
@@ -414,6 +436,7 @@ class Camera(HomeAccessory, PyhapCamera):
         if FFMPEG_WATCHER not in self.sessions[session_id]:
             return
         self.sessions[session_id].pop(FFMPEG_WATCHER)()
+        self.sessions[session_id].pop(FFMPEG_LOGGER).cancel()
 
     async def stop_stream(self, session_info):
         """Stop the stream for the given ``session_id``."""

tests/components/homekit/test_type_cameras.py

@@ -99,6 +99,7 @@ def _get_exits_after_startup_mock_ffmpeg():
     ffmpeg.open = AsyncMock(return_value=True)
     ffmpeg.close = AsyncMock(return_value=True)
     ffmpeg.kill = AsyncMock(return_value=True)
+    ffmpeg.get_reader = AsyncMock()
     return ffmpeg
 
 
@@ -108,6 +109,7 @@ def _get_working_mock_ffmpeg():
     ffmpeg.open = AsyncMock(return_value=True)
     ffmpeg.close = AsyncMock(return_value=True)
     ffmpeg.kill = AsyncMock(return_value=True)
+    ffmpeg.get_reader = AsyncMock()
     return ffmpeg
 
 
@@ -118,6 +120,7 @@ def _get_failing_mock_ffmpeg():
     ffmpeg.open = AsyncMock(return_value=False)
     ffmpeg.close = AsyncMock(side_effect=OSError)
     ffmpeg.kill = AsyncMock(side_effect=OSError)
+    ffmpeg.get_reader = AsyncMock()
     return ffmpeg
 
 
@@ -189,6 +192,8 @@ async def test_camera_stream_source_configured(hass, run_driver, events):
         input_source="-i /dev/null",
         output=expected_output.format(**session_info),
         stdout_pipe=False,
+        extra_cmd="-hide_banner -nostats",
+        stderr_pipe=True,
     )
 
     await _async_setup_endpoints(hass, acc)
@@ -472,6 +477,8 @@ async def test_camera_stream_source_configured_and_copy_codec(hass, run_driver,
         input_source="-i /dev/null",
         output=expected_output.format(**session_info),
         stdout_pipe=False,
+        extra_cmd="-hide_banner -nostats",
+        stderr_pipe=True,
     )
 
 
@@ -542,6 +549,8 @@ async def test_camera_streaming_fails_after_starting_ffmpeg(hass, run_driver, ev
         input_source="-i /dev/null",
         output=expected_output.format(**session_info),
         stdout_pipe=False,
+        extra_cmd="-hide_banner -nostats",
+        stderr_pipe=True,
     )