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

@@ -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
 

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"]

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<PCM>,
     format: AudioFormat,
@@ -23,25 +55,40 @@ pub struct AlsaSink {
     period_buffer: Vec<u8>,
 }
 
-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<Error>> {
-    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<String>, 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(())
     }
 }

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,7 +1070,8 @@ impl PlayerInternal {
         match self.sink_status {
             SinkStatus::Running => {
                 trace!("== Stopping sink ==");
-                self.sink.stop().unwrap();
+                match self.sink.stop() {
+                    Ok(()) => {
                         self.sink_status = if temporarily {
                             SinkStatus::TemporarilyClosed
                         } else {
@@ -1076,6 +1081,12 @@ impl PlayerInternal {
                             callback(self.sink_status);
                         }
                     }
+                    Err(err) => {
+                        error!("Fatal error, could not stop audio sink: {}", err);
+                        exit(1);
+                    }
+                }
+            }
             SinkStatus::TemporarilyClosed => {
                 if !temporarily {
                     self.sink_status = SinkStatus::Closed;
@@ -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);
                     }
                 }
             }