Merge pull request #908 from JakeStanger/chore/volume-logging

chore: add trace logging to volume module

src/clients/volume/mod.rs

@@ -12,7 +12,7 @@ use libpulse_binding::volume::{ChannelVolumes, Volume};
 use std::fmt::{Debug, Formatter};
 use std::sync::{Arc, Mutex};
 use tokio::sync::broadcast;
-use tracing::{debug, error, info, warn};
+use tracing::{debug, error, info, trace, warn};
 
 pub use sink::Sink;
 pub use sink_input::SinkInput;
@@ -230,6 +230,8 @@ fn on_event(
         return;
     };
 
+    trace!("server event: {facility:?}, op: {op:?}, i: {i}");
+
     match facility {
         Facility::Server => on_server_event(context, &data.sinks, &data.default_sink_name, tx),
         Facility::Sink => sink::on_event(context, &data.sinks, &data.default_sink_name, tx, op, i),

src/clients/volume/sink.rs

@@ -7,7 +7,7 @@ use libpulse_binding::context::subscribe::Operation;
 use libpulse_binding::def::SinkState;
 use std::sync::{Arc, Mutex, mpsc};
 use tokio::sync::broadcast;
-use tracing::{debug, error};
+use tracing::{debug, error, instrument, trace};
 
 #[derive(Debug, Clone)]
 pub struct Sink {
@@ -41,16 +41,19 @@ impl From<&SinkInfo<'_>> for Sink {
 }
 
 impl Client {
+    #[instrument(level = "trace")]
     pub fn sinks(&self) -> Arc<Mutex<Vec<Sink>>> {
         self.data.sinks.clone()
     }
 
+    #[instrument(level = "trace")]
     pub fn set_default_sink(&self, name: &str) {
         if let ConnectionState::Connected { context, .. } = &*lock!(self.connection) {
             lock!(context).set_default_sink(name, |_| {});
         }
     }
 
+    #[instrument(level = "trace")]
     pub fn set_sink_volume(&self, name: &str, volume_percent: f64) {
         if let ConnectionState::Connected { introspector, .. } = &mut *lock!(self.connection) {
             let (tx, rx) = mpsc::channel();
@@ -73,6 +76,7 @@ impl Client {
         }
     }
 
+    #[instrument(level = "trace")]
     pub fn set_sink_muted(&self, name: &str, muted: bool) {
         if let ConnectionState::Connected { introspector, .. } = &mut *lock!(self.connection) {
             introspector.set_sink_mute_by_name(name, muted, None);
@@ -122,6 +126,8 @@ pub fn add(info: ListResult<&SinkInfo>, sinks: &ArcMutVec<Sink>, tx: &broadcast:
         return;
     };
 
+    trace!("adding {info:?}");
+
     lock!(sinks).push(info.into());
     send!(tx, Event::AddSink(info.into()));
 }
@@ -136,6 +142,8 @@ fn update(
         return;
     };
 
+    trace!("updating {info:?}");
+
     {
         let mut sinks = lock!(sinks);
         let Some(pos) = sinks.iter().position(|sink| sink.index == info.index) else {
@@ -166,6 +174,8 @@ fn update(
 }
 
 fn remove(index: u32, sinks: &ArcMutVec<Sink>, tx: &broadcast::Sender<Event>) {
+    trace!("removing {index}");
+
     let mut sinks = lock!(sinks);
 
     if let Some(pos) = sinks.iter().position(|s| s.index == index) {

src/clients/volume/sink_input.rs

@@ -6,7 +6,7 @@ use libpulse_binding::context::introspect::SinkInputInfo;
 use libpulse_binding::context::subscribe::Operation;
 use std::sync::{Arc, Mutex, mpsc};
 use tokio::sync::broadcast;
-use tracing::{debug, error};
+use tracing::{debug, error, instrument, trace};
 
 #[derive(Debug, Clone)]
 pub struct SinkInput {
@@ -35,10 +35,12 @@ impl From<&SinkInputInfo<'_>> for SinkInput {
 }
 
 impl Client {
+    #[instrument(level = "trace")]
     pub fn sink_inputs(&self) -> Arc<Mutex<Vec<SinkInput>>> {
         self.data.sink_inputs.clone()
     }
 
+    #[instrument(level = "trace")]
     pub fn set_input_volume(&self, index: u32, volume_percent: f64) {
         if let ConnectionState::Connected { introspector, .. } = &mut *lock!(self.connection) {
             let (tx, rx) = mpsc::channel();
@@ -61,6 +63,7 @@ impl Client {
         }
     }
 
+    #[instrument(level = "trace")]
     pub fn set_input_muted(&self, index: u32, muted: bool) {
         if let ConnectionState::Connected { introspector, .. } = &mut *lock!(self.connection) {
             introspector.set_sink_input_mute(index, muted, None);
@@ -112,6 +115,8 @@ pub fn add(
         return;
     };
 
+    trace!("adding {info:?}");
+
     lock!(inputs).push(info.into());
     send!(tx, Event::AddInput(info.into()));
 }
@@ -125,6 +130,8 @@ fn update(
         return;
     };
 
+    trace!("updating {info:?}");
+
     {
         let mut inputs = lock!(inputs);
         let Some(pos) = inputs.iter().position(|input| input.index == info.index) else {
@@ -141,6 +148,8 @@ fn update(
 fn remove(index: u32, inputs: &ArcMutVec<SinkInput>, tx: &broadcast::Sender<Event>) {
     let mut inputs = lock!(inputs);
 
+    trace!("removing {index}");
+
     if let Some(pos) = inputs.iter().position(|s| s.index == index) {
         let info = inputs.remove(pos);
         send!(tx, Event::RemoveInput(info.index));

src/modules/volume.rs

@@ -12,6 +12,7 @@ use gtk::{Button, CellRendererText, ComboBoxText, Label, Orientation, Scale, Tog
 use serde::Deserialize;
 use std::collections::HashMap;
 use tokio::sync::mpsc;
+use tracing::trace;
 
 #[derive(Debug, Clone, Deserialize)]
 #[cfg_attr(feature = "schema", derive(schemars::JsonSchema))]
@@ -159,12 +160,16 @@ impl Module<Button> for VolumeModule {
                     sinks.iter().cloned().collect::<Vec<_>>()
                 };
 
+                trace!("initial syncs: {sinks:?}");
+
                 let inputs = {
                     let inputs = client.sink_inputs();
                     let inputs = lock!(inputs);
                     inputs.iter().cloned().collect::<Vec<_>>()
                 };
 
+                trace!("initial inputs: {inputs:?}");
+
                 for sink in sinks {
                     send_async!(tx, ModuleUpdateEvent::Update(Event::AddSink(sink)));
                 }
@@ -178,6 +183,7 @@ impl Module<Button> for VolumeModule {
 
                 // recv loop
                 while let Ok(event) = rx.recv().await {
+                    trace!("received event: {event:?}");
                     send_async!(tx, ModuleUpdateEvent::Update(event));
                 }
             });