fix(engine): don't kill cold gst registry rebuild with 2s probe timeout - #717
Open
ivanslabbert wants to merge 26 commits into
Open
fix(engine): don't kill cold gst registry rebuild with 2s probe timeout#717ivanslabbert wants to merge 26 commits into
ivanslabbert wants to merge 26 commits into
Conversation
…y pipeline - Added documentation for video player hardware decode and display pipeline, detailing findings from the field test on Raspberry Pi devices. - Updated hardware setup recommendations to ensure optimal configuration for media router hosts, including video memory allocation and codec throughput. - Introduced unit tests for the `westonOutput` helper functions, ensuring correct parsing of the compositor's output configuration and handling of various transform scenarios. - Enhanced the `resolveWestonSurface` function to accurately determine the logical surface size based on the compositor's configuration, accounting for transformations and manual mode settings.
Restores the renderWatch feature dropped in the branch rebase, redesigned
around a field-proven flaw: the original counted buffer ARRIVALS at the
sink pad, which reported a clean 50 fps while waylandsink internally
discarded 18 fps (compositor pacing) — blind during exactly the stutter
it exists to catch.
- gst-pipeline-runner.py: _start/_stop_render_watch — judge the PRESENTED
rate from GstBaseSink `stats` (rendered/dropped deltas per 2 s window);
pad arrivals kept only as a stall gate (no arrivals = stall watchdog's
condition, not lag) and as fallback for sinks without `stats`. Emits
`renderwatch:lag` / `renderwatch:recovered` with
{achievedFps, expectedFps, droppedFps}
- render_lag.py: hysteresis monitor (0.85 trip / 0.95 recover, 3 windows),
pure logic, restored verbatim; render_lag_test.py: 19 self-checks
- PluginModule.ts: PipelineDescription.renderWatch + RenderWatchRunnerConfig
- GstChildProcess/PythonProcess: forward renderWatch to the runner
- engine package.json: ship render_lag.py to dist (build cp list)
- plugins/README.md: renderWatch section
Verified on a field Pi 4: one lag transition in a 2 h soak
(achieved=35.0 expected=50.0 dropped=15.5), matching independent
measurements, no flapping.
2005 tests passing across 145 files, plus 19 render_lag self-checks.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Two field-found failures share one root cause: with no `display`
configured, pickActiveDisplay('') returns an empty name by design, and
two consumers treated that as "no display" instead of falling back to
the first lit output (as the surface-sizing path already does):
- buildPipelineEnv got no MR_GLIB_PRGNAME, so kiosk-shell (which only
maps surfaces whitelisted in the output's app-ids=) never placed the
video surface — pipeline running, screen empty
- currentActiveDisplayName returned '' so findCogPidForDisplay matched
nothing and the cog poll watch never armed; after a weston restart cog
could land on top and frame-callback-starve the video to ~1 fps while
decode burned 0.56 core, with no recovery (weston restarts happen on
every device-manager display-config apply)
Both now fall back to firstConnectedDisplay(), mirroring the
surfaceConnector fallback.
Also wires renderWatch onto the live pipeline (renderwatch:lag →
health warning "Video output can't keep up (a/b fps)", recovery only
clears health this latch set; watch attached only when the sink is
named — autovideosink is a bin without name=sink).
2005 tests passing across 145 files.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
tsparse's documented purpose — re-anchoring PCR so multi-stage REMUX paths don't accumulate clock drift — doesn't apply to a terminal display pipeline: the player never re-muxes, the default sink presents on arrival (sync=false), clock-locked mode takes its timeline from tsdemux PES via preserveSourceTimeline, and the leaky jitter queue sits upstream of where tsparse sat and operates on bus timestamps either way. Measured on a field Pi 4 (1080p50): tsparse set-timestamps=true was the single most expensive element in the chain at 0.11 core (it re-frames per TS packet; staged A/B: receive 0.13, +tsparse 0.11, +tsdemux 0.005); tsdemux consumes the raw bus buffers directly. Runner CPU 0.56 -> 0.51 core in production, playback and renderWatch behaviour unchanged. Input is now buildBusSrc + buildLeakyQueue directly (identical chain minus tsparse, watchdog naming preserved for bus_stall detection); buildTsUdpInput and its remux rationale stay untouched for other modules. 2005 tests passing across 145 files. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
mr-tssplit broadcast each per-input-buffer same-PID packet run as its own bus buffer — measured 692 buffers/s of ~1.3 KB on a 1080p50 feed — and every broadcast pays a memfd_create + write + per-client fd-pass, with each consumer paying recvmsg + mmap + munmap + close per buffer. Accumulate per output and flush at BUFFER_BYTES (~24 KB ≈ 22 ms of video) or FLUSH_INTERVAL_MS via the existing tick(), whichever first — the time flush keeps low-rate PIDs (audio would take seconds to fill a size batch) inside the same latency bound. Packet order and PSI-ahead- of-ES ordering are preserved; added latency is bounded by the flush interval, well inside the player's 200 ms jitter budget. Measured on the field Pi 4 (with the tsparse removal in the previous commit): bus edge 692 -> 39 buf/s @ 22.5 KB; video-player runner CPU 564 -> 235 jiffies/10 s (0.56 -> 0.24 core; decode+display now dominate at 86 j); mr-tssplit itself 142 -> 89. Playback verified unchanged, with presented rate slightly up (~35 -> ~37 fps) from reduced scheduling contention. 2005 tests passing across 145 files; all 3 native C++ suites pass. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Replaces the July field-test writeup (largely superseded: renderWatch re-landed with stats-based counting, SAND patches exist on oswald's branch, the surface rule went source-sized, plane scanout confirmed working) with the current open items distilled from all 2026-08-01 instrumented sessions. Adds the two new CPU todos: unixfdsink ingest coalescing (symmetric to ae748f6, rides the SAND gstreamer rebuild) and the librist rist-reader cost. The full investigation history moves to the media-router-yocto branch git log; the standalone handover doc there is being retired in favour of this file. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The gst-side patch (0007 in media-router-yocto) is authored and wired into the bbappend; it rides the SAND image build together with the unixfdsink ingest coalescing. Verification criteria recorded. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Hand-built on the Pi 5 dev box, deployed on the field device: live 1080p50 now presents at full rate (arrivals == presented, drops 0, RSS flat). Patch v3 records the AB-BA deadlock found and fixed along the way. Permanent delivery rides the image build. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…h-ms Makes the fan-out coalescing window a per-module setting instead of a compile-time constant. `busBatchMs` (schema: default 20 ms, 0-100, x-unit ms) flows through buildSpawnArgs as `--flush-ms` to mr-tssplit; 0 disables coalescing entirely and takes the original zero-copy direct-broadcast path for ultra-low-latency chains, at the measured per-buffer fan-out cost (~0.35 core at 1080p50 across producer and consumers). The BUFFER_BYTES size cap still applies independently as a memory bound. Omitted config keeps the runner's built-in 20 ms default, byte-identical to the previous behaviour (field-verified: ~42 buf/s @ ~22 KB on the live device). Measured for the trade-off note: flip-cadence on the display path is IDENTICAL at 0 ms, 10 ms and 20 ms batching (12.2/s skipped vblanks in all three) — batching affects CPU and latency only, not smoothness. 2007 tests passing across 145 files; all 3 native C++ suites pass. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…e path Resolves the sync=true timestamp question left open by the tsparse removal. Traced end to end: unixfdsrc converts the bus's monotonic wire timestamps into pipeline running time (from_monotonic in 1.28.2), and the long-shipped pacing recipe pairs a sync=true sink with tsparse's PCR-derived, clock-anchored per-frame timestamps (buildSink's own sync documentation). So buildLivePipeline now takes sinkPaced: when the sink honours PTS (the `sync` config or clockSync), the inbound chain is the classic buildTsUdpInput with set-timestamps=<!preserveSourcePts>; otherwise the tsparse-free present-on-arrival fast path stays. The 0.11-core tsparse cost is paid only when pacing is chosen; clockSync keeps set-timestamps=false so the shared A/V timeline survives. This is the designed fix for the residual ~2/s display judder: with sync=false nothing paces frames, so arrival jitter reaches the compositor and latest-wins latching turns it into skipped/doubled vblanks (12/s measured, independent of bus batching). Enabling the existing "Honour buffer PTS" toggle now activates the paced chain; field validation of smoothness is the remaining step. 2008 tests passing across 145 files. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…hain Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Operator-confirmed smooth; weston timeline: skipped vblanks 12.2/s -> 2.2/s (clock-drift beat floor), flat 50 flips/s. Bonus finding: tsparse on the batched bus costs ~0.02 core (vs 0.11 unbatched), so pacing and batching compose — smooth mode is nearly free. Open decision recorded: sync-on-by-default for playout. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…yout Flips the default: clock-paced presentation is the out-of-the-box behaviour; the knob stays as the ultra-low-latency / degraded-PCR escape hatch. Latency of pacing field-measured on the live 1080p50 path: frames arrive at median ~0-1 ms before their presentation deadline (the tsparse timeline is arrival-anchored, so the pipeline's announced latency cancels against processing delay) — pacing adds ~nothing at the median and up to a few tens of ms of per-frame jitter smoothing. Schema description rewritten around the plain trade-off: smooth playback (on) vs lowest latency (off). DEPLOY NOTE added to TodoNotes.md: unset configs flip to paced on the next engine update; broken-PCR feeds may need the toggle off. 2008 tests passing across 145 files. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Field-measured: the clockSync pipeline schedules its first frame 19.2 hours in the future (raw PES epoch against a near-zero shared-clock running time) and the sink waits. Structural and pre-existing, not a regression. Recorded with the fix direction (epoch latch wiring) and interim guidance (toggle off; default sync covers all but lipsync). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Points at the diagnosed first-frame freeze (epoch mismatch, tracked in docs/TodoNotes-video-hw-decode.md) and states the intended lipsync purpose and the interim guidance. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…sive Review of the TODO against the session's fixes. Adds a prominent gate: every display fix (waylandsink 0007, sync default ON, tsparse-conditional chain, batching, F13/F19) was validated on one Pi 4 but ships fleet-wide — Pi 5 and Intel must be tested before concluding, with the two named machine-specific risks: different buffer-release/flip timing on rp1/i915 for the sink patch, and paced presentation against SOFTWARE decode latencies on Pi 5 (previously default-off there). Header refreshed to the end-of-session state; old smoke-test bullet folded into the gate. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Full patch series (base 0001 + bad 0002-0007) built natively on the dev box and hand-deployed on the field Pi 4. Decode proof passes (4 s clip, 0.73 core-s vs software's 6.7; NV12_128C8/SAND128 selected); SAND dmabufs keep the hardware overlay plane (no GL fallback). Records the two CI-gate test gotchas found the hard way: ANY-caps peers hide DRM formats (so fakesink can never prove SAND decode) and decide_allocation mandates VideoMeta — the valid headless proof is fakevideosink. Live HEVC through the player pending an HEVC bus source. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The OCC feed switched to H.265 and surfaced two independent blockers. (a) Hardware SAND decode is resolution-dependent: synthetic 720p50 passes (1.0 s, 0.73 core-s), synthetic 1080p50 and a captured OCC sample both hang with "Decoding frame 2 took too long" — pointing at the resolution-scaled math in patches 0003/0004 or SAND stride/column handling at 1920. Repro assets banked on the device for oswald. (b) decodebin3 never plugs the SAND decoder (setup_decoder hang with parsebin-fixated hvc1 caps); the direct parse+decoder chain works, so the player needs a codec-aware builder (tsProbe + explicit chain + restart-on-codec-change) or a decodebin3 fix. Field device interim: dist hand-patched to the direct HEVC chain; recommendation recorded to run the OCC feed on H.264 until (a) is fixed. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Operator-confirmed: after retried 1080p HEVC decode attempts the field box hard-hung (frozen last frame, network down, power-cycle needed) — a wedged rpivid decode job takes the kernel with it. Interim hang guard installed on the device: v4l2slh265dec rank-masked via a user-unit drop-in (manual repro pipelines still work), hand-patched dist restored to the built decodebin3 chain. Boot evidence lost to the known no-persistent-journal gap. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- runner: report arrivalsFps in renderwatch:lag events - video-player: when presented ≈ arrivals (dropped 0), warn "Stream under-delivering — check the source/link" instead of advising a resolution change the operator doesn't need - field case: intermittent 41fps warning on OCC feed was stream delivery dips, not render lag (arrivals==presented, dropped==0) - TodoNotes-video-hw-decode.md: field forensics recorded — recovered- loss RIST storms invisible to ad-hoc link checks; overnight wall- clock-grid shallow dips still open; RWX/RSX diagnostics left armed on .108; per-packet Python pad probe hazard noted 2016 tests passing across 146 files (4 new). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- new "Loss (recovered)" % in Live Stats: missing/(received+missing)
per stats window — exposes a degraded link that still delivers a
perfect stream (lost only counts unrecovered packets)
- module health with hysteresis: quality <85 for 3 consecutive stats
windows → warning ("RIST link degraded — recovering N% packet loss
(RTT X ms); stream still intact"); clears after 5 clean windows
(≥95); mid-band keeps an active warning latched; never clears a
warning another path owns
- dedup the double setStatusData('stats') while in there
2018 tests passing across 146 files (6 new).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- rist-reader thread broke out of its loop on the first RistError; a link blackout (field case: peer dead 832 ms) deletes+recreates the librist flow, the read raises -3 once, and the relay then sat wedged with an undrained fifo until a module restart - retry through read errors (warn once per burst, 100 ms backoff via _rist_stop.wait so teardown stays responsive) - TodoNotes: incident recorded + open item for decoder state reset on the video player's stall-resume path 2018 tests passing across 146 files. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- render_lag: sustained sink drops (>5% of expected fps) count toward the lag streak even when presented fps sits inside the hysteresis band; recovery additionally requires drops to clear. Field case 2026-08-02: 12% late-drops at presented ratio 0.88 stuttered silently for 5 minutes. - resume stability gate: stall-resume waits for 3 consecutive flowing 1 Hz polls before rebuilding live, instead of rebuilding on the first byte against a still-churning source - post-resume self-heal: a renderwatch lag within 120 s of a stall-resume triggers ONE automatic rebuild (never for source shortfall, never twice per resume) - TodoNotes: resume-gap item addressed; RT-priority image item added (PipeWire/librist threads run without RT — confirmed contributing to audio xruns, parked for a separate investigation) 2021 tests passing across 146 files (+23 render_lag self-checks). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- lowLatencySync hardcoded a 50 ms ring that xrunned audibly on the field Pi 4 (pw-top ERR ~1/90 s, dropouts "here and there"); the path now honours sinkBufferMs with a 100 ms floor — with sync=true the anchor is ts-offset, so ring depth is scheduling margin, not proportional standing latency - field-validated audio config for the eventual default flip: lowLatencySync on, syncOffsetMs 250-350, slaveMethod skew (resample slaving hunts audibly under pipewire-pulse) 2021 tests passing across 146 files. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…isplay hot-plug
- video-player: cog restack rule — process start-time comparison with a
15 s surface-grace window replaces the PID baseline that missed the
compositor-restart respawn race (field 2026-08-02: video hidden
behind the control panel after a monitor power-cycle); one restack
per cog incarnation, latch survives internal restarts
- video-player: renderwatch-owned warning cleared on pipeline rebuild
(fresh monitor only reports transitions — "(0/50 fps)" stuck forever)
- routing: MediaRouter.reexecuteIncomingPwLinks re-executes pw-link
edges into a module's rebuilt PipeWire node; audio-output calls it
from onDeviceReconnected (recreated remap-sink was a new node — the
decoder→output link died silently, module IDLE while "running")
- state sync: getState() serializes a cleared error as null, not
undefined — JSON drops undefined keys and the manager-ui's per-field
merger could never clear stale error text ("healthy but shows an old
error", any module, survived engine restarts); a successful start
also wipes the previous incarnation's error text
- field-verified via weston-restart drills on .108: rebuild → restack →
steady playback, error=null on the wire
2032 tests passing across 147 files.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
On a cold plugin-registry cache the first gst-inspect-1.0 rebuilds the full registry (>2s on a Pi 4). The fatal unixfdsrc probe's 2s timeout killed the rebuild mid-write, leaving only a registry .tmp file — so the cache never completed and the engine crash-looped forever with 'GStreamer unixfdsrc not available' even though the plugin is installed (seen on fleet unit 10.32.1.12, restart counter 50+). Give probeGstElement an optional timeout and let the fail-fast unixfdsrc probe wait 120s. It is the first gst-inspect of the process, so its completion also warms the registry for every later 2s/5s probe. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
TLDR
On a box with a cold GStreamer registry cache, the engine's fatal
unixfdsrcprobe killedgst-inspect-1.0at 2s — mid registry rebuild — so the cache never completed and the engine crash-looped forever with "GStreamer unixfdsrc not available" even though gst 1.28 + the plugin are installed. Side effect in the field: local device manager profile saves silently vanished on page refresh (engine API on :3001 never up; UI still said "saved"). Seen on fleet unit 10.32.1.12, restart counter 50+.Fix:
probeGstElement()takes an optional timeout; the fail-fastunixfdsrcprobe inEngine.start()now waits up to 120s. It's the first gst-inspect of the process, so completing it also warms the registry for every later 2s/5s probe.Validated on 10.32.1.12: wiped
~/.cache/gstreamer-1.0(the stuck state), restarted — engine comes up, registry rebuilds fully, profiles persist across refresh.Not addressed here: the device-manager UI reporting "saved" when the engine sync fails (separate repo/fix).
🤖 Generated with Claude Code