Add tracing to various places.

.gitignore

@@ -2,3 +2,5 @@
 /target
 /out
 Cargo.lock
+
+trace-*.json

Cargo.toml

@@ -17,6 +17,11 @@ exclude = ["/assets"]
 [dependencies]
 sdl2 = "0.34.0"
 slotmap = "0.4.0"
+tracing = "0.1.19"
+
+[dev-dependencies]
+tracing-chrome = "0.1.0"
+tracing-subscriber = "0.2.11"
 
 [features]
 default = ["sdl2/bundled"]

examples/effects.rs

@@ -1,8 +1,12 @@
 use sdl2;
 use std::error::Error;
 use timbre::{effects::{HighPass, LowPass, BasicMixer, Echo}, decoders::WavDecoder, Share, drivers::Sdl2Output};
+use tracing_subscriber::prelude::*;
 
 fn main() -> Result<(), Box<dyn Error>> {
+    let (chrome_layer, _guard) = tracing_chrome::ChromeLayerBuilder::new().build();
+    tracing_subscriber::registry().with(chrome_layer).init();
+
     let sdl = sdl2::init()?;
     let audio = sdl.audio()?;
 

examples/listen_to_mic.rs

@@ -1,8 +1,12 @@
 use sdl2;
-use timbre::{self, drivers::{Sdl2Output, Sdl2Input}, };
 use std::error::Error;
+use timbre::{self, drivers::{Sdl2Output, Sdl2Input}, };
+use tracing_subscriber::prelude::*;
 
 fn main() -> Result<(), Box<dyn Error>> {
+    let (chrome_layer, _guard) = tracing_chrome::ChromeLayerBuilder::new().build();
+    tracing_subscriber::registry().with(chrome_layer).init();
+
     let sdl = sdl2::init()?;
     let audio = sdl.audio()?;
 

src/decoders/wav_decoder.rs

@@ -3,6 +3,7 @@ use crate::{AudioFormat, AudioSource, StreamState};
 use sdl2::audio::{AudioFormatNum, AudioSpecWAV};
 
 use std::convert::TryInto;
+use tracing::trace_span;
 
 pub struct WavDecoder {
     data: Vec<f32>,
@@ -12,13 +13,11 @@ pub struct WavDecoder {
 
 impl WavDecoder {
     pub fn from_file(path: &str) -> Self {
-        let before = std::time::Instant::now();
-        let wav_data = AudioSpecWAV::load_wav(path).unwrap();
-        println!("load_wav took {:?} ms ", before.elapsed().as_millis());
+        let span = trace_span!("WavDecoder::from_file");
+        let _span = span.enter();
 
-        let before = std::time::Instant::now();
+        let wav_data = AudioSpecWAV::load_wav(path).unwrap();
         let data = convert_samples(wav_data.buffer(), wav_data.format);
-        println!("convert_samples took {:?} ms", before.elapsed().as_millis());
 
         let format = match wav_data.channels {
             1 => AudioFormat::Mono(wav_data.freq),

src/drivers/sdl2_input.rs

@@ -4,6 +4,7 @@ use std::collections::VecDeque;
 use std::sync::{Arc, Mutex};
 
 use sdl2::audio::{AudioCallback, AudioSpecDesired};
+use tracing::trace_span;
 
 pub struct Sdl2Input {
     device: sdl2::audio::AudioDevice<Callback>,
@@ -23,6 +24,9 @@ struct AudioSourceImpl {
 impl AudioCallback for Callback {
     type Channel = f32;
     fn callback(&mut self, samples: &mut [Self::Channel]) {
+        let span = trace_span!("Sdl2Input::callback");
+        let _span = span.enter();
+
         self.buffer.lock().unwrap().extend(samples.iter().cloned());
     }
 }
@@ -73,6 +77,9 @@ impl AudioSource for AudioSourceImpl {
     }
 
     fn read(&mut self, samples: &mut [f32]) -> StreamState {
+        let span = trace_span!("Sdl2Input::read");
+        let _span = span.enter();
+
         let mut buffer = self.buffer.lock().unwrap();
 
         let mut i: usize = 0;

src/drivers/sdl2_output.rs

@@ -3,6 +3,7 @@ use crate::{AudioFormat, AudioSource, StreamState};
 use std::sync::{Arc, Mutex};
 
 use sdl2::audio::{AudioCallback, AudioFormatNum, AudioSpecDesired};
+use tracing::trace_span;
 
 struct Callback {
     pub format: AudioFormat,
@@ -12,6 +13,9 @@ struct Callback {
 impl AudioCallback for Callback {
     type Channel = f32;
     fn callback(&mut self, samples: &mut [Self::Channel]) {
+        let span = trace_span!("Sdl2Output::callback");
+        let _span = span.enter();
+
         if let Some(source) = &self.source {
             let mut source = source.lock().unwrap();
             if source.format() != self.format {

src/effects/basic_mixer.rs

@@ -3,6 +3,7 @@ use crate::core::{AudioFormat, AudioSource, StreamState};
 use slotmap::{DefaultKey, DenseSlotMap};
 
 use std::sync::{Arc, Mutex};
+use tracing::trace_span;
 
 pub struct BasicMixer {
     buffer: Vec<f32>,
@@ -43,6 +44,9 @@ impl AudioSource for BasicMixer {
     }
 
     fn read(&mut self, samples: &mut [f32]) -> StreamState {
+        let span = trace_span!("BasicMixer::read");
+        let _span = span.enter();
+
         if self.sources.is_empty() {
             samples.iter_mut().for_each(|sample| *sample = 0.0);
             return StreamState::Good;

src/effects/echo.rs

@@ -1,6 +1,7 @@
 use crate::core::{AudioFormat, AudioSource, StreamState};
 
 use std::sync::{Arc, Mutex};
+use tracing::trace_span;
 
 pub struct Echo {
     source: Arc<Mutex<dyn AudioSource + Send>>,
@@ -30,6 +31,9 @@ impl AudioSource for Echo {
     }
 
     fn read(&mut self, samples: &mut [f32]) -> StreamState {
+        let span = trace_span!("Echo::read");
+        let _span = span.enter();
+
         let status = self.source.lock().unwrap().read(samples);
         let written = match status {
             StreamState::Good => samples.len(),

src/effects/high_pass.rs

@@ -1,6 +1,7 @@
 use crate::core::{AudioFormat, AudioSource, StreamState};
 
 use std::sync::{Arc, Mutex};
+use tracing::trace_span;
 
 pub struct HighPass {
     buffer: Vec<f32>,
@@ -31,6 +32,9 @@ impl AudioSource for HighPass {
     }
 
     fn read(&mut self, samples: &mut [f32]) -> StreamState {
+        let span = trace_span!("HighPass::read");
+        let _span = span.enter();
+
         let result = self.source.lock().unwrap().read(samples);
         let written = match result {
             StreamState::Good => samples.len(),

src/effects/low_pass.rs

@@ -1,6 +1,7 @@
 use crate::core::{AudioFormat, AudioSource, StreamState};
 
 use std::sync::{Arc, Mutex};
+use tracing::trace_span;
 
 pub struct LowPass {
     buffer: Vec<f32>,
@@ -37,6 +38,9 @@ impl AudioSource for LowPass {
     }
 
     fn read(&mut self, samples: &mut [f32]) -> StreamState {
+        let span = trace_span!("LowPass::read");
+        let _span = span.enter();
+
         let result = self.source.lock().unwrap().read(samples);
         let written = match result {
             StreamState::Good => samples.len(),