diff --git a/CHANGELOG.md b/CHANGELOG.md index 32716fbda..20fb65ce9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -20,6 +20,7 @@ All notable changes to Bambuddy will be documented in this file. - **PyJWT CVE-2025-45768 (PYSEC-2025-183 / GHSA-65pc-fj4g-8rjx): permanently ignored in pip-audit** — Advisory is disputed by the PyJWT maintainers, with the advisory description literally noting *"this is disputed by the Supplier because the key length is chosen by the application that uses the library."* `fix_versions=[]` on the advisory confirms no PyJWT patch exists or will exist. Bambuddy is not affected: `backend/app/core/auth.py:184` auto-generates secrets via `secrets.token_urlsafe(64)` (~86 chars of entropy, far above any sane minimum) and the file-loaded path at `:177` rejects secrets shorter than 32 chars. Added a permanent `--ignore-vuln CVE-2025-45768` to `.github/workflows/security.yml` with an inline comment citing the file:line evidence so a future maintainer reviewing the ignore list sees why it's load-bearing. Also dropped the stale `--ignore-vuln CVE-2026-4539` for Pygments — Pygments has since shipped a patched version and the ignore is no longer load-bearing (verified: `pip-audit --ignore-vuln CVE-2025-45768` alone reports clean). ### Fixed +- **Camera: ffmpeg's stderr is now captured when an RTSP stream stalls instead of only when ffmpeg crashes (#1395, reported by @Tschipel)** — A P2S support bundle taken on 0.2.5b1 (the per-model probesize fix already applied) showed the camera still failing: ffmpeg connects, stays alive 30+ seconds, emits zero JPEG bytes, the stream's 30 s `stdout.read` times out, reconnect loop repeats — but with **no ffmpeg stderr anywhere in the log** to say why. Root cause was a diagnostic bug, not the camera path: `_read_ffmpeg_stderr` called `process.stderr.read()` (read-to-EOF). A stalled-but-still-alive ffmpeg — exactly the P2S RTSP failure mode — never closes stderr, so the read blocked until the 2 s `wait_for` timeout and returned `None`, discarding the banner + stream-analysis lines ffmpeg had already printed. ffmpeg's stderr was therefore captured *only* when it fully exited; the earlier "not enough frames to estimate rate" smoking gun was available only because ffmpeg crashed back then, and once the probesize bump turned the crash into a hang the diagnostic went dark. **Fix**: `_read_ffmpeg_stderr` now drains stderr incrementally in bounded 8 KB chunks (64 KB cap), returning whatever ffmpeg has printed so far whether or not it has exited — so a hung stream is self-describing in the next support bundle. Additionally, `generate_rtsp_mjpeg_stream` now logs the resolved per-model `probesize` / `analyzeduration` on the info-level "Starting RTSP camera stream" line (verifiable without debug logging), and the debug-level ffmpeg-command line logs the full argv with only the credential-bearing camera URL redacted, instead of hiding the entire command. No behaviour change to streaming itself — this makes the still-unresolved P2S RTSP stall diagnosable. **Tests**: 4 new in `test_camera_stderr_summary.py` cover `_read_ffmpeg_stderr` capturing output from a *running* (un-exited, no-EOF) ffmpeg — the regression — as well as the exited case, the no-stderr-pipe case, and banner-only output summarizing to `None`. 9 camera-stderr tests green; backend ruff clean. - **Camera diagnostic (stethoscope) was missing from the pop-out camera window (#1395, reported by @Tschipel)** — The #1395 camera-diagnostic follow-up — stethoscope icon in the control bar, **Diagnose** button in the stream-error state, `CameraDiagnoseModal` — shipped wired into `EmbeddedCameraViewer.tsx` only, the *embedded* camera mode. It was never added to `CameraPage.tsx`, the standalone window that opens at `/camera/{id}` when `camera_view_mode` is `window` (the default). The reporter's support bundle had `"camera_view_mode": "window"`, so they were on `CameraPage` the whole time and genuinely could not see the stethoscope no matter how many container rebuilds or cache clears they tried — the JS bundle did contain the `camera.diagnose` strings (they come from `EmbeddedCameraViewer`), but that component never renders in window mode. Switching to overlay mode made it appear instantly, exactly as the reporter found. **Fix**: ported the diagnostic into `CameraPage.tsx` — the `Stethoscope` control-bar button (between **Refresh** and **Fullscreen**, matching the embedded viewer), a **Diagnose** button next to **Retry** in the `streamError` block, and the `CameraDiagnoseModal` render. No new i18n keys — `camera.diagnose.*` already exist in all 9 locales. The backend per-model camera-profile fix from the same issue is view-mode-agnostic and already applied; this only makes the diagnostic reachable in the default window mode. Frontend build clean. - **A backend restart mid-print no longer duplicates the job in the archive (#1485, reported by @pwostran)** — When the server running Bambuddy restarted during an active print, the running job was duplicated in the archive — and deleting the duplicate didn't help: every subsequent restart while the print was still running spawned a fresh one. Both support bundles confirmed it: `WARNING Found stale 'printing' archive 3 (age: 9:46:23), marking as cancelled and creating new archive` → `Created archive 4`. On reconnect `on_print_start` fires (Bambuddy sees the printer running) and tries to re-attach to the existing archive in `main.py`. The reliable match is by `subtask_id`; the fallback is a name match plus — and this was the bug — a **4-hour staleness heuristic**: a name-matched `printing` archive older than 4h was assumed dead, marked `cancelled`, and a new archive created. Bambu prints routinely run far longer than 4h, so a genuine long print's *live* archive was destroyed and duplicated on every restart. **Two root causes, both fixed.** **(1) Queue/scheduled archives never persisted a restart-stable `subtask_id`.** Bambuddy mints a per-job id (`project_id`/`subtask_id`/`task_id`) inside `start_print` when it sends the `project_file` command, and the printer echoes it back — but often not within the ~10s before `on_print_start` first fires, so the expected-print branch's `if subtask_id and not archive.subtask_id` write got an empty value and the archive was left with no id. A later restart then had nothing to match on and fell through to the fragile name path. Fix: `BambuMQTTClient.start_print` now records the minted id on `last_dispatch_subtask_id`, and `on_print_start` falls back to it when the printer hasn't echoed `subtask_id` yet — so every dispatched archive persists a stable id and a restart resumes it by id, age-independent. **(2) The 4-hour cutoff itself.** Replaced with a progress-aware check: when a name-matched `printing` archive is found on restart, the printer's *current* reported progress decides resume-vs-stale, not wall-clock age. Real progress (or unknown progress — printer offline) always resumes the existing archive. It is only treated as a stale leftover when the printer clearly shows a *different, freshly-started* print — under 1% progress on an archive more than 2h old, a state a real in-progress print is never in. The arbitrary 4h constant is gone. **Net effect**: a restart mid-print resumes the existing archive (`started_at`, energy, timelapse intact) instead of ever cancelling it and creating a duplicate. **Tests**: 2 new in `test_bambu_mqtt.py` (`start_print` records `last_dispatch_subtask_id`, and updates it per submission); new `TestStaleVsResume` in `test_subtask_archive_resume.py` — 6 cases pinning the progress-aware decision (long print mid-run resumes; barely-started long print resumes; ~0% + old archive is stale; ~0% + young archive resumes; unknown progress never cancels; the sub-1%/2h boundary). 472 print-start / MQTT / scheduler / dispatch tests green; backend ruff clean. - **File Manager no longer polls the printer over FTPS every 30 seconds while open (#1480, reported by @OscarsWorldTech)** — The reporter's P1S churned through MQTT disconnect/reconnect cycles and timelapse downloads silently failed. The support bundle showed the real picture: during the churn windows, MQTT (`Connection stale - no message for 60.2s`), FTPS (`_ssl.c:1015: The handshake operation timed out`) and the camera all timed out *together* and recovered together — the P1S's embedded controller saturating, not a network fault (wifi -44 dBm, Docker host networking). A visible contributor on Bambuddy's side: `FileManagerModal.tsx` ran its `getPrinterFiles` query with `refetchInterval: 30000`, so every 30 s while the File Manager modal sat open it opened a *fresh* FTPS connection — full TLS handshake — to re-list the current directory. A printer's file list doesn't change on its own; it only changes on upload / delete (the modal's mutations already `invalidateQueries`) or when a print finishes. The blind 30 s poll was pure load, and on a fragile controller like the P1S it was enough to tip MQTT and FTP into the timeouts above. **Fix**: the `refetchInterval` is removed. The listing still refreshes on modal open, on directory / tab change (the path is in the query key), after every upload / delete, and via the existing manual Refresh button — so nothing stops updating, the printer just isn't hammered. Reduces steady-state FTPS connection load while the modal is open from one handshake every 30 s to zero. 19 FileManagerModal tests green; frontend build clean. diff --git a/backend/app/api/routes/camera.py b/backend/app/api/routes/camera.py index 3dea1bb26..fcc9496b1 100644 --- a/backend/app/api/routes/camera.py +++ b/backend/app/api/routes/camera.py @@ -276,20 +276,35 @@ def _summarize_ffmpeg_stderr(text: str | None) -> str: async def _read_ffmpeg_stderr(process: asyncio.subprocess.Process) -> str | None: - """Read ffmpeg stderr for diagnostics (best-effort, non-blocking). + """Read whatever ffmpeg has written to stderr so far (best-effort). - Returns the stderr content with ffmpeg's boilerplate banner stripped, - so log output stays focused on the actual error. + ffmpeg's stderr must be drained *incrementally*. A stalled-but-still-alive + ffmpeg — the typical P2S RTSP failure, where it connects but never produces + a frame — never closes stderr, so a plain ``stderr.read()`` (read-to-EOF) + blocks until the wait_for timeout and returns nothing, discarding the + banner + stream-analysis lines ffmpeg already printed. Reading in bounded + chunks returns the buffered output promptly whether or not ffmpeg has + exited. Returns the content with ffmpeg's boilerplate banner stripped. """ if not process or not process.stderr: return None + chunks: list[bytes] = [] + total = 0 + cap = 65536 try: - data = await asyncio.wait_for(process.stderr.read(), timeout=2.0) - if not data: - return None - return _summarize_ffmpeg_stderr(data.decode(errors="replace")) or None - except (TimeoutError, Exception): + while total < cap: + chunk = await asyncio.wait_for(process.stderr.read(8192), timeout=2.0) + if not chunk: + break # EOF — ffmpeg has exited + chunks.append(chunk) + total += len(chunk) + except Exception: + # Timed out waiting for more data — ffmpeg is alive but quiet now. + # Fall through and return whatever it already printed. + pass + if not chunks: return None + return _summarize_ffmpeg_stderr(b"".join(chunks).decode(errors="replace")) or None async def generate_rtsp_mjpeg_stream( @@ -365,9 +380,19 @@ async def generate_rtsp_mjpeg_stream( _disconnect_events[stream_id] = disconnect_event logger.info( - "Starting RTSP camera stream for %s (stream_id=%s, model=%s, fps=%s)", ip_address, stream_id, model, fps + "Starting RTSP camera stream for %s (stream_id=%s, model=%s, fps=%s, probesize=%s, analyzeduration=%s)", + ip_address, + stream_id, + model, + fps, + profile.probesize, + profile.analyzeduration, ) - logger.debug("ffmpeg command: %s ... (url hidden)", ffmpeg) + # Log the full argv so a support bundle shows the actual ffmpeg flags + # (probesize, analyzeduration, transport, ...). Only camera_url carries a + # secret (the access code), so redact just that one element. + _redacted_cmd = ["rtsp:///streaming/live/1" if a == camera_url else a for a in cmd] + logger.debug("ffmpeg command: %s", " ".join(_redacted_cmd)) # On Windows, spawn ffmpeg in its own process group so that # terminate() doesn't broadcast CTRL_C_EVENT to uvicorn (#605). diff --git a/backend/tests/unit/test_camera_stderr_summary.py b/backend/tests/unit/test_camera_stderr_summary.py index 0adb9e1fd..63f3469cf 100644 --- a/backend/tests/unit/test_camera_stderr_summary.py +++ b/backend/tests/unit/test_camera_stderr_summary.py @@ -7,7 +7,9 @@ single click produced 555 lines across 30 retries. The helper strips the banner so logs stay focused on the real error. """ -from backend.app.api.routes.camera import _summarize_ffmpeg_stderr +import asyncio + +from backend.app.api.routes.camera import _read_ffmpeg_stderr, _summarize_ffmpeg_stderr _FAKE_BANNER = """ffmpeg version 7.1.3-0+deb13u1 Copyright (c) 2000-2025 the FFmpeg developers built with gcc 14 (Debian 14.2.0-19) @@ -66,3 +68,55 @@ def test_drops_blank_lines(): def test_banner_only_returns_empty(): """If ffmpeg prints only the banner (no errors), the summary should be empty.""" assert _summarize_ffmpeg_stderr(_FAKE_BANNER) == "" + + +# --- _read_ffmpeg_stderr (#1395) ------------------------------------------- +# A stalled-but-alive ffmpeg (the P2S RTSP failure) never closes stderr, so a +# read-to-EOF discarded everything it had already printed. _read_ffmpeg_stderr +# now drains incrementally and must return that buffered output. + + +class _FakeProcess: + """Minimal stand-in for asyncio.subprocess.Process — only .stderr is read.""" + + def __init__(self, stderr): + self.stderr = stderr + + +def _reader_with(data: bytes, *, eof: bool) -> asyncio.StreamReader: + reader = asyncio.StreamReader() + if data: + reader.feed_data(data) + if eof: + reader.feed_eof() + return reader + + +async def test_read_stderr_captures_output_from_a_running_ffmpeg(): + """The #1395 regression: ffmpeg is alive and has NOT closed stderr (no EOF). + The output it already printed must still be returned, not discarded while + waiting for an EOF that never arrives.""" + stderr = _FAKE_BANNER + "[rtsp @ 0x5] Could not find codec parameters\n" + proc = _FakeProcess(_reader_with(stderr.encode(), eof=False)) + result = await _read_ffmpeg_stderr(proc) + assert result is not None + assert "Could not find codec parameters" in result + assert "ffmpeg version" not in result # banner still stripped + + +async def test_read_stderr_captures_output_from_an_exited_ffmpeg(): + stderr = _FAKE_BANNER + "Error opening input: Connection refused\n" + proc = _FakeProcess(_reader_with(stderr.encode(), eof=True)) + result = await _read_ffmpeg_stderr(proc) + assert result is not None + assert "Connection refused" in result + + +async def test_read_stderr_returns_none_when_no_stderr_pipe(): + assert await _read_ffmpeg_stderr(_FakeProcess(None)) is None + + +async def test_read_stderr_returns_none_for_banner_only_output(): + """Banner with no actionable lines summarizes to empty -> None.""" + proc = _FakeProcess(_reader_with(_FAKE_BANNER.encode(), eof=True)) + assert await _read_ffmpeg_stderr(proc) is None