Performance: reduce HLS stream publication latency after bounded output #852

Open
opened 2026-10-02 14:24:25 +00:00 by kayg · 6 comments
Owner

Found while fixing #779. The bounded server-owned HLS pipe protocol adds latency in a five-sample native-encoder profile on the perf VM. This is a SLOW-only follow-up, not a merge blocker.

Environment: root@10.69.69.63, HDD emulator at /srv/hdd-emu, held /root/perf.lock, load average inside lock 2.87 1.31 0.86. Baseline docs/perf/baseline.json has no HLS-output metric; compare the previous native output protocol from round 7a with the new server-owned stream protocol. bench/media_hls.py measures namespace/encoder process-tree CPU and peak RSS, plus encoder-and-parent-sink wall latency. It excludes HTTP and Index work.

Average, eight-second fixture, five samples:

  • p50: 165.14 → 202.46 ms (+22.60%).
  • p95: 165.60 → 279.21 ms (+68.60%; general p95 threshold 10%).
  • CPU: 110 → 112 ms (+1.82%).
  • mean peak RSS: 78,473,625.6 → 80,272,588.8 bytes (+2.29%).

Two-job burst, 300-second fixture:

  • p50: 570.28 → 668.95 ms.
  • p95: 571.78 → 721.17 ms (+26.13%).
  • CPU: 620 → 630 ms.
  • mean peak RSS: 81,676,288 → 83,138,560 bytes.

The first profile was discarded because wait4 measured only Bubblewrap's outer monitor. The corrected profile samples descendants in the PID namespace. The new stream and playlist use fsync before publication, which the prior direct-output path did not explicitly require. Investigate batching and syscall cost while retaining the protected free-space reserve, aggregate byte cap, cancellation cleanup and progressive playback. Do not remove those boundaries to improve the number.

Found while fixing #779. The bounded server-owned HLS pipe protocol adds latency in a five-sample native-encoder profile on the perf VM. This is a SLOW-only follow-up, not a merge blocker. Environment: `root@10.69.69.63`, HDD emulator at `/srv/hdd-emu`, held `/root/perf.lock`, load average inside lock `2.87 1.31 0.86`. Baseline `docs/perf/baseline.json` has no HLS-output metric; compare the previous native output protocol from round 7a with the new server-owned stream protocol. `bench/media_hls.py` measures namespace/encoder process-tree CPU and peak RSS, plus encoder-and-parent-sink wall latency. It excludes HTTP and Index work. Average, eight-second fixture, five samples: - p50: 165.14 → 202.46 ms (+22.60%). - p95: 165.60 → 279.21 ms (+68.60%; general p95 threshold 10%). - CPU: 110 → 112 ms (+1.82%). - mean peak RSS: 78,473,625.6 → 80,272,588.8 bytes (+2.29%). Two-job burst, 300-second fixture: - p50: 570.28 → 668.95 ms. - p95: 571.78 → 721.17 ms (+26.13%). - CPU: 620 → 630 ms. - mean peak RSS: 81,676,288 → 83,138,560 bytes. The first profile was discarded because wait4 measured only Bubblewrap's outer monitor. The corrected profile samples descendants in the PID namespace. The new stream and playlist use fsync before publication, which the prior direct-output path did not explicitly require. Investigate batching and syscall cost while retaining the protected free-space reserve, aggregate byte cap, cancellation cleanup and progressive playback. Do not remove those boundaries to improve the number.
Author
Owner

Final native HLS output protocol measurement for #779, held /root/perf.lock on root@10.69.69.63 and used bench/hdd-emu.sh run-limited. Load inside lock: 0.13 0.52 0.51. Normal native media probes passed: PASS: bounded sealed image/video probes, thumbnails and HLS transcode.

Five eight-second samples, before → after: p50 165.25 → 287.39 ms; p95 166.17 → 394.12 ms; CPU 112 → 124 ms; mean peak process-tree RSS 78,558,822.4 → 80,855,040 bytes. Two-job, 300-second burst: p50 877.11 → 760.85 ms; p95 880.25 → 760.88 ms; CPU 600 → 610 ms; RSS 81,514,496 → 84,824,064 bytes. The baseline JSON has no HLS-output metric, so the comparison uses the old round-7a native output protocol on the same VM and fixture. This profile excludes HTTP/Index work and measures native output plus a bounded parent sink. It does not measure progressive Rust publication or large output volumes. Follow-up #852 tracks the average latency regression; no security boundary should be removed to improve it.

Final native HLS output protocol measurement for #779, held /root/perf.lock on root@10.69.69.63 and used bench/hdd-emu.sh run-limited. Load inside lock: `0.13 0.52 0.51`. Normal native media probes passed: `PASS: bounded sealed image/video probes, thumbnails and HLS transcode`. Five eight-second samples, before → after: p50 165.25 → 287.39 ms; p95 166.17 → 394.12 ms; CPU 112 → 124 ms; mean peak process-tree RSS 78,558,822.4 → 80,855,040 bytes. Two-job, 300-second burst: p50 877.11 → 760.85 ms; p95 880.25 → 760.88 ms; CPU 600 → 610 ms; RSS 81,514,496 → 84,824,064 bytes. The baseline JSON has no HLS-output metric, so the comparison uses the old round-7a native output protocol on the same VM and fixture. This profile excludes HTTP/Index work and measures native output plus a bounded parent sink. It does not measure progressive Rust publication or large output volumes. Follow-up #852 tracks the average latency regression; no security boundary should be removed to improve it.
Author
Owner

a publication failure and assert that Drop removes the private name.

Duplicate search: temporary and recovery/depth. Add evidence to #802.

F3 — P2: progressive HLS callbacks block Tokio workers

Evidence: crates/plugins/files/src/media.rs:496 invokes the stream sink
inside an async pipe-read loop. crates/plugins/video/src/transcode.rs:766
connects that sink to HlsWork::write_stream; metadata calls
publish_progress. crates/calternal-fs/src/quota.rs:58 performs synchronous
statvfs and write_all under the shared operation mutex. hls.rs:89 performs
stream fsync, playlist write, rename, and directory fsync synchronously.
The parent repeats playlist parsing on each stdout chunk (transcode.rs:766),
even when metadata has not changed.

Slow disk work occupies a Tokio worker and competes with unrelated request
work. Repeated parsing adds CPU cost as an event playlist grows. This is a
source-level performance finding, not a measured outage or a merge blocker.

Rule: performance-first owner rule; #663 interactive-path rules.

Fix: use one bounded blocking sink worker per rendition. Send chunks and
playlist updates with backpressure. Parse each metadata version once, retain
its required stream boundary, and publish only when that boundary is synced.
Keep reservation ordering, byte limits, cleanup, and progressive playback.

Test idea: block an inert sink while an unrelated runtime task completes.
Assert bounded queued bytes, cancellation cleanup, and publication only after
all declared ranges exist. Compare long-playlist work with the existing profile.

Duplicate search: HLS. #852 owns this publication cost fix; add evidence there.

a publication failure and assert that Drop removes the private name. Duplicate search: temporary and recovery/depth. Add evidence to #802. ## F3 — P2: progressive HLS callbacks block Tokio workers Evidence: `crates/plugins/files/src/media.rs:496` invokes the stream sink inside an async pipe-read loop. `crates/plugins/video/src/transcode.rs:766` connects that sink to `HlsWork::write_stream`; metadata calls `publish_progress`. `crates/calternal-fs/src/quota.rs:58` performs synchronous `statvfs` and `write_all` under the shared operation mutex. `hls.rs:89` performs stream fsync, playlist write, rename, and directory fsync synchronously. The parent repeats playlist parsing on each stdout chunk (`transcode.rs:766`), even when metadata has not changed. Slow disk work occupies a Tokio worker and competes with unrelated request work. Repeated parsing adds CPU cost as an event playlist grows. This is a source-level performance finding, not a measured outage or a merge blocker. Rule: performance-first owner rule; #663 interactive-path rules. Fix: use one bounded blocking sink worker per rendition. Send chunks and playlist updates with backpressure. Parse each metadata version once, retain its required stream boundary, and publish only when that boundary is synced. Keep reservation ordering, byte limits, cleanup, and progressive playback. Test idea: block an inert sink while an unrelated runtime task completes. Assert bounded queued bytes, cancellation cleanup, and publication only after all declared ranges exist. Compare long-playlist work with the existing profile. Duplicate search: HLS. #852 owns this publication cost fix; add evidence there.
Author
Owner

F3 reproduction before the fix: cargo test -p calternal-plugin-files media::tests::slow_media_sink_does_not_block_unrelated_runtime_work -- --exact --nocapture failed because the unrelated Tokio task ran after 267.813 ms while the old callback blocked the current-thread runtime. The run is recorded in artifacts/mediafix/f3-red.log. The change now queues owned pipe frames through a capacity-2 channel to one blocking sink worker; the HLS worker caches each distinct parsed playlist frame. Focused green verification is in progress.

F3 reproduction before the fix: `cargo test -p calternal-plugin-files media::tests::slow_media_sink_does_not_block_unrelated_runtime_work -- --exact --nocapture` failed because the unrelated Tokio task ran after 267.813 ms while the old callback blocked the current-thread runtime. The run is recorded in `artifacts/mediafix/f3-red.log`. The change now queues owned pipe frames through a capacity-2 channel to one blocking sink worker; the HLS worker caches each distinct parsed playlist frame. Focused green verification is in progress.
Author
Owner

The first post-change run exposed a queue shutdown bug: after both pipe readers finished, sender clones remained live while the worker was awaited, so the new test returned None at its 2-second deadline. I moved each sender into its reader future and scope the readers so their senders drop before the worker join. The focused regression test is running again.

The first post-change run exposed a queue shutdown bug: after both pipe readers finished, sender clones remained live while the worker was awaited, so the new test returned `None` at its 2-second deadline. I moved each sender into its reader future and scope the readers so their senders drop before the worker join. The focused regression test is running again.
Author
Owner

F3 sink-worker regression passed after fixing the reader sender lifetime. The final focused output was:

running 1 test
test media::tests::slow_media_sink_does_not_block_unrelated_runtime_work ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 159 filtered out; finished in 0.03s

Commit d23da1a34623c5192b8721dc866521cd3603542f contains the files-side change. The video frame-cache test and crate gates are running.

F3 sink-worker regression passed after fixing the reader sender lifetime. The final focused output was: ```text running 1 test test media::tests::slow_media_sink_does_not_block_unrelated_runtime_work ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 159 filtered out; finished in 0.03s ``` Commit `d23da1a34623c5192b8721dc866521cd3603542f` contains the files-side change. The video frame-cache test and crate gates are running.
Author
Owner

The video slice is committed as ab3a5753309294fe49918b1ec0fe644aa8b367a1. The crate suite passed:

running 15 tests
...
test result: ok. 15 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.56s

The focused sealed-input HLS integration test also passed with the staged media sandbox enabled:

test transcode::media_sandbox_tests::real_video_probe_and_hls_transcode_use_a_sealed_snapshot ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 14 filtered out; finished in 3.14s

The parser regression confirms repeated identical frames reuse the cached parse. Remaining crate clippy/test gates are running.

The video slice is committed as `ab3a5753309294fe49918b1ec0fe644aa8b367a1`. The crate suite passed: ```text running 15 tests ... test result: ok. 15 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.56s ``` The focused sealed-input HLS integration test also passed with the staged media sandbox enabled: ```text test transcode::media_sandbox_tests::real_video_probe_and_hls_transcode_use_a_sealed_snapshot ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 14 filtered out; finished in 3.14s ``` The parser regression confirms repeated identical frames reuse the cached parse. Remaining crate clippy/test gates are running.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
kayg/calternal#852
No description provided.