diff --git a/.gitignore b/.gitignore index 38fa69c..d866240 100644 --- a/.gitignore +++ b/.gitignore @@ -1,2 +1,3 @@ /deps /target +/untracked diff --git a/Cargo.lock b/Cargo.lock index 338bd9c..8c878a8 100644 --- a/Cargo.lock +++ b/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" diff --git a/Cargo.toml b/Cargo.toml index e6918ea..23a8a62 100644 --- a/Cargo.toml +++ b/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" } diff --git a/src/controller.rs b/src/controller.rs index c045d54..611445e 100644 --- a/src/controller.rs +++ b/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 (), + }) + } } diff --git a/src/driver.rs b/src/driver.rs index fc8d5f7..cdd5900 100644 --- a/src/driver.rs +++ b/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 , ctl: Controller, + debug_logger: DebugLogger, } pub fn sleep_ms (ms: u64) @@ -60,13 +70,16 @@ impl Driver send_to_gui: mpsc::Sender , ) -> 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 , + 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 , + + // 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 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 (()) + } +} diff --git a/src/main.rs b/src/main.rs index 2aab6bc..37f38a6 100644 --- a/src/main.rs +++ b/src/main.rs @@ -74,6 +74,7 @@ struct App { recv_at_gui: mpsc::Receiver , 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"); }); } }