Merge pull request #849 from vangel76/gap-audio-stream-recovery

#840: restart an audio stream the device drops instead of playing silent
This commit is contained in:
Brandon Thomas 2026-10-11 19:18:34 -04:00
commit bd2b1c57c1
4 changed files with 359 additions and 52 deletions

View File

@ -1,18 +1,33 @@
//! cpal audio output: the playback master clock. Settings ▸ Audio Hardware picks the host
//! ("Device Class"), the output device, the I/O buffer size and the sample rate.
//!
//! A stream the device drops while playing (an ALSA xrun the backend does not recover from, which
//! cpal reports as `poll() returned POLLERR`; an unplugged device) is restarted by
//! [`AudioOut::recover`], keeping the played-frame clock and the play-ahead mixer, so sound
//! resumes where it stopped instead of playback going silent (#840).
use std::panic::{AssertUnwindSafe, catch_unwind};
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
use std::time::{Duration, Instant};
use std::sync::{Arc, Mutex, PoisonError};
use std::sync::{Arc, Mutex, PoisonError, TryLockError};
use cpal::traits::{DeviceTrait, HostTrait, StreamTrait};
use filmcraft_engine::settings::AudioHardwarePrefs;
use filmcraft_ui_egui::{AudioDevices, AudioOut};
/// The playback mixer callback handed to [`AudioOut::start`].
type Fill = Box<dyn FnMut(&mut [f32], usize) + Send>;
pub struct CpalOut {
stream: Option<cpal::Stream>,
/// The running playback's mixer, shared with the stream so a restarted stream continues it.
fill: Option<Arc<Mutex<Fill>>>,
played: Arc<AtomicU64>,
failed: Arc<AtomicBool>,
health: Arc<Health>,
watchdog: Watchdog,
/// Time base for the watchdog.
epoch: Instant,
rate: u32,
channels: u16,
hw: AudioHardwarePrefs,
@ -128,8 +143,11 @@ impl CpalOut {
};
Self {
stream: None,
fill: None,
played: Arc::new(AtomicU64::new(0)),
failed: Arc::new(AtomicBool::new(false)),
health: Arc::new(Health::default()),
watchdog: Watchdog::default(),
epoch: Instant::now(),
rate: cfg.as_ref().map_or(48_000, |c| c.sample_rate().0),
channels: cfg.as_ref().map_or(2, |c| c.channels()),
hw: AudioHardwarePrefs::default(),
@ -153,19 +171,14 @@ impl CpalOut {
Ok(exact.unwrap_or(default))
}
fn converted_stream<T>(
&self,
dev: &cpal::Device,
config: &cpal::StreamConfig,
mut fill: Box<dyn FnMut(&mut [f32], usize) + Send>,
) -> Result<cpal::Stream, cpal::BuildStreamError>
fn converted_stream<T>(&self, dev: &cpal::Device, config: &cpal::StreamConfig, fill: Arc<Mutex<Fill>>) -> Result<cpal::Stream, cpal::BuildStreamError>
where
T: cpal::SizedSample + cpal::FromSample<f32>,
{
let channels = usize::from(config.channels);
let played = self.played.clone();
let failed = self.failed.clone();
let error_flag = failed.clone();
let health = self.health.clone();
let error_health = health.clone();
let mut scratch = Vec::new();
dev.build_output_stream(
config,
@ -173,39 +186,23 @@ impl CpalOut {
// Reuse the conversion buffer. A pathological driver buffer must not panic the audio thread.
if buf.len() > 1_048_576 || scratch.try_reserve(buf.len().saturating_sub(scratch.len())).is_err() {
buf.fill(T::EQUILIBRIUM);
if !failed.swap(true, Ordering::SeqCst) {
if !health.failed.swap(true, Ordering::SeqCst) {
eprintln!("filmcraft: unable to allocate the audio conversion buffer");
}
return;
}
scratch.resize(buf.len(), 0.0);
fill(&mut scratch, channels);
render(&fill, &mut scratch, channels, &played, &health);
convert_samples(&scratch, buf);
played.fetch_add((buf.len() / channels) as u64, Ordering::SeqCst);
},
move |e| stream_error(&error_flag, e),
move |e| stream_error(&error_health, e),
None,
)
}
}
fn stream_error(failed: &AtomicBool, e: cpal::StreamError) {
if !failed.swap(true, Ordering::SeqCst) {
eprintln!("filmcraft: audio stream error: {e}");
}
}
fn convert_samples<T: cpal::Sample + cpal::FromSample<f32>>(input: &[f32], output: &mut [T]) {
// Integer conversion represents [-1, 1). In particular I24 cannot represent +1 exactly.
let upper = f32::from_bits(1.0_f32.to_bits() - 1);
for (sample, converted) in input.iter().zip(output) {
*converted = T::from_sample(if sample.is_finite() { sample.clamp(-1.0, upper) } else { 0.0 });
}
}
impl AudioOut for CpalOut {
fn start(&mut self, mut fill: Box<dyn FnMut(&mut [f32], usize) + Send>) -> Result<u32, String> {
self.stop();
/// Open the configured output device and play `fill` on it. `expect` is the (sample rate,
/// channels) a restarted stream must keep: the mixer was set up for them.
fn open(&mut self, fill: Arc<Mutex<Fill>>, expect: Option<(u32, u16)>) -> Result<(), String> {
let host = host(&self.hw.device_class);
let DeviceChoice { device: dev, fallback } = output_device(&host, &self.hw.default_output, &self.fallback).ok_or("no output device")?;
self.note = fallback;
@ -214,6 +211,11 @@ impl AudioOut for CpalOut {
if channels == 0 || cfg.sample_rate().0 == 0 {
return Err("the output device returned an invalid channel count or sample rate".into());
}
if let Some((rate, ch)) = expect
&& (rate, ch) != (cfg.sample_rate().0, cfg.channels())
{
return Err(format!("the output device now runs at {} Hz with {} channels", cfg.sample_rate().0, cfg.channels()));
}
let mut config: cpal::StreamConfig = cfg.clone().into();
if let cpal::SupportedBufferSize::Range { min, max } = cfg.buffer_size()
&& (*min..=*max).contains(&self.hw.buffer_size)
@ -222,20 +224,18 @@ impl AudioOut for CpalOut {
}
self.rate = cfg.sample_rate().0;
self.channels = cfg.channels();
self.played.store(0, Ordering::SeqCst);
self.failed.store(false, Ordering::SeqCst);
let played = self.played.clone();
let failed = self.failed.clone();
let stream = match cfg.sample_format() {
cpal::SampleFormat::F32 => dev.build_output_stream(
&config,
move |buf: &mut [f32], _| {
fill(buf, channels);
played.fetch_add((buf.len() / channels) as u64, Ordering::SeqCst);
},
move |e| stream_error(&failed, e),
None,
),
cpal::SampleFormat::F32 => {
let played = self.played.clone();
let health = self.health.clone();
let error_health = health.clone();
dev.build_output_stream(
&config,
move |buf: &mut [f32], _| render(&fill, buf, channels, &played, &health),
move |e| stream_error(&error_health, e),
None,
)
}
cpal::SampleFormat::I8 => self.converted_stream::<i8>(&dev, &config, fill),
cpal::SampleFormat::I16 => self.converted_stream::<i16>(&dev, &config, fill),
cpal::SampleFormat::I24 => self.converted_stream::<cpal::I24>(&dev, &config, fill),
@ -251,10 +251,172 @@ impl AudioOut for CpalOut {
.map_err(|e| e.to_string())?;
stream.play().map_err(|e| e.to_string())?;
self.stream = Some(stream);
Ok(())
}
/// Replace a dropped stream with a new one on the same mixer, clock and format.
fn restart(&mut self) -> Result<(), String> {
let fill = self.fill.clone().ok_or("nothing is playing")?;
let expect = (self.rate, self.channels);
// The old stream (and its audio thread) goes first: only one stream ever runs the mixer.
self.stream = None;
self.health.clear_errors();
self.open(fill, Some(expect))
}
}
/// What the audio thread reports to the UI thread.
#[derive(Default)]
struct Health {
/// The device went away (unplugged): restart the stream at once.
lost: AtomicBool,
/// A backend error since the last check (cpal keeps the stream alive after these): restart
/// only if the stream also stopped consuming samples.
errored: AtomicBool,
/// Unrecoverable: the mixer panicked, a buffer could not be allocated, or restarts ran out.
/// [`AudioOut::played_frames`] reports `None` and playback goes on without sound.
failed: AtomicBool,
/// The first error of a stream has been printed.
reported: AtomicBool,
}
impl Health {
fn clear_errors(&self) {
self.lost.store(false, Ordering::SeqCst);
self.errored.store(false, Ordering::SeqCst);
self.reported.store(false, Ordering::SeqCst);
}
}
/// How long a stream that reported an error may go without consuming samples before it is
/// restarted. Well under the UI's `AUDIO_STALL_S`, which gives up on the device clock.
const STALL_RESTART: Duration = Duration::from_millis(300);
/// At most this many restarts within [`RESTART_WINDOW`]; a device that keeps failing gives up.
const MAX_RESTARTS: usize = 3;
const RESTART_WINDOW: Duration = Duration::from_secs(10);
/// What [`Watchdog::check`] decides about the running stream.
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
enum Verdict {
Healthy,
Restart,
GiveUp,
}
/// Decides when a stream that reported errors is restarted (UI thread, every frame).
#[derive(Default)]
struct Watchdog {
/// Played-frame count last seen, and when it last changed.
seen: (u64, Duration),
/// An error was reported and the stream has not consumed samples since.
pending_error: bool,
/// When recent restarts happened (at most [`MAX_RESTARTS`] kept).
restarts: Vec<Duration>,
}
impl Watchdog {
fn reset(&mut self, now: Duration) {
*self = Self { seen: (0, now), ..Self::default() };
}
fn check(&mut self, now: Duration, played: u64, errored: bool, lost: bool) -> Verdict {
if played != self.seen.0 {
self.seen = (played, now);
self.pending_error = false;
}
// An error that arrives with the stream still consuming samples is only a hiccup.
self.pending_error |= errored;
let stalled = now.saturating_sub(self.seen.1) >= STALL_RESTART;
if !lost && !(self.pending_error && stalled) {
return Verdict::Healthy;
}
self.restarts.retain(|t| now.saturating_sub(*t) < RESTART_WINDOW);
if self.restarts.len() >= MAX_RESTARTS {
return Verdict::GiveUp;
}
self.restarts.push(now);
self.seen = (played, now);
self.pending_error = false;
Verdict::Restart
}
}
/// One device callback: run the shared mixer into `buf` and advance the clock. Never panics: a
/// panicking mixer plays silence and fails the stream, and a mixer held by another stream (never
/// expected: a restart drops the old stream first) plays silence without advancing the clock.
fn render(fill: &Mutex<Fill>, buf: &mut [f32], channels: usize, played: &AtomicU64, health: &Health) {
let mut guard = match fill.try_lock() {
Ok(guard) => guard,
Err(TryLockError::Poisoned(poisoned)) => poisoned.into_inner(),
Err(TryLockError::WouldBlock) => {
buf.fill(0.0);
return;
}
};
if health.failed.load(Ordering::SeqCst) || catch_unwind(AssertUnwindSafe(|| (*guard)(buf, channels))).is_err() {
buf.fill(0.0);
if !health.failed.swap(true, Ordering::SeqCst) {
eprintln!("filmcraft: the audio mixer failed; playing without sound");
}
return;
}
played.fetch_add((buf.len() / channels.max(1)) as u64, Ordering::SeqCst);
}
fn stream_error(health: &Health, e: cpal::StreamError) {
match e {
cpal::StreamError::DeviceNotAvailable => health.lost.store(true, Ordering::SeqCst),
cpal::StreamError::BackendSpecific { .. } => health.errored.store(true, Ordering::SeqCst),
}
if !health.reported.swap(true, Ordering::SeqCst) {
eprintln!("filmcraft: audio stream error: {e}");
}
}
fn convert_samples<T: cpal::Sample + cpal::FromSample<f32>>(input: &[f32], output: &mut [T]) {
// Integer conversion represents [-1, 1). In particular I24 cannot represent +1 exactly.
let upper = f32::from_bits(1.0_f32.to_bits() - 1);
for (sample, converted) in input.iter().zip(output) {
*converted = T::from_sample(if sample.is_finite() { sample.clamp(-1.0, upper) } else { 0.0 });
}
}
impl AudioOut for CpalOut {
fn start(&mut self, fill: Box<dyn FnMut(&mut [f32], usize) + Send>) -> Result<u32, String> {
self.stop();
self.played.store(0, Ordering::SeqCst);
self.health = Arc::new(Health::default());
self.watchdog.reset(self.epoch.elapsed());
let fill = Arc::new(Mutex::new(fill));
self.open(fill.clone(), None)?;
self.fill = Some(fill);
Ok(self.rate)
}
fn stop(&mut self) {
self.stream = None;
self.fill = None;
}
fn recover(&mut self) {
if self.stream.is_none() || self.health.failed.load(Ordering::SeqCst) {
return;
}
let lost = self.health.lost.swap(false, Ordering::SeqCst);
let errored = self.health.errored.swap(false, Ordering::SeqCst);
match self.watchdog.check(self.epoch.elapsed(), self.played.load(Ordering::SeqCst), errored, lost) {
Verdict::Healthy => {}
Verdict::Restart => {
log::warn!("the audio output stream {}; restarting it", if lost { "lost its device" } else { "stopped after an error" });
if let Err(e) = self.restart() {
log::warn!("the audio output stream could not be restarted: {e}");
self.stream = None;
self.health.failed.store(true, Ordering::SeqCst);
}
}
Verdict::GiveUp => {
log::warn!("the audio output stream keeps failing ({MAX_RESTARTS} restarts within {} s)", RESTART_WINDOW.as_secs());
self.health.failed.store(true, Ordering::SeqCst);
}
}
}
fn sample_rate(&self) -> u32 {
self.rate
@ -263,7 +425,7 @@ impl AudioOut for CpalOut {
self.channels as usize
}
fn played_frames(&self) -> Option<u64> {
self.stream.as_ref().filter(|_| !self.failed.load(Ordering::SeqCst)).map(|_| self.played.load(Ordering::SeqCst))
self.stream.as_ref().filter(|_| !self.health.failed.load(Ordering::SeqCst)).map(|_| self.played.load(Ordering::SeqCst))
}
fn devices(&self) -> AudioDevices {
let h = host(&self.hw.device_class);
@ -327,11 +489,92 @@ mod tests {
}
#[test]
fn failed_stream_relinquishes_the_playback_clock() {
let failed = AtomicBool::new(false);
stream_error(&failed, cpal::StreamError::DeviceNotAvailable);
assert!(failed.load(Ordering::SeqCst));
fn stream_errors_ask_for_a_restart_instead_of_failing_playback() {
let health = Health::default();
stream_error(&health, cpal::StreamError::BackendSpecific { err: cpal::BackendSpecificError { description: "`alsa::poll()` returned POLLERR".into() } });
assert!(health.errored.load(Ordering::SeqCst) && !health.lost.load(Ordering::SeqCst));
stream_error(&health, cpal::StreamError::DeviceNotAvailable);
assert!(health.lost.load(Ordering::SeqCst));
assert!(!health.failed.load(Ordering::SeqCst), "a stream error alone must not silence playback");
let output = CpalOut::new();
assert_eq!(output.played_frames(), None);
assert_eq!(output.played_frames(), None, "no stream, no clock");
}
fn ms(n: u64) -> Duration {
Duration::from_millis(n)
}
#[test]
fn an_error_while_samples_keep_flowing_is_only_a_hiccup() {
let mut w = Watchdog::default();
w.reset(ms(0));
assert_eq!(w.check(ms(10), 480, true, false), Verdict::Healthy);
// the stream keeps consuming samples after the error: never restarted
for (i, t) in (20..2_000).step_by(20).enumerate() {
assert_eq!(w.check(ms(t), 480 * (i as u64 + 2), false, false), Verdict::Healthy);
}
}
#[test]
fn a_stream_that_errors_and_stops_consuming_is_restarted() {
let mut w = Watchdog::default();
w.reset(ms(0));
assert_eq!(w.check(ms(10), 480, false, false), Verdict::Healthy);
// POLLERR: the backend reports errors and no longer calls back
assert_eq!(w.check(ms(20), 480, true, false), Verdict::Healthy);
assert_eq!(w.check(ms(200), 480, true, false), Verdict::Healthy);
assert_eq!(w.check(ms(310), 480, false, false), Verdict::Restart);
// the restarted stream gets a fresh grace period
assert_eq!(w.check(ms(400), 480, false, false), Verdict::Healthy);
// a stall without any reported error is left to the UI's own watchdog
assert_eq!(w.check(ms(2_000), 480, false, false), Verdict::Healthy);
}
#[test]
fn a_lost_device_restarts_at_once_and_repeated_failures_give_up() {
let mut w = Watchdog::default();
w.reset(ms(0));
assert_eq!(w.check(ms(5), 0, false, true), Verdict::Restart);
assert_eq!(w.check(ms(10), 0, false, true), Verdict::Restart);
assert_eq!(w.check(ms(15), 0, false, true), Verdict::Restart);
assert_eq!(w.check(ms(20), 0, false, true), Verdict::GiveUp);
// sporadic failures far apart keep being recovered
assert_eq!(w.check(ms(10_006), 0, false, true), Verdict::Restart);
}
#[test]
fn the_device_callback_never_panics_and_counts_played_frames() {
let (played, health) = (AtomicU64::new(0), Health::default());
let fill: Mutex<Fill> = Mutex::new(Box::new(|buf: &mut [f32], _| buf.fill(0.25)));
let mut buf = [1.0_f32; 8];
render(&fill, &mut buf, 2, &played, &health);
assert_eq!((buf, played.load(Ordering::SeqCst)), ([0.25; 8], 4));
// a mixer still held elsewhere plays silence without moving the clock
{
let _held = fill.lock().unwrap();
render(&fill, &mut buf, 2, &played, &health);
}
assert_eq!((buf, played.load(Ordering::SeqCst)), ([0.0; 8], 4));
// zero channels from a broken driver must not divide by zero
render(&fill, &mut buf, 0, &played, &health);
assert_eq!(played.load(Ordering::SeqCst), 12);
}
#[test]
fn a_panicking_mixer_plays_silence_and_fails_the_stream() {
let (played, health) = (AtomicU64::new(0), Health::default());
let fill: Mutex<Fill> = Mutex::new(Box::new(|buf: &mut [f32], _| {
buf.fill(0.5);
panic!("mixer bug");
}));
let mut buf = [1.0_f32; 4];
render(&fill, &mut buf, 2, &played, &health);
assert_eq!(buf, [0.0; 4]);
assert_eq!(played.load(Ordering::SeqCst), 0);
assert!(health.failed.load(Ordering::SeqCst));
// later callbacks stay silent instead of re-entering the broken mixer
buf = [1.0; 4];
render(&fill, &mut buf, 2, &played, &health);
assert_eq!(buf, [0.0; 4]);
}
}

View File

@ -83,6 +83,10 @@ pub trait AudioOut {
}
/// Frames played since `start` (the playback master clock), if the device reports it.
fn played_frames(&self) -> Option<u64>;
/// Called every frame while playing, before `played_frames`: restart a stream the device
/// dropped (a driver error, an unplugged device), keeping the clock and `fill`. A stream that
/// cannot be restarted reports `played_frames() == None`.
fn recover(&mut self) {}
/// Hosts and devices that can be chosen in Settings ▸ Audio Hardware.
fn devices(&self) -> AudioDevices {
AudioDevices::default()
@ -1041,6 +1045,11 @@ impl FilmcraftApp {
self.playback.anchor_time = now;
}
let rate = self.session.sequence_rate();
if self.playback.audio_clock
&& let Some(audio) = self.audio.as_mut()
{
audio.recover();
}
let reading = if self.playback.audio_clock { self.audio.as_ref().and_then(|a| a.played_frames().map(|f| (f, a.sample_rate()))) } else { None };
if self.playback.audio_clock && reading.is_none() {
// A device error relinquishes its clock immediately. Resume from the displayed
@ -2252,6 +2261,52 @@ mod audio_recovery_tests {
assert!(app.ui.status.contains("Audio output failed"));
app.stop();
}
/// A stream the device dropped, which `recover` restarts on the same clock.
struct Restartable {
reading: Option<u64>,
}
impl AudioOut for Restartable {
fn start(&mut self, _: Box<dyn FnMut(&mut [f32], usize) + Send>) -> Result<u32, String> {
Ok(48000)
}
fn stop(&mut self) {}
fn sample_rate(&self) -> u32 {
48000
}
fn played_frames(&self) -> Option<u64> {
self.reading
}
fn recover(&mut self) {
self.reading = self.reading.or(Some(48_000));
}
}
#[test]
fn a_restarted_stream_keeps_the_device_clock_and_the_sound() {
let mut session = Session::default();
session.execute("file.openDemoProject", json!({})).unwrap();
let ctx = egui::Context::default();
let mut app = FilmcraftApp::new(session);
app.audio = Some(Box::new(Restartable { reading: None }));
app.playback.playing = true;
app.playback.audio_clock = true;
app.playback.anchor_tick = Tick::ZERO;
app.playback.anchor_time = 0.0;
app.playback.audio_seen = (0, 10.0);
let mut output = ctx.run_ui(egui::RawInput { time: Some(10.0), ..Default::default() }, |ui| app.advance_playback(ui.ctx()));
output.textures_delta.clear();
assert!(app.playback.audio_clock, "the restarted stream is still the master clock");
assert!(!app.ui.status.contains("Audio output failed"));
// 48 000 frames played at 48 kHz: one second in, on a frame boundary
let (shown, second) = (app.session.playhead(), Tick::from_seconds_f64(1.0));
assert!(
shown <= second && shown + app.session.sequence_rate().frame_duration() > second,
"the playhead follows the frames the device played: {shown:?}"
);
app.stop();
}
}
/// Whether a shortcut chord must be left alone because a text field is focused.

View File

@ -213,6 +213,11 @@ impl FilmcraftApp {
self.source_playback.clock.audio_seen = (0, now);
self.start_source_audio();
}
if self.source_playback.clock.audio_clock
&& let Some(audio) = self.audio.as_mut()
{
audio.recover();
}
let clock = &mut self.source_playback.clock;
if clock.anchor_time < 0.0 {
clock.anchor_time = now;

View File

@ -247,6 +247,10 @@ platforms** G4, G9, G17; **performance** G16; **ecosystem** G11; **measurement**
- **Evidence:** Asus Xonar DX output broken (#605), no audio (#602), audio cuts out with
overlapping clips (#336), buggy audio (#410), Linux stutter (#617). No ASIO; cpal only.
- **Have:** a stream the device drops while playing (an ALSA xrun cpal reports as `POLLERR`, an
unplugged device) is restarted with the same rate, channels, clock and mixer position, so sound
resumes instead of playback going silent (at most 3 restarts in 10 s); a panicking mixer plays
silence (#840).
- **Estimate:** 20–40 h.
## G18. Effects depth: approximations and missing behaviour