flybrain/infra/docs/capture-freeze.md

The capture freeze: one new picture a second, perfect audio, 0 dup / 0 drop

Measured 2026-09-16 on the release box the release container and reproduced six times on the dev box the dev container. ffmpeg 7.1.5 (Debian trixie) on both. Fixed by an ordering gate, and watched by a probe on the encoder output; the exact mechanism inside ffmpeg is not established and nothing below claims one.

1. The symptom

flycast (ffmpeg: x11grab on :99 at 30 fps plus the pulse stream.monitor, an fps=30:round=near filter, -fps_mode:v cfr, tee'd to MediaMTX RTMP and to 10-minute mpegts segments) produces a video stream in which only about one frame per second is a new picture and the other 29 are repeats, while:

• the audio is perfect the whole time;
• ffmpeg's own progress counters report 0 dup, 0 drop, 30 fps — check 3 of fly-watchdog (frame= advancing in /run/fly/flycast.progress) is satisfied;
• an independent x11grab of the same display shows the display updating normally — the page, Chromium and Xvfb are all fine;
• the freeze lasts for the life of the ffmpeg process. It does not recover.

On the release container it was present from the 06:35:52 UTC container boot until a manual systemctl restart flycast at 10:26 UTC — 3 h 50 min of frozen broadcast. Confirmed after the fact by decoding the recorded segments: 174 to 177 identical consecutive frames out of 180 in the first six seconds of every segment from 06:35 to 10:25, against 0 to 4 out of 180 in the segments recorded between the 06:06 restart and the 06:35 boot, and again after the 10:26 restart.

In the frozen state, strace on the x11grab thread shows about 4 X round trips per second instead of 30, and no time blocked in them.

2. The trigger, from the dev box

Ten experiments on the dev container. The number is identical consecutive frames out of 180 in the local HLS output, measured 40 s after the start.

Experiment	Identical / 180
restart xvfb (so flystage and flycast co-start via Requires=)	171	frozen
restart flycast alone with Chromium already up and steady	6	fine
flystage stopped, restart flycast, start flystage 8 s later	0	fine
flystage stopped, restart xvfb+flycast together, start flystage 10 s later	5	fine
restart flystage and flycast at the same instant, old Xvfb	171	frozen
Chromium up, an extra silent audio client connects to the pulse sink 1 s after flycast start	22	mostly fine
flystage stopped (sink IDLE), restart flycast, a silent client connects 1 s later, flystage started 5 s after that	167	frozen
hammering the X server with xsetroot during flycast's first 4 s, no audio change	4	fine
a permanent silent client keeps the sink RUNNING, flystage stopped, restart flycast, start flystage 1 s later	166	frozen
same permanent silent client, restart flystage and flycast at the same instant	12	fine

Conclusion. A new PulseAudio client (Chromium's audio stream at boot, or any client) attaching to the null sink during roughly the first one to three seconds of ffmpeg's start — its stream probing window — leaves the video path permanently starved. A client attaching at the same instant, or 8 s later, does not. The X server is not involved: hammering it in the same window changes nothing.

Two things this rules out, both worth stating because both were the obvious first guesses:

• It is not the sink going idle. A sink keep-alive does not fix it: the two experiments with a permanent silent client holding the sink RUNNING still froze when the page's client attached 1 s in.
• It is not encoder CPU starvation. It reproduces on the NVENC dev box, where the encoder is off-CPU, and it survives with sim/page/encoder on separate cores.

What is not established: what inside ffmpeg goes wrong. Do not turn "its stream probing window" into a mechanism claim. -analyzeduration and -probesize are demuxer probing controls (-analyzeduration "specify how many microseconds are analyzed to probe the input", default 0, i.e. the format decides; -probesize a byte cap, default 5 MB) and ffmpeg's own documentation of them says nothing about a device input's first seconds — so the ffmpeg command is deliberately left untouched by this fix. Tuning them would be a guess dressed as a fix, on the one process whose flags are the broadcast.

3. What changed

Nothing in the ffmpeg command line. The fix is ordering plus a watchdog.

3.1 units/flycast.service: order after the page, and wait for it

• After=xvfb.service pulse.service mediamtx.service **flystage.service**. Ordering only; flystage.service is deliberately NOT in Requires= — a dead or restarting page must not be able to take the encoder, the recording and the broadcast down with it, which is this repo's "the page is display only so the fly survives browser and encoder restarts" rule.
• ExecStartPre=/opt/fly/bin/wait-for-stage 120, after the existing wait-for-x :99 30.
• TimeoutStartSec=180. Both waits are inside the start job and 30 + 120 s exceeds systemd's default TimeoutStartSec=90s, which would have killed the unit mid-wait with Restart=always spinning it. The same latent bug was in flystage.service (30 + 120 behind its /healthz wait); fixed there too, though it was never observed — flysim answers well inside 90 s on the release container.

3.2 bin/wait-for-stage: what "ready" means

wait-for-stage [TIMEOUT] returns 0 only when all three of these hold, and have held continuously for a 5 s settle period:

1. The X display answers — xdpyinfo on :99, the same probe wait-for-x uses. Its root geometry is reused by check 2.
2. A Chromium kiosk window is mapped on :99 — xwininfo -root -tree, taking the windows whose WM_CLASS is ("chromium" "Chromium"), or, if the profile renamed itself (e.g. under vglrun), any child window whose geometry matches the root. A candidate counts only if xwininfo -id <id> -stats says Map State: IsViewable and it covers at least half the root area. There is no window manager on :99, so there is no _NET_* state to ask instead.
3. The pulse sink stream has at least one sink-input — pactl list short sink-inputs as the fly user with PULSE_SERVER=unix:/run/fly/pulse/native and XDG_RUNTIME_DIR=/run/fly (the env pulse.service sets and flycast.service already passes), matched against the sink index pactl list short sinks gives for the name stream. This is the condition that matters: it means the page's audio client is already attached, so ffmpeg's first seconds see a static client set rather than a connect.

If any check flips back to not-ready, the settle period starts over — a client connecting or reconnecting resets the clock instead of letting ffmpeg start into a moving target. Settle timing is whole-second, so the held period can be up to a second short of 5 s.

xwininfo is from x11-utils and pactl from pulseaudio-utils, both already in 02-base.sh's package list; nothing new is installed for this, and xdotool (which is not in that list) is not used.

After TIMEOUT (120 s) it logs a WARNING and still exits 0, so flycast starts anyway: a black-but-running stream beats no stream, and a page that never comes up is flystage's failure to report. The only nonzero exits are usage errors. wait-for-stage --once evaluates the three checks once, prints which one failed, and exits 1 — that is the hand-run diagnostic.

3.3 bin/fly-watchdog check 9: the self-healing probe

The ordering gate closes the window that was reproduced; it is not proof that no path into the freeze remains, and the freeze is invisible to every other check (audio fine, frame= advancing, page healthy). So the watchdog now measures the encoder output:

ffmpeg -sseof -4 -i <newest segment> -t 3 \
  -vf "tblend=all_mode=difference,blackframe=amount=99.5:threshold=8" -an -f null -

and counts the Parsed_blackframe report lines (each carries ] frame:; the last_keyframe field on those same lines is not what is counted). With tblend's difference output, a frame that reads as black is a frame identical to the one before it.

• Every 5 minutes, not every 60 s pass; the newest .ts under /srv/fly/media/rec, and only when flycast.service is active and that segment is being written (mtime under 120 s old) — otherwise a deliberately stopped encoder would look frozen.
• Run under nice -n 10 and taskset -c on flycast's own AllowedCPUs (read from /etc/systemd/system/flycast.service.d/cpuset.conf, which 05-deploy.sh generates from CPUSET/RAYON_THREADS/ENCODER_CORES); unpinned when no partition is configured. The probe must never land on the sim's cores. A timeout 60 guard keeps a wedged probe from holding the pass open.
• Two consecutive probes at 80 or more identical frames out of ~90 restarts flycast once, logs it at err, and never restarts again for this reason inside 30 minutes. One bad probe logs and waits: a legitimately still page could read high once.
• A probe that decodes fewer than 60 frames is logged as inconclusive and not compared. An absolute threshold under-counts on a short decode, and under-counting can only ever hide a freeze, never invent one — the safe direction for something that restarts a live broadcast.
• Metrics, in the watchdog's existing node_exporter textfile: fly_capture_freeze_restarts_total (counter) and fly_capture_identical_frames (gauge, the last probe's value, -1 before the first probe).

The restart it issues goes through the ordering gate like any other flycast start, so the self-heal cannot itself land in the freeze window: the page is already up, so wait-for-stage should return after its 5 s settle, and the gap is under ten seconds.

Local calibration of the same command on fixture segments (infra/tests/lint.sh section 3e): a static colour reads 81 identical frames, a mandelbrot reads 0. The live numbers are the same shape: 174-177/180 frozen against 0-4/180 healthy.

3.4 05-deploy.sh: stop the deploy hurting the sim

Unrelated to the freeze, owed from the same morning. Every in-container step runs through pct exec, which lands on the container's whole cpuset, so the release extraction, the MANIFEST sha256sum -c pass and chown -R competed with flysim: fly_lag_seconds went from 3 s to 5 s during the live v0.1.1 deploy. Those three steps now run under taskset -c <page cpus>, derived from the same lib/common.sh cpuset_partition call (the same CPUSET/RAYON_THREADS/ENCODER_CORES values) that generates the cpuset drop-ins, so the two can never disagree about which cpus belong to the sim. It is a no-op when no partition is configured, or when the container's conf does not match CPUSET — the same guard the drop-ins use. The page group is the target because it has the most slack; the encoder group has to stay clear or the deploy shows up as dropped frames on the broadcast.

The script header now also says, in as many words: never re-run 05-deploy.sh on a live release box as an idempotency check. It is idempotent, and that is not the point — every run does real work on the cores the sim is holding real time on. Verify a deploy by reading /opt/fly/current, the MANIFEST and the units.

4. The measurement lesson

The "identical frames" check must be run on the ENCODER OUTPUT — the local HLS, or the newest segment under /srv/fly/media/rec, which is the same bytes MediaMTX and Twitch get. Never on an independent x11grab of the display. The display was fine the whole time; a second grabber of :99 reports a healthy, updating picture while the broadcast is frozen, so it reports PASS on exactly the failure it is supposed to catch.

This is not hypothetical. The 3/57 measurement recorded in docs/stream-mvp-plan.md (2026-09-16 06:36 UTC, "unchanged captured frames 3/57 (was 73/115)", after the release container was widened to ten node-1 cores) was taken with that wrong instrument, and it is why a frozen broadcast read as fixed at 06:36 and then ran frozen until 10:26. A correction note is filed in infra/docs/p0-measurements.md and against that plan entry.

The same number in its earlier form — "63% of captured frames came back unchanged across two fly-watchdog passes", quoted in infra/README.md step 4, infra/docs/runbook.md's "CPU partition (cpuset)" and lib/common.sh's cpuset_partition header as the finding that justifies giving flycast its own cores — is the 73/115 half of that same pair, from that same instrument. It has not been re-measured, so treat the three-way cpuset split as unproven-by-that-number rather than wrong: the split is cheap, it is live on the release container and the dev container, and nothing here is a reason to re-plumb it. It is a reason not to cite 63% as evidence for anything until someone re-runs it against the encoder output.

5. What is not verified

• wait-for-stage's readiness path and check 9's live behaviour cannot be exercised without a container: they need Xvfb, a Chromium kiosk, a pulse sink with a real client, and a running flycast. Everything testable on the operator box is in infra/tests/lint.sh section 3e (the unit's ordering/timeout directives, the argument handling, the timeout contract, and the whole of check 9 against ffmpeg-made fixture segments with a fake systemctl).
• The mechanism inside ffmpeg. The fix avoids the window; it does not explain it.
• Whether the ordering gate closes every path into the freeze. That is what check 9 and fly_capture_identical_frames are for. If the counter ever climbs on a container where wait-for-stage reported ready, this document's conclusion is incomplete and the next experiment is the pulse client set during ffmpeg's first three seconds (pactl subscribe alongside a flycast start is the cheap way to log it).