Camera stream hangs forever after printer reboot #99

Closed
opened 2026-07-23 15:38:21 +02:00 by fmontagna · 1 comment

Description

After a printer reboot (or any interruption that drops the connection), all camera endpoints stop working permanently. MQTT reconnects on its own, but the camera never recovers and nothing is logged. The only fix is POST /api/camera/reset or restarting the bridge.

Root cause: the printer rotates its stream token on reboot (e.g. /live/<old-token> becomes /live/<new-token>). _on_info picks up the new rtspUrl and calls CameraCache.set_url(), but that method only assigns the attribute. The three running ffmpeg processes still hold the old URL, and the loops only re-read self._url at the top of each while True iteration, which they never reach because they are blocked in await proc.stdout.read().

They stay blocked because the TCP connections remain ESTABLISHED with no data and no FIN. A passive reader cannot tell "peer is silent" from "peer is gone" without an I/O timeout, and none is configured (ffmpeg's tcp -timeout defaults to -1, disabled). ensure_running() does not help: it checks task.done(), and the tasks are alive, just permanently blocked. Nothing is logged because the exit/retry logging lives after the finally, which is never reached.

Steps to Reproduce

  1. Start the bridge, confirm the camera stream works
  2. Power-cycle the printer (or disconnect it from the network for ~1 minute)
  3. Wait for MQTT to reconnect, then open /api/camera/stream

Expected Behavior

Camera streams recover automatically once the printer is back and a new stream URL has been received, in the same way MQTT reconnects on its own.

Actual Behavior

The stream page loads indefinitely and never renders a frame. /api/camera/snapshot returns a stale frame or 503. GET /api/camera already reports the new token, so the bridge knows the correct URL, it just never acts on it.

All three ffmpeg processes still alive on the old token after 16h, never respawned:

1347520  ... -i http://<printer-ip>:18088/live/<old-token> -vf fps=2 ...
1347522  ... -i http://<printer-ip>:18088/live/<old-token> -c:v copy ...
1347524  ... -i http://<printer-ip>:18088/live/<old-token> -vf fps=15,scale=640:-1 ...

Sockets alive but idle, Recv-Q 0 on all three:

ESTAB 0 0 <container-ip>:49108 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347520,fd=4))
ESTAB 0 0 <container-ip>:49096 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347522,fd=4))
ESTAB 0 0 <container-ip>:49088 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347524,fd=4))

CPU time flat over 20s (utime stime from /proc/<pid>/stat), confirming no I/O:

196962 12899
196963 12899

POST /api/camera/reset restores the stream immediately, the loops respawn and re-read the updated URL.

Suggested fix

A changed URL is a reliable signal that the running processes are stale, so set_url() can tear them down itself:

def set_url(self, url: str):
    # A changed URL means the printer rotated its stream token (typically
    # after a reboot). Running ffmpeg processes still hold the stale URL and
    # will never pick it up on their own, so tear them down. The next
    # ensure_running() respawns them against the new URL.
    changed = bool(url and self._url and url != self._url)
    self._url = url
    if changed:
      self.reset()

This makes the recovery automatic and matches what the manual reset already does.

Optional hardening: the above covers a rotated token, but not a source that goes silent while the URL stays the same (transient network loss, camera hang). ffmpeg's tcp -timeout option targets that case: it applies to socket I/O rather than just connect. Since it is a tcp-protocol option it applies to both branches of _input_args (the RTSP branch already forces -rtsp_transport tcp), so it can go before the split:

def _input_args(self, url: str) -> list[str]:
    args = ["-fflags", "nobuffer", "-flags", "low_delay",
            # Bail out if the source goes silent. A printer reboot or
            # network loss leaves the connection ESTABLISHED with no data
            # and no FIN, so a passive reader blocks forever.
            "-timeout", "10000000"]  # microseconds
    ...

With this, ffmpeg would exit on a stalled read and the existing retry loop takes over, logging normally.

Separately: handle_camera_stream has no timeout on the first frame (unlike handle_api_camera_snapshot, which waits 5s). A client that never receives a frame hangs forever instead of getting a 503, which is why the failure presents as "the page loads forever" rather than an error.

Environment

  • KX-Bridge Version: v0.9.28-nightly39
  • Installation: Docker

Logs

[13:24:05] WARNING kobrax.mqtt: Connection lost - reconnecting...
[13:24:05] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 1), warte 2s
[13:24:05] ERROR kobrax.mqtt: send error: 'NoneType' object has no attribute 'sendall', reconnecting
[13:24:07] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 2), warte 4s
[13:24:11] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 3), warte 8s
[13:24:24] WARNING kobrax.mqtt: Reconnect fehlgeschlagen (_ssl.c:999: The handshake operation timed out, Versuch 4), warte 15s
[13:24:44] WARNING kobrax.mqtt: Reconnect fehlgeschlagen (_ssl.c:999: The handshake operation timed out, Versuch 5), warte 30s
[13:27:24] INFO  kobrax.mqtt: Reconnect successful (after 8 attempts)

No camera-related log lines at all in this window, the ffmpeg loops never logged an exit or retry.

## Description After a printer reboot (or any interruption that drops the connection), all camera endpoints stop working permanently. MQTT reconnects on its own, but the camera never recovers and nothing is logged. The only fix is `POST /api/camera/reset` or restarting the bridge. Root cause: the printer rotates its stream token on reboot (e.g. `/live/<old-token>` becomes `/live/<new-token>`). `_on_info` picks up the new `rtspUrl` and calls `CameraCache.set_url()`, but that method only assigns the attribute. The three running ffmpeg processes still hold the old URL, and the loops only re-read `self._url` at the top of each `while True` iteration, which they never reach because they are blocked in `await proc.stdout.read()`. They stay blocked because the TCP connections remain `ESTABLISHED` with no data and no FIN. A passive reader cannot tell "peer is silent" from "peer is gone" without an I/O timeout, and none is configured (ffmpeg's tcp `-timeout` defaults to `-1`, disabled). `ensure_running()` does not help: it checks `task.done()`, and the tasks are alive, just permanently blocked. Nothing is logged because the exit/retry logging lives after the `finally`, which is never reached. ## Steps to Reproduce 1. Start the bridge, confirm the camera stream works 2. Power-cycle the printer (or disconnect it from the network for ~1 minute) 3. Wait for MQTT to reconnect, then open `/api/camera/stream` ## Expected Behavior Camera streams recover automatically once the printer is back and a new stream URL has been received, in the same way MQTT reconnects on its own. ## Actual Behavior The stream page loads indefinitely and never renders a frame. `/api/camera/snapshot` returns a stale frame or 503. `GET /api/camera` already reports the *new* token, so the bridge knows the correct URL, it just never acts on it. All three ffmpeg processes still alive on the old token after 16h, never respawned: 1347520 ... -i http://<printer-ip>:18088/live/<old-token> -vf fps=2 ... 1347522 ... -i http://<printer-ip>:18088/live/<old-token> -c:v copy ... 1347524 ... -i http://<printer-ip>:18088/live/<old-token> -vf fps=15,scale=640:-1 ... Sockets alive but idle, `Recv-Q` 0 on all three: ESTAB 0 0 <container-ip>:49108 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347520,fd=4)) ESTAB 0 0 <container-ip>:49096 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347522,fd=4)) ESTAB 0 0 <container-ip>:49088 <printer-ip>:18088 users:(("ffmpeg-linux-x8",pid=1347524,fd=4)) CPU time flat over 20s (`utime stime` from `/proc/<pid>/stat`), confirming no I/O: 196962 12899 196963 12899 `POST /api/camera/reset` restores the stream immediately, the loops respawn and re-read the updated URL. ## Suggested fix A changed URL is a reliable signal that the running processes are stale, so `set_url()` can tear them down itself: def set_url(self, url: str): # A changed URL means the printer rotated its stream token (typically # after a reboot). Running ffmpeg processes still hold the stale URL and # will never pick it up on their own, so tear them down. The next # ensure_running() respawns them against the new URL. changed = bool(url and self._url and url != self._url) self._url = url if changed: self.reset() This makes the recovery automatic and matches what the manual reset already does. **Optional hardening:** the above covers a rotated token, but not a source that goes silent while the URL stays the same (transient network loss, camera hang). ffmpeg's tcp `-timeout` option targets that case: it applies to socket I/O rather than just connect. Since it is a tcp-protocol option it applies to both branches of `_input_args` (the RTSP branch already forces `-rtsp_transport tcp`), so it can go before the split: def _input_args(self, url: str) -> list[str]: args = ["-fflags", "nobuffer", "-flags", "low_delay", # Bail out if the source goes silent. A printer reboot or # network loss leaves the connection ESTABLISHED with no data # and no FIN, so a passive reader blocks forever. "-timeout", "10000000"] # microseconds ... With this, ffmpeg would exit on a stalled read and the existing retry loop takes over, logging normally. Separately: `handle_camera_stream` has no timeout on the first frame (unlike `handle_api_camera_snapshot`, which waits 5s). A client that never receives a frame hangs forever instead of getting a 503, which is why the failure presents as "the page loads forever" rather than an error. ## Environment - KX-Bridge Version: v0.9.28-nightly39 - Installation: Docker ## Logs [13:24:05] WARNING kobrax.mqtt: Connection lost - reconnecting... [13:24:05] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 1), warte 2s [13:24:05] ERROR kobrax.mqtt: send error: 'NoneType' object has no attribute 'sendall', reconnecting [13:24:07] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 2), warte 4s [13:24:11] WARNING kobrax.mqtt: Reconnect fehlgeschlagen ([Errno 111] Connection refused, Versuch 3), warte 8s [13:24:24] WARNING kobrax.mqtt: Reconnect fehlgeschlagen (_ssl.c:999: The handshake operation timed out, Versuch 4), warte 15s [13:24:44] WARNING kobrax.mqtt: Reconnect fehlgeschlagen (_ssl.c:999: The handshake operation timed out, Versuch 5), warte 30s [13:27:24] INFO kobrax.mqtt: Reconnect successful (after 8 attempts) No camera-related log lines at all in this window, the ffmpeg loops never logged an exit or retry.
fmontagna added the
bug
label 2026-07-23 15:38:21 +02:00
Owner

Thanks for the exceptionally thorough writeup, @fmontagna — root cause, reproduction, socket/process evidence, and a working fix proposal made this straightforward to verify and land.

Implemented all three parts, verified against current code:

  1. CameraCache.set_url() now detects when the URL actually changed and calls reset() to tear down the stale ffmpeg loops, exactly as proposed. The next ensure_running() respawns them against the new URL.
  2. -timeout 10000000 (10s, microseconds) added to _input_args() as a second line of defense — applies to both the RTSP and HTTP-FLV paths since they share this one method. Covers the case you flagged separately: a source going silent while the URL itself doesn't change.
  3. First-frame timeout on /api/camera/stream — implemented with one adjustment from the suggested diff: the wait for the first frame (5s) now happens before resp.prepare(request) rather than wrapping the first loop iteration after streaming has already started. prepare() sends the response headers and commits the HTTP status to 200 — once that's called, a 503 can no longer actually be delivered to the client. Waiting on the queue first (with the subscriber already registered, so no frames are missed) lets a stalled source return a proper 503 instead of what would otherwise still be an infinite hang with the wrong status code already sent.

All changes committed locally on nightly, going out with the next nightly build. Added a small test suite for the set_url/reset change-detection logic.

Thanks for the exceptionally thorough writeup, @fmontagna — root cause, reproduction, socket/process evidence, and a working fix proposal made this straightforward to verify and land. Implemented all three parts, verified against current code: 1. **`CameraCache.set_url()`** now detects when the URL actually changed and calls `reset()` to tear down the stale ffmpeg loops, exactly as proposed. The next `ensure_running()` respawns them against the new URL. 2. **`-timeout 10000000`** (10s, microseconds) added to `_input_args()` as a second line of defense — applies to both the RTSP and HTTP-FLV paths since they share this one method. Covers the case you flagged separately: a source going silent while the URL itself doesn't change. 3. **First-frame timeout on `/api/camera/stream`** — implemented with one adjustment from the suggested diff: the wait for the first frame (5s) now happens *before* `resp.prepare(request)` rather than wrapping the first loop iteration after streaming has already started. `prepare()` sends the response headers and commits the HTTP status to 200 — once that's called, a 503 can no longer actually be delivered to the client. Waiting on the queue first (with the subscriber already registered, so no frames are missed) lets a stalled source return a proper 503 instead of what would otherwise still be an infinite hang with the wrong status code already sent. All changes committed locally on `nightly`, going out with the next nightly build. Added a small test suite for the `set_url`/`reset` change-detection logic.
Sign in to join this conversation.
2 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: viewit/KX-Bridge-Release#99
No description provided.