Merge pull request #5 from SolarLiner/feat/logging

Add logging

Cargo.toml

@@ -7,11 +7,13 @@ license = "MIT"
 
 [dependencies]
 duplicate = "1.0.0"
+log = "0.4.22"
 ndarray = "0.15.6"
 thiserror = "1.0.63"
 
 [dev-dependencies]
 anyhow = "1.0.86"
+env_logger = "0.11.5"
 indicatif = "0.17.8"
 
 [build-dependencies]

examples/enumerate_alsa.rs

@@ -6,6 +6,9 @@ mod util;
 fn main() -> Result<(), Box<dyn Error>> {
  use crate::util::enumerate::enumerate_devices;
  use interflow::backends::alsa::AlsaDriver;
+
+ env_logger::init();
+
  enumerate_devices(AlsaDriver::default())
 }
 

examples/input.rs

@@ -5,6 +5,8 @@ use interflow::prelude::*;
 use interflow::timestamp::Timestamp;
 
 fn main() -> Result<()> {
+ env_logger::init();
+
  let device = default_input_device();
  let config = StreamConfig {
  samplerate: 48000.,

examples/sine_wave.rs

@@ -5,6 +5,8 @@ use anyhow::Result;
 use interflow::prelude::*;
 
 fn main() -> Result<()> {
+ env_logger::init();
+
  let device = default_output_device();
  let config = StreamConfig {
  samplerate: 48000.,

src/backends/alsa.rs

@@ -98,10 +98,16 @@ impl AudioDevice for AlsaDevice {
  }
 
  fn is_config_supported(&self, config: &StreamConfig) -> bool {
- self.get_hwp(config).is_ok()
+ self.get_hwp(config)
+ .inspect_err(|err| {
+ log::debug!("{config:#?}");
+ log::debug!("Configuration unsupported: {err}");
+ })
+ .is_ok()
  }
 
  fn enumerate_configurations(&self) -> Option<impl IntoIterator<Item = StreamConfig>> {
+ log::info!("TODO: enumerate configurations");
  None::<[StreamConfig; 0]>
  }
 }
@@ -183,6 +189,9 @@ impl AlsaDevice {
  let hwp = self.pcm.hw_params_current()?;
  let swp = self.pcm.sw_params_current()?;
 
+ log::debug!("Apply config: hwp {hwp:#?}");
+ log::debug!("Apply config: swp {swp:#?}");
+
  // TODO: Forward buffer size hints
 
  swp.set_start_threshold(hwp.get_buffer_size()?)?;
@@ -221,9 +230,11 @@ impl<Callback: 'static + Send + AudioInputCallback> AlsaStream<Callback> {
  let (hwp, _, io) = device.apply_config(&stream_config)?;
  let (_, period_size) = device.pcm.get_params()?;
  let period_size = period_size as usize;
- eprintln!("Period size: {period_size}");
+ log::info!("Period size : {period_size}");
  let num_channels = hwp.get_channels()? as usize;
+ log::info!("Num channels: {num_channels}");
  let samplerate = hwp.get_rate()? as f64;
+ log::info!("Sample rate : {samplerate}");
  let stream_config = StreamConfig {
  samplerate,
  channels: ChannelMap32::default()
@@ -234,16 +245,22 @@ impl<Callback: 'static + Send + AudioInputCallback> AlsaStream<Callback> {
  let mut buffer = vec![0f32; period_size * num_channels];
  device.pcm.prepare()?;
  if device.pcm.state() != pcm::State::Running {
+ log::info!("Device not already started, starting now");
  device.pcm.start()?;
  }
  let _try = || loop {
  if eject_signal.load(Ordering::Relaxed) {
+ log::debug!("Eject requested, returning ownership of callback");
  break Ok(callback);
  }
  let frames = device.pcm.avail_update()? as usize;
  let len = frames * num_channels;
  match io.readi(&mut buffer[..len]) {
- Err(err) => device.pcm.try_recover(err, true)?,
+ Err(err) => {
+ log::warn!("ALSA PCM error, trying to recover ...");
+ log::debug!("Error: {err}");
+ device.pcm.try_recover(err, true)?;
+ }
  _ => {}
  }
  let buffer = AudioRef::from_interleaved(&buffer[..len], num_channels).unwrap();
@@ -254,7 +271,7 @@ impl<Callback: 'static + Send + AudioInputCallback> AlsaStream<Callback> {
  let input = AudioInput { buffer, timestamp };
  callback.on_input_data(context, input);
  timestamp += frames as u64;
- 
+
  match device.pcm.state() {
  pcm::State::Suspended => {
  if hwp.can_resume() {
@@ -287,8 +304,11 @@ impl<Callback: 'static + Send + AudioOutputCallback> AlsaStream<Callback> {
  let (hwp, _, io) = device.apply_config(&stream_config)?;
  let (_, period_size) = device.pcm.get_params()?;
  let period_size = period_size as usize;
+ log::debug!("Period size : {period_size}");
  let num_channels = hwp.get_channels()? as usize;
+ log::debug!("Num channels: {num_channels}");
  let samplerate = hwp.get_rate()? as f64;
+ log::debug!("Sample rate : {samplerate}");
  let stream_config = StreamConfig {
  samplerate,
  channels: ChannelMap32::default()
@@ -326,16 +346,20 @@ impl<Callback: 'static + Send + AudioOutputCallback> AlsaStream<Callback> {
  match device.pcm.state() {
  pcm::State::Suspended => {
  if hwp.can_resume() {
+ log::debug!("Stream suspended, resuming");
  device.pcm.resume()?;
  } else {
+ log::debug!(
+ "Stream suspended but cannot resume, re-prepare instead"
+ );
  device.pcm.prepare()?;
  }
  }
  pcm::State::Paused => std::thread::sleep(Duration::from_secs(1)),
  _ => {}
  }
  };
- _try().inspect_err(|err| eprintln!("Audio thread error: {err}"))
+ _try().inspect_err(|err| log::error!("Audio thread error: {err}"))
  }
  });
  Self {