Add a camera specific logger to help diagnose stream errors (#61647)

* Add a camera specific logger to help diagnose stream errors

Add a camera specific logger to help users associate stream errors with a particular camera.
Issue #54659

* Apply code review feedback

* Update package name based on manual testing
This commit is contained in:
Allen Porter 2021-12-19 19:42:37 -08:00 committed by GitHub
parent 1f066a7b6f
commit 6ae7b928ea
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 40 additions and 15 deletions

View File

@ -462,7 +462,12 @@ class Camera(Entity):
source = await self.stream_source() source = await self.stream_source()
if not source: if not source:
return None return None
self.stream = create_stream(self.hass, source, options=self.stream_options) self.stream = create_stream(
self.hass,
source,
options=self.stream_options,
stream_label=self.entity_id,
)
self.stream.set_update_callback(self.async_write_ha_state) self.stream.set_update_callback(self.async_write_ha_state)
return self.stream return self.stream

View File

@ -69,12 +69,17 @@ def redact_credentials(data: str) -> str:
def create_stream( def create_stream(
hass: HomeAssistant, stream_source: str, options: dict[str, str] hass: HomeAssistant,
stream_source: str,
options: dict[str, str],
stream_label: str | None = None,
) -> Stream: ) -> Stream:
"""Create a stream with the specified identfier based on the source url. """Create a stream with the specified identfier based on the source url.
The stream_source is typically an rtsp url and options are passed into The stream_source is typically an rtsp url (though any url accepted by ffmpeg is fine) and
pyav / ffmpeg as options. options are passed into pyav / ffmpeg as options.
The stream_label is a string used as an additional message in logging.
""" """
if DOMAIN not in hass.config.components: if DOMAIN not in hass.config.components:
raise HomeAssistantError("Stream integration is not set up.") raise HomeAssistantError("Stream integration is not set up.")
@ -87,7 +92,7 @@ def create_stream(
**options, **options,
} }
stream = Stream(hass, stream_source, options=options) stream = Stream(hass, stream_source, options=options, stream_label=stream_label)
hass.data[DOMAIN][ATTR_STREAMS].append(stream) hass.data[DOMAIN][ATTR_STREAMS].append(stream)
return stream return stream
@ -192,12 +197,17 @@ class Stream:
"""Represents a single stream.""" """Represents a single stream."""
def __init__( def __init__(
self, hass: HomeAssistant, source: str, options: dict[str, str] self,
hass: HomeAssistant,
source: str,
options: dict[str, str],
stream_label: str | None = None,
) -> None: ) -> None:
"""Initialize a stream.""" """Initialize a stream."""
self.hass = hass self.hass = hass
self.source = source self.source = source
self.options = options self.options = options
self._stream_label = stream_label
self.keepalive = False self.keepalive = False
self.access_token: str | None = None self.access_token: str | None = None
self._thread: threading.Thread | None = None self._thread: threading.Thread | None = None
@ -206,6 +216,11 @@ class Stream:
self._fast_restart_once = False self._fast_restart_once = False
self._available: bool = True self._available: bool = True
self._update_callback: Callable[[], None] | None = None self._update_callback: Callable[[], None] | None = None
self._logger = (
logging.getLogger(f"{__package__}.stream.{stream_label}")
if stream_label
else _LOGGER
)
def endpoint_url(self, fmt: str) -> str: def endpoint_url(self, fmt: str) -> str:
"""Start the stream and returns a url for the output format.""" """Start the stream and returns a url for the output format."""
@ -285,11 +300,13 @@ class Stream:
target=self._run_worker, target=self._run_worker,
) )
self._thread.start() self._thread.start()
_LOGGER.info("Started stream: %s", redact_credentials(str(self.source))) self._logger.info(
"Started stream: %s", redact_credentials(str(self.source))
)
def update_source(self, new_source: str) -> None: def update_source(self, new_source: str) -> None:
"""Restart the stream with a new stream source.""" """Restart the stream with a new stream source."""
_LOGGER.debug("Updating stream source %s", new_source) self._logger.debug("Updating stream source %s", new_source)
self.source = new_source self.source = new_source
self._fast_restart_once = True self._fast_restart_once = True
self._thread_quit.set() self._thread_quit.set()
@ -313,7 +330,8 @@ class Stream:
self._thread_quit, self._thread_quit,
) )
except StreamWorkerError as err: except StreamWorkerError as err:
_LOGGER.error("Error from stream worker: %s", str(err)) self._logger.error("Error from stream worker: %s", str(err))
self._available = False
stream_state.discontinuity() stream_state.discontinuity()
if not self.keepalive or self._thread_quit.is_set(): if not self.keepalive or self._thread_quit.is_set():
@ -332,7 +350,7 @@ class Stream:
if time.time() - start_time > STREAM_RESTART_RESET_TIME: if time.time() - start_time > STREAM_RESTART_RESET_TIME:
wait_timeout = 0 wait_timeout = 0
wait_timeout += STREAM_RESTART_INCREMENT wait_timeout += STREAM_RESTART_INCREMENT
_LOGGER.debug( self._logger.debug(
"Restarting stream worker in %d seconds: %s", "Restarting stream worker in %d seconds: %s",
wait_timeout, wait_timeout,
self.source, self.source,
@ -363,7 +381,9 @@ class Stream:
self._thread_quit.set() self._thread_quit.set()
self._thread.join() self._thread.join()
self._thread = None self._thread = None
_LOGGER.info("Stopped stream: %s", redact_credentials(str(self.source))) self._logger.info(
"Stopped stream: %s", redact_credentials(str(self.source))
)
async def async_record( async def async_record(
self, video_path: str, duration: int = 30, lookback: int = 5 self, video_path: str, duration: int = 30, lookback: int = 5
@ -390,7 +410,7 @@ class Stream:
recorder.video_path = video_path recorder.video_path = video_path
self.start() self.start()
_LOGGER.debug("Started a stream recording of %s seconds", duration) self._logger.debug("Started a stream recording of %s seconds", duration)
# Take advantage of lookback # Take advantage of lookback
hls: HlsStreamOutput = cast(HlsStreamOutput, self.outputs().get(HLS_PROVIDER)) hls: HlsStreamOutput = cast(HlsStreamOutput, self.outputs().get(HLS_PROVIDER))

View File

@ -724,7 +724,7 @@ async def test_durations(hass, record_worker_sync):
) )
source = generate_h264_video(duration=SEGMENT_DURATION + 1) source = generate_h264_video(duration=SEGMENT_DURATION + 1)
stream = create_stream(hass, source, {}) stream = create_stream(hass, source, {}, stream_label="camera")
# use record_worker_sync to grab output segments # use record_worker_sync to grab output segments
with patch.object(hass.config, "is_allowed_path", return_value=True): with patch.object(hass.config, "is_allowed_path", return_value=True):
@ -797,7 +797,7 @@ async def test_has_keyframe(hass, record_worker_sync, h264_video):
}, },
) )
stream = create_stream(hass, h264_video, {}) stream = create_stream(hass, h264_video, {}, stream_label="camera")
# use record_worker_sync to grab output segments # use record_worker_sync to grab output segments
with patch.object(hass.config, "is_allowed_path", return_value=True): with patch.object(hass.config, "is_allowed_path", return_value=True):
@ -836,7 +836,7 @@ async def test_h265_video_is_hvc1(hass, record_worker_sync):
) )
source = generate_h265_video() source = generate_h265_video()
stream = create_stream(hass, source, {}) stream = create_stream(hass, source, {}, stream_label="camera")
# use record_worker_sync to grab output segments # use record_worker_sync to grab output segments
with patch.object(hass.config, "is_allowed_path", return_value=True): with patch.object(hass.config, "is_allowed_path", return_value=True):