Logging used a bit more

src/log.rs

@@ -14,16 +14,22 @@ thread_local! {
     pub static LOG: RefCell<Option<Log>> = RefCell::new(None);
 }
 
-pub fn retrieve_log_messages(msgs: &mut Vec<String>) {
+pub fn retrieve_log_messages<F: FnMut(&str, &str)>(f: F) {
     if let Ok(mut lr) = LOG_RECV.lock() {
-        lr.retrieve_messages(msgs);
+        lr.retrieve_messages(f);
     }
 }
 
-pub fn init_thread_logger() {
+#[inline]
+pub fn init_thread_logger(name: &'static str) -> bool {
+    if !LOG.with(|l| l.borrow().is_some()) {
         if let Ok(mut lr) = LOG_RECV.lock() {
-        lr.spawn_global_logger();
+            lr.spawn_global_logger(name);
+            return true;
         }
+    }
+
+    false
 }
 
 pub fn log<F: Fn(&mut std::io::BufWriter<&mut [u8]>)>(f: F) {
@@ -40,7 +46,7 @@ pub fn log<F: Fn(&mut std::io::BufWriter<&mut [u8]>)>(f: F) {
 const MAX_LOG_BUFFER : usize = 4096;
 
 pub struct LogReceiver {
-    consumers:  Vec<Consumer<u8>>,
+    consumers:  Vec<(&'static str, Consumer<u8>)>,
 }
 
 impl LogReceiver {
@@ -50,17 +56,14 @@ impl LogReceiver {
         }
     }
 
-    pub fn retrieve_messages(&mut self, out: &mut Vec<String>) {
-        for consumer in self.consumers.iter_mut() {
+    pub fn retrieve_messages<F: FnMut(&str, &str)>(&mut self, mut f: F) {
+        for (name, consumer) in self.consumers.iter_mut() {
             let mut buf = [0; 1024];
             let mut oi = 0;
 
             while let Some(byte) = consumer.pop() {
                 if oi >= buf.len() || byte == 0xFF {
-                    out.push(
-                        std::str::from_utf8(&buf[0..oi])
-                        .unwrap()
-                        .to_string());
+                    f(name, std::str::from_utf8(&buf[0..oi]).unwrap());
                     oi = 0;
                 } else {
                     buf[oi] = byte;
@@ -70,19 +73,20 @@ impl LogReceiver {
         }
     }
 
-    pub fn spawn_logger(&mut self) -> Log {
+    pub fn spawn_logger(&mut self, name: &'static str) -> Log {
         let rb = RingBuffer::new(MAX_LOG_BUFFER);
         let (producer, con) = rb.split();
 
-        self.consumers.push(con);
+        self.consumers.push((name, con));
         Log {
             producer,
             buf: [0; 512],
         }
     }
 
-    pub fn spawn_global_logger(&mut self) {
-        let hdl = self.spawn_logger();
+    #[inline]
+    pub fn spawn_global_logger(&mut self, name: &'static str) {
+        let hdl = self.spawn_logger(name);
         LOG.with(move |f| {
             *f.borrow_mut() = Some(hdl);
         });
@@ -126,7 +130,7 @@ mod tests {
     fn check_threaded_logger() {
         std::thread::spawn(|| {
             use std::io::Write;
-            init_thread_logger();
+            assert!(init_thread_logger("tstlog"));
             log(|w| write!(w, "Test Log{}!", 1).unwrap());
             log(|w| write!(w, "Test Log{}!", 2).unwrap());
         });
@@ -136,11 +140,11 @@ mod tests {
             std::thread::sleep(
                 std::time::Duration::from_millis(100));
 
-            retrieve_log_messages(&mut msgs);
+            retrieve_log_messages(|name, s| msgs.push(name.to_string() + "/" + s));
 
             if msgs.len() > 1 {
-                assert_eq!(msgs[0], "Test Log1!");
-                assert_eq!(msgs[1], "Test Log2!");
+                assert_eq!(msgs[0], "tstlog/Test Log1!");
+                assert_eq!(msgs[1], "tstlog/Test Log2!");
                 break;
             }
         };

src/nodes/node_exec.rs

@@ -11,6 +11,9 @@ use crate::dsp::{NodeId, Node, NodeContext, MAX_BLOCK_SIZE};
 use crate::util::{Smoother, AtomicFloat};
 use crate::monitor::{MonitorBackend, MON_SIG_CNT};
 
+use std::io::Write;
+use crate::log;
+
 use ringbuf::{Producer, Consumer};
 use std::sync::Arc;
 
@@ -54,6 +57,9 @@ pub struct NodeExecutor {
 
     /// The connection with the [crate::nodes::NodeConfigurator].
     shared: SharedNodeExec,
+
+    /// A flag to remember if we already initialized the logger on the audio thread.
+    dsp_log_init: bool,
 }
 
 /// Contains anything that connects the [NodeExecutor] with the frontend part.
@@ -198,6 +204,7 @@ impl NodeExecutor {
             prog:              NodeProg::empty(),
             monitor_signal_cur_inp_indices: [UNUSED_MONITOR_IDX; MON_SIG_CNT],
             exec_ctx:          NodeExecContext::new(),
+            dsp_log_init:      false,
             shared,
         }
     }
@@ -212,6 +219,10 @@ impl NodeExecutor {
                         std::mem::replace(
                             &mut self.nodes[index as usize],
                             node);
+
+                    log(|w| {
+                        let _ = write!(w, "[dbg] Create node index={}", index); });
+
                     let _ =
                         self.shared.graph_drop_prod.push(
                             DropMsg::Node { node: prev_node });
@@ -231,10 +242,16 @@ impl NodeExecutor {
                     self.monitor_signal_cur_inp_indices =
                         [UNUSED_MONITOR_IDX; MON_SIG_CNT];
 
+                    log(|w| {
+                        let _ = write!(w,
+                            "[dbg] Cleared graph ({} nodes)",
+                            self.prog.prog.len()); });
+
                     let prev_prog = std::mem::replace(&mut self.prog, prog);
                     let _ =
                         self.shared.graph_drop_prod.push(
                             DropMsg::Prog { prog: prev_prog });
+
                 },
                 GraphMessage::NewProg { prog, copy_old_out } => {
                     let mut prev_prog = std::mem::replace(&mut self.prog, prog);
@@ -295,6 +312,11 @@ impl NodeExecutor {
                     let _ =
                         self.shared.graph_drop_prod.push(
                             DropMsg::Prog { prog: prev_prog });
+
+                    log(|w| { let _ =
+                        write!(w,
+                            "[dbg] Created new graph (node count={})",
+                            self.prog.prog.len()); });
                 },
             }
         }
@@ -421,6 +443,14 @@ impl NodeExecutor {
     pub fn process<T: NodeAudioContext>(&mut self, ctx: &mut T) {
         // let tb = std::time::Instant::now();
 
+        if !self.dsp_log_init
+           && crate::log::init_thread_logger("dsp")
+        {
+            self.dsp_log_init = true;
+            crate::log(|w| {
+                let _ = write!(w, "DSP thread logger initialized"); });
+        }
+
         self.process_param_updates(ctx.nframes());
 
         let nodes    = &mut self.nodes;