🚧 wip: working on some debugging tools

.gitignore

@@ -1,2 +1,3 @@
 /deps
 /target
+/untracked

Cargo.lock

@@ -895,6 +895,8 @@ version = "0.1.0"
 dependencies = [
  "eframe",
  "linuxvideo",
+ "serde",
+ "serde_json",
  "thiserror",
  "tokio",
  "zune-core",
@@ -1198,6 +1200,12 @@ dependencies = [
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "itoa"
+version = "1.0.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "af150ab688ff2122fcef229be89cb50dd66af9e01a4ff320cc137eecc9bacc38"
+
 [[package]]
 name = "jni"
 version = "0.21.1"
@@ -1875,6 +1883,12 @@ dependencies = [
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "ryu"
+version = "1.0.15"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1ad4cc8da4ef723ed60bced201181d83791ad433213d8c24efffda1eec85d741"
+
 [[package]]
 name = "same-file"
 version = "1.0.6"
@@ -1929,6 +1943,17 @@ dependencies = [
  "syn 2.0.31",
 ]
 
+[[package]]
+name = "serde_json"
+version = "1.0.107"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6b420ce6e3d8bd882e9b243c6eed35dbc9a6110c9769e74b584e0d68d1f20c65"
+dependencies = [
+ "itoa",
+ "ryu",
+ "serde",
+]
+
 [[package]]
 name = "serde_repr"
 version = "0.1.16"

Cargo.toml

@@ -8,6 +8,8 @@ edition = "2021"
 [dependencies]
 eframe = "0.22.0"
 linuxvideo = { path = "deps/LinuxVideo" }
+serde = { version = "1.0.188", features = ["derive"] }
+serde_json = "1.0.107"
 thiserror = "1.0.48"
 tokio = { version = "1.32.0", features = ["full"] }
 zune-core = { path = "deps/zune-image/zune-core" }

src/controller.rs

@@ -159,4 +159,24 @@ impl Controller
 			None
 		}
 	}
+	
+	pub fn to_json (&self, start_time: Instant) -> serde_json::Value {
+        serde_json::json! ({
+            "gui_has_new_frame": self.gui_has_new_frame,
+            "gui_needs_frame": self.gui_needs_frame,
+            
+            "jpeg_decoder_is_running": self.jpeg_decoder_is_running,
+            "jpeg_decoder_has_new_frame": self.jpeg_decoder_has_new_frame,
+            "jpeg_decoder_needs_frame": self.jpeg_decoder_needs_frame,
+            
+            "network_send_is_running": self.network_send_is_running,
+            "network_send_has_new_frame": self.network_send_has_new_frame,
+            "network_send_needs_frame": self.network_send_needs_frame,
+            
+            "capture_is_running": self.capture_is_running,
+            
+            "rgba_frame_capture_time": (self.rgba_frame.capture_time - start_time).as_millis (),
+            "jpeg_frame_capture_time": (self.jpeg_frame.capture_time - start_time).as_millis (),
+        })
+    }
 }

src/driver.rs

@@ -2,11 +2,19 @@
 
 use std::
 {
-    time::Instant,
+    time::{Duration, Instant},
 };
 
 use eframe::egui;
-use tokio::sync::mpsc;
+use tokio::{
+    fs,
+    io::{
+        AsyncWriteExt,
+        BufWriter,
+        Result,
+    },
+    sync::mpsc,
+};
 
 use crate::
 {
@@ -23,6 +31,7 @@ use crate::
 pub enum MsgToDriver
 {
     GuiNeedsRgbaFrame,
+    GuiDebugCapture (bool),
     DecodedJpegToRgba (RgbaFrame),
     NetworkWriteFinished,
     GotCapture ((Capture, JpegFrame)),
@@ -44,6 +53,7 @@ pub struct Driver
     capture: Option <Capture>,
     
     ctl: Controller,
+    debug_logger: DebugLogger,
 }
 
 pub fn sleep_ms (ms: u64)
@@ -60,13 +70,16 @@ impl Driver
         send_to_gui: mpsc::Sender <MsgToGui>,
     ) -> Self
     {
+        let now = Instant::now ();
+        
         Self {
             send,
             recv,
             gui_ctx,
             send_to_gui,
             capture: Some (Capture::new ().unwrap ()),
-            ctl: Controller::new (Instant::now ()),
+            ctl: Controller::new (now),
+            debug_logger: DebugLogger::new (now),
         }
     }
     
@@ -74,12 +87,15 @@ impl Driver
     {
         loop
         {
+            self.debug_logger.log_state (&self.ctl).await.unwrap ();
+            
             match self.recv.recv().await.unwrap ()
             {
                 MsgToDriver::GuiNeedsRgbaFrame =>
                 {
                     self.ctl.handle_gui_needs_frame ();
                 },
+                MsgToDriver::GuiDebugCapture(x) => self.debug_logger.set_enabled (x).await.unwrap (),
                 MsgToDriver::DecodedJpegToRgba (frame) =>
                 {
                     self.ctl.handle_rgba_frame (frame);
@@ -164,3 +180,98 @@ impl Driver
         }
     }
 }
+
+struct DebugLogger {
+    inner: Option <DebugLoggerInner>,
+    start_time: Instant,
+}
+
+impl DebugLogger {
+    pub fn new (start_time: Instant) -> Self {
+        Self {
+            inner: None,
+            start_time,
+        }
+    }
+    
+    pub async fn log_state (&mut self, ctl: &Controller) -> Result <()> {
+        if let Some (inner) = &mut self.inner {
+            inner.log_state(ctl).await?;
+        }
+        Ok (())
+    }
+    
+    pub async fn set_enabled (&mut self, x: bool) -> Result <()> {
+        match (&mut self.inner, x) {
+            (None, true) => {
+                let f = fs::File::create ("untracked/debug.jsonl").await?;
+                let f = BufWriter::new (f);
+                self.inner = Some (DebugLoggerInner {
+                    overhead: Default::default (),
+                    log_ops: 0,
+                    f,
+                    start_time: self.start_time,
+                });
+            },
+            (Some (inner), false) => {
+                inner.log_overhead ().await?;
+                inner.f.flush ().await?;
+                self.inner = None;
+            },
+            _ => (),
+        }
+        
+        Ok (())
+    }
+}
+
+struct DebugLoggerInner {
+    // Time spent inside the logger
+    overhead: Duration,
+    
+    // Log operations performed
+    log_ops: u32,
+    
+    // Log output file
+    f: BufWriter <fs::File>,
+    
+    // An arbitrary start time to count milliseconds from
+    start_time: Instant,
+}
+
+impl DebugLoggerInner {
+    pub async fn log_overhead (&mut self) -> Result <()> {
+        self.log_map (|me| {
+            serde_json::json! ({
+                "overhead": {
+                    "milliseconds": me.overhead.as_millis (),
+                    "ops": me.log_ops,
+                },
+            })
+        }).await
+    }
+    
+    pub async fn log_state (&mut self, ctl: &Controller) -> Result <()> {
+        self.log_map (|me| {
+            serde_json::json! ({
+                "state": ctl.to_json (me.start_time),
+            })
+        }).await
+    }
+    
+    async fn log_map <F: FnOnce (&Self) -> serde_json::Value> (&mut self, f: F) -> Result <()> {
+        let start = Instant::now ();
+        
+        let time = (start - self.start_time).as_millis ();
+        let j: serde_json::Value = f (&*self);
+        let line = serde_json::json! ([time, j]);
+        
+        self.log_ops += 1;
+        self.f.write_all (format! ("{line}\n").as_bytes ()).await?;
+        
+        let stop = Instant::now ();
+        self.overhead += stop - start;
+        
+        Ok (())
+    }
+}

src/main.rs

@@ -74,6 +74,7 @@ struct App {
     recv_at_gui: mpsc::Receiver <MsgToGui>,
     
     requesting_frames: bool,
+    debug_capture: bool,
     
     next_stat_refresh: Instant,
 }
@@ -103,6 +104,7 @@ impl App {
             send_to_ctl,
             recv_at_gui,
             requesting_frames: true,
+            debug_capture: false,
             next_stat_refresh: Instant::now (),
         }
     }
@@ -120,6 +122,7 @@ impl eframe::App for App {
             {
                 self.send_to_ctl.blocking_send (MsgToDriver::GuiNeedsRgbaFrame).unwrap ();
             }
+            self.send_to_ctl.blocking_send(MsgToDriver::GuiDebugCapture (self.debug_capture)).unwrap ();
             
             while let Ok (msg) = self.recv_at_gui.try_recv()
             {
@@ -168,6 +171,7 @@ impl eframe::App for App {
             // println! ("GUI");
             
             ui.checkbox(&mut self.requesting_frames, "Run");
+            ui.checkbox(&mut self.debug_capture, "Debug capture");
         });
     }
 }