From 4c77854ffe79620fae046a047e89ca94ed814b8c Mon Sep 17 00:00:00 2001 From: Jason Gray Date: Fri, 18 Jun 2021 13:25:09 -0500 Subject: [PATCH] Better errors alsa backend (#797) Better error handling in Alsa backend * More consistent error messages * Bail on fatal errors in player * Capture and log the original error as a warning when trying to write to PCM before trying to recover --- CHANGELOG.md | 2 + playback/Cargo.toml | 2 +- playback/src/audio_backend/alsa.rs | 213 ++++++++++++++++++++++------- playback/src/player.rs | 33 +++-- 4 files changed, 188 insertions(+), 62 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4293b8d6..c9ca30a8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -24,6 +24,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - [playback] `alsamixer`: complete rewrite (breaking) - [playback] `alsamixer`: query card dB range for the `log` volume control unless specified otherwise - [playback] `alsamixer`: use `--device` name for `--mixer-card` unless specified otherwise +- [playback] `player`: consider errors in `sink.start`, `sink.stop` and `sink.write` fatal and `exit(1)` (breaking) ### Deprecated - [connect] The `discovery` module was deprecated in favor of the `librespot-discovery` crate @@ -42,6 +43,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - [playback] `alsamixer`: make `--volume-ctrl {linear|log}` work as expected - [playback] `alsa`, `gstreamer`, `pulseaudio`: always output in native endianness - [playback] `alsa`: revert buffer size to ~500 ms +- [playback] `alsa`: better error handling ## [0.2.0] - 2021-05-04 diff --git a/playback/Cargo.toml b/playback/Cargo.toml index e19f4ffd..0bed793c 100644 --- a/playback/Cargo.toml +++ b/playback/Cargo.toml @@ -51,7 +51,7 @@ rand = "0.8" rand_distr = "0.4" [features] -alsa-backend = ["alsa"] +alsa-backend = ["alsa", "thiserror"] portaudio-backend = ["portaudio-rs"] pulseaudio-backend = ["libpulse-binding", "libpulse-simple-binding"] jackaudio-backend = ["jack"] diff --git a/playback/src/audio_backend/alsa.rs b/playback/src/audio_backend/alsa.rs index b69b6455..3084f186 100644 --- a/playback/src/audio_backend/alsa.rs +++ b/playback/src/audio_backend/alsa.rs @@ -5,17 +5,49 @@ use crate::decoder::AudioPacket; use crate::{NUM_CHANNELS, SAMPLE_RATE}; use alsa::device_name::HintIter; use alsa::pcm::{Access, Format, HwParams, PCM}; -use alsa::{Direction, Error, ValueOr}; +use alsa::{Direction, ValueOr}; use std::cmp::min; -use std::ffi::CString; use std::io; use std::process::exit; use std::time::Duration; +use thiserror::Error; // 125 ms Period time * 4 periods = 0.5 sec buffer. const PERIOD_TIME: Duration = Duration::from_millis(125); const NUM_PERIODS: u32 = 4; +#[derive(Debug, Error)] +enum AlsaError { + #[error("AlsaSink, device {device} may be invalid or busy, {err}")] + PCMSetUpError { device: String, err: alsa::Error }, + #[error("AlsaSink, device {device} unsupported access type RWInterleaved, {err}")] + UnsupportedAccessTypeError { device: String, err: alsa::Error }, + #[error("AlsaSink, device {device} unsupported format {format:?}, {err}")] + UnsupportedFormatError { + device: String, + format: AudioFormat, + err: alsa::Error, + }, + #[error("AlsaSink, device {device} unsupported sample rate {samplerate}, {err}")] + UnsupportedSampleRateError { + device: String, + samplerate: u32, + err: alsa::Error, + }, + #[error("AlsaSink, device {device} unsupported channel count {channel_count}, {err}")] + UnsupportedChannelCountError { + device: String, + channel_count: u8, + err: alsa::Error, + }, + #[error("AlsaSink Hardware Parameters Error, {0}")] + HwParamsError(alsa::Error), + #[error("AlsaSink Software Parameters Error, {0}")] + SwParamsError(alsa::Error), + #[error("AlsaSink PCM Error, {0}")] + PCMError(alsa::Error), +} + pub struct AlsaSink { pcm: Option, format: AudioFormat, @@ -23,25 +55,40 @@ pub struct AlsaSink { period_buffer: Vec, } -fn list_outputs() { +fn list_outputs() -> io::Result<()> { + println!("Listing available Alsa outputs:"); for t in &["pcm", "ctl", "hwdep"] { println!("{} devices:", t); - let i = HintIter::new(None, &*CString::new(*t).unwrap()).unwrap(); + let i = match HintIter::new_str(None, &t) { + Ok(i) => i, + Err(e) => { + return Err(io::Error::new(io::ErrorKind::Other, e)); + } + }; for a in i { if let Some(Direction::Playback) = a.direction { // mimic aplay -L - println!( - "{}\n\t{}\n", - a.name.unwrap(), - a.desc.unwrap().replace("\n", "\n\t") - ); + let name = a + .name + .ok_or(io::Error::new(io::ErrorKind::Other, "Could not parse name"))?; + let desc = a + .desc + .ok_or(io::Error::new(io::ErrorKind::Other, "Could not parse desc"))?; + println!("{}\n\t{}\n", name, desc.replace("\n", "\n\t")); } } } + + Ok(()) } -fn open_device(dev_name: &str, format: AudioFormat) -> Result<(PCM, usize), Box> { - let pcm = PCM::new(dev_name, Direction::Playback, false)?; +fn open_device(dev_name: &str, format: AudioFormat) -> Result<(PCM, usize), AlsaError> { + let pcm = + PCM::new(dev_name, Direction::Playback, false).map_err(|e| AlsaError::PCMSetUpError { + device: dev_name.to_string(), + err: e, + })?; + let alsa_format = match format { AudioFormat::F64 => Format::float64(), AudioFormat::F32 => Format::float(), @@ -56,23 +103,64 @@ fn open_device(dev_name: &str, format: AudioFormat) -> Result<(PCM, usize), Box< }; let bytes_per_period = { - let hwp = HwParams::any(&pcm)?; - hwp.set_access(Access::RWInterleaved)?; - hwp.set_format(alsa_format)?; - hwp.set_rate(SAMPLE_RATE, ValueOr::Nearest)?; - hwp.set_channels(NUM_CHANNELS as u32)?; - // Deal strictly in time and periods. - hwp.set_periods(NUM_PERIODS, ValueOr::Nearest)?; - hwp.set_period_time_near(PERIOD_TIME.as_micros() as u32, ValueOr::Nearest)?; - pcm.hw_params(&hwp)?; + let hwp = HwParams::any(&pcm).map_err(|e| AlsaError::HwParamsError(e))?; + hwp.set_access(Access::RWInterleaved).map_err(|e| { + AlsaError::UnsupportedAccessTypeError { + device: dev_name.to_string(), + err: e, + } + })?; + + hwp.set_format(alsa_format) + .map_err(|e| AlsaError::UnsupportedFormatError { + device: dev_name.to_string(), + format: format, + err: e, + })?; + + hwp.set_rate(SAMPLE_RATE, ValueOr::Nearest).map_err(|e| { + AlsaError::UnsupportedSampleRateError { + device: dev_name.to_string(), + samplerate: SAMPLE_RATE, + err: e, + } + })?; + + hwp.set_channels(NUM_CHANNELS as u32).map_err(|e| { + AlsaError::UnsupportedChannelCountError { + device: dev_name.to_string(), + channel_count: NUM_CHANNELS, + err: e, + } + })?; + + // Deal strictly in time and periods. + hwp.set_periods(NUM_PERIODS, ValueOr::Nearest) + .map_err(|e| AlsaError::HwParamsError(e))?; + + hwp.set_period_time_near(PERIOD_TIME.as_micros() as u32, ValueOr::Nearest) + .map_err(|e| AlsaError::HwParamsError(e))?; + + pcm.hw_params(&hwp).map_err(|e| AlsaError::PCMError(e))?; + + let swp = pcm + .sw_params_current() + .map_err(|e| AlsaError::PCMError(e))?; - let swp = pcm.sw_params_current()?; // Don't assume we got what we wanted. // Ask to make sure. - let frames_per_period = hwp.get_period_size()?; + let frames_per_period = hwp + .get_period_size() + .map_err(|e| AlsaError::HwParamsError(e))?; - swp.set_start_threshold(hwp.get_buffer_size()? - frames_per_period)?; - pcm.sw_params(&swp)?; + let frames_per_buffer = hwp + .get_buffer_size() + .map_err(|e| AlsaError::HwParamsError(e))?; + + swp.set_start_threshold(frames_per_buffer - frames_per_period) + .map_err(|e| AlsaError::SwParamsError(e))?; + + pcm.sw_params(&swp).map_err(|e| AlsaError::PCMError(e))?; // Let ALSA do the math for us. pcm.frames_to_bytes(frames_per_period) as usize @@ -83,19 +171,23 @@ fn open_device(dev_name: &str, format: AudioFormat) -> Result<(PCM, usize), Box< impl Open for AlsaSink { fn open(device: Option, format: AudioFormat) -> Self { - info!("Using Alsa sink with format: {:?}", format); - let name = match device.as_deref() { - Some("?") => { - println!("Listing available Alsa outputs:"); - list_outputs(); - exit(0) - } + Some("?") => match list_outputs() { + Ok(_) => { + exit(0); + } + Err(err) => { + error!("Error listing Alsa outputs, {}", err); + exit(1); + } + }, Some(device) => device, None => "default", } .to_string(); + info!("Using AlsaSink with format: {:?}", format); + Self { pcm: None, format, @@ -108,18 +200,13 @@ impl Open for AlsaSink { impl Sink for AlsaSink { fn start(&mut self) -> io::Result<()> { if self.pcm.is_none() { - let pcm = open_device(&self.device, self.format); - match pcm { - Ok((p, bytes_per_period)) => { - self.pcm = Some(p); + match open_device(&self.device, self.format) { + Ok((pcm, bytes_per_period)) => { + self.pcm = Some(pcm); self.period_buffer = Vec::with_capacity(bytes_per_period); } Err(e) => { - error!("Alsa error PCM open {}", e); - return Err(io::Error::new( - io::ErrorKind::Other, - "Alsa error: PCM open failed", - )); + return Err(io::Error::new(io::ErrorKind::Other, e)); } } } @@ -131,9 +218,17 @@ impl Sink for AlsaSink { { // Write any leftover data in the period buffer // before draining the actual buffer - self.write_bytes(&[]).expect("could not flush buffer"); - let pcm = self.pcm.as_mut().unwrap(); - pcm.drain().unwrap(); + self.write_bytes(&[])?; + let pcm = self.pcm.as_mut().ok_or(io::Error::new( + io::ErrorKind::Other, + "Error stopping AlsaSink, PCM is None", + ))?; + pcm.drain().map_err(|e| { + io::Error::new( + io::ErrorKind::Other, + format!("Error stopping AlsaSink {}", e), + ) + })? } self.pcm = None; Ok(()) @@ -154,7 +249,7 @@ impl SinkAsBytes for AlsaSink { .extend_from_slice(&data[processed_data..processed_data + data_to_buffer]); processed_data += data_to_buffer; if self.period_buffer.len() == self.period_buffer.capacity() { - self.write_buf(); + self.write_buf()?; self.period_buffer.clear(); } } @@ -166,12 +261,30 @@ impl SinkAsBytes for AlsaSink { impl AlsaSink { pub const NAME: &'static str = "alsa"; - fn write_buf(&mut self) { - let pcm = self.pcm.as_mut().unwrap(); + fn write_buf(&mut self) -> io::Result<()> { + let pcm = self.pcm.as_mut().ok_or(io::Error::new( + io::ErrorKind::Other, + "Error writing from AlsaSink buffer to PCM, PCM is None", + ))?; let io = pcm.io_bytes(); - match io.writei(&self.period_buffer) { - Ok(_) => (), - Err(err) => pcm.try_recover(err, false).unwrap(), - }; + if let Err(err) = io.writei(&self.period_buffer) { + // Capture and log the original error as a warning, and then try to recover. + // If recovery fails then forward that error back to player. + warn!( + "Error writing from AlsaSink buffer to PCM, trying to recover {}", + err + ); + pcm.try_recover(err, false).map_err(|e| { + io::Error::new( + io::ErrorKind::Other, + format!( + "Error writing from AlsaSink buffer to PCM, recovery failed {}", + e + ), + ) + })? + } + + Ok(()) } } diff --git a/playback/src/player.rs b/playback/src/player.rs index 4daac9b4..a6e71aad 100644 --- a/playback/src/player.rs +++ b/playback/src/player.rs @@ -2,6 +2,7 @@ use std::cmp::max; use std::future::Future; use std::io::{self, Read, Seek, SeekFrom}; use std::pin::Pin; +use std::process::exit; use std::task::{Context, Poll}; use std::time::{Duration, Instant}; use std::{mem, thread}; @@ -1057,7 +1058,10 @@ impl PlayerInternal { } match self.sink.start() { Ok(()) => self.sink_status = SinkStatus::Running, - Err(err) => error!("Could not start audio: {}", err), + Err(err) => { + error!("Fatal error, could not start audio sink: {}", err); + exit(1); + } } } } @@ -1066,14 +1070,21 @@ impl PlayerInternal { match self.sink_status { SinkStatus::Running => { trace!("== Stopping sink =="); - self.sink.stop().unwrap(); - self.sink_status = if temporarily { - SinkStatus::TemporarilyClosed - } else { - SinkStatus::Closed - }; - if let Some(callback) = &mut self.sink_event_callback { - callback(self.sink_status); + match self.sink.stop() { + Ok(()) => { + self.sink_status = if temporarily { + SinkStatus::TemporarilyClosed + } else { + SinkStatus::Closed + }; + if let Some(callback) = &mut self.sink_event_callback { + callback(self.sink_status); + } + } + Err(err) => { + error!("Fatal error, could not stop audio sink: {}", err); + exit(1); + } } } SinkStatus::TemporarilyClosed => { @@ -1294,8 +1305,8 @@ impl PlayerInternal { } if let Err(err) = self.sink.write(&packet, &mut self.converter) { - error!("Could not write audio: {}", err); - self.ensure_sink_stopped(false); + error!("Fatal error, could not write audio to audio sink: {}", err); + exit(1); } } }