feat(dev): add tracing feature

5 files changed, 80 insertions, 6 deletions

diff --git a/src/bin/zjstatus.rs b/src/bin/zjstatus.rs
index 07c38a0..1f0de0e 100644
--- a/src/bin/zjstatus.rs
+++ b/src/bin/zjstatus.rs
@@ -8,10 +8,13 @@ use widgets::{
     tabs::TabsWidget,
     widget::Widget,
 };
+
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
+
 use zellij_tile::prelude::*;
 
 use chrono::Local;
-use std::{collections::BTreeMap, sync::Arc, usize};
+use std::{collections::BTreeMap, fs::File, sync::Arc, usize};
 use uuid::Uuid;
 
 use zjstatus::{
@@ -31,8 +34,25 @@ struct State {
 #[cfg(not(test))]
 register_plugin!(State);
 
+#[cfg(feature = "tracing")]
+fn init_tracing() {
+    let file = File::create(".zjstatus.log");
+    let file = match file {
+        Ok(file) => file,
+        Err(error) => panic!("Error: {:?}", error),
+    };
+    let debug_log = tracing_subscriber::fmt::layer().with_writer(Arc::new(file));
+
+    tracing_subscriber::registry().with(debug_log).init();
+
+    tracing::info!("tracing initialized");
+}
+
 impl ZellijPlugin for State {
     fn load(&mut self, configuration: BTreeMap<String, String>) {
+        #[cfg(feature = "tracing")]
+        init_tracing();
+
         // we need the ReadApplicationState permission to receive the ModeUpdate and TabUpdate
         // events
         // we need the RunCommands permission to run "cargo test" in a floating window
@@ -41,6 +61,7 @@ impl ZellijPlugin for State {
             PermissionType::ChangeApplicationState,
             PermissionType::RunCommands,
         ]);
+
         subscribe(&[
             EventType::Mouse,
             EventType::ModeUpdate,
@@ -70,11 +91,16 @@ impl ZellijPlugin for State {
         };
     }
 
+    #[tracing::instrument(skip_all, fields(event_type))]
     fn update(&mut self, event: Event) -> bool {
         let mut should_render = false;
         match event {
             Event::Mouse(mouse_info) => {
+                tracing::Span::current().record("event_type", "Event::Mouse");
+                tracing::debug!(mouse = ?mouse_info);
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
 
@@ -85,7 +111,11 @@ impl ZellijPlugin for State {
                 );
             }
             Event::ModeUpdate(mode_info) => {
+                tracing::Span::current().record("event_type", "Event::ModeUpdate");
+                tracing::debug!(mode = ?mode_info.mode);
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
 
@@ -94,7 +124,11 @@ impl ZellijPlugin for State {
                 should_render = true;
             }
             Event::PaneUpdate(pane_info) => {
+                tracing::Span::current().record("event_type", "Event::PaneUpdate");
+                tracing::debug!(pane_count = ?pane_info.panes.len());
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
 
@@ -111,12 +145,23 @@ impl ZellijPlugin for State {
 
                 should_render = true;
             }
-            Event::PermissionRequestResult(_result) => {
+            Event::PermissionRequestResult(result) => {
+                tracing::Span::current().record("event_type", "Event::PermissionRequestResult");
+                tracing::debug!(result = ?result);
                 set_selectable(false);
                 self.got_permissions = true;
             }
             Event::RunCommandResult(exit_code, stdout, stderr, context) => {
+                tracing::Span::current().record("event_type", "Event::RunCommandResult");
+                tracing::debug!(
+                    exit_code = ?exit_code,
+                    stdout = ?String::from_utf8(stdout.clone()),
+                    stderr = ?String::from_utf8(stderr.clone()),
+                    context = ?context
+                );
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
                 self.state.cache_mask = UpdateEventMask::Command as u8;
@@ -144,7 +189,10 @@ impl ZellijPlugin for State {
                 }
             }
             Event::SessionUpdate(session_info, _) => {
+                tracing::Span::current().record("event_type", "Event::SessionUpdate");
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
 
@@ -166,7 +214,11 @@ impl ZellijPlugin for State {
                 should_render = true;
             }
             Event::TabUpdate(tab_info) => {
+                tracing::Span::current().record("event_type", "Event::TabUpdate");
+                tracing::debug!(tab_count = ?tab_info.len());
+
                 if !self.got_permissions {
+                    tracing::info!("no permissions");
                     return false;
                 }
 
@@ -216,5 +268,7 @@ fn register_widgets(configuration: &BTreeMap<String, String>) -> BTreeMap<String
     );
     widget_map.insert("tabs".to_owned(), Arc::new(TabsWidget::new(configuration)));
 
+    tracing::debug!("registered widgets: {:?}", widget_map.keys());
+
     widget_map
 }
diff --git a/src/border.rs b/src/border.rs
index c3f0419..f1720db 100644
--- a/src/border.rs
+++ b/src/border.rs
@@ -4,13 +4,14 @@ use crate::render::FormattedPart;
 
 const DEFAULT_CHAR: &str = "─";
 
-#[derive(Default, PartialEq)]
+#[derive(Default, PartialEq, Debug)]
 pub enum BorderPosition {
     #[default]
     Top,
     Bottom,
 }
 
+#[derive(Debug)]
 pub struct BorderConfig {
     pub enabled: bool,
     pub char: String,
diff --git a/src/config.rs b/src/config.rs
index 7b2ac47..ec1efed 100644
--- a/src/config.rs
+++ b/src/config.rs
@@ -44,7 +44,7 @@ pub fn event_mask_from_widget_name(name: &str) -> u8 {
     }
 }
 
-#[derive(Default)]
+#[derive(Default, Debug)]
 pub struct ModuleConfig {
     pub left_parts_config: String,
     pub left_parts: Vec<FormattedPart>,
@@ -326,6 +326,7 @@ impl ModuleConfig {
         )
     }
 
+    #[tracing::instrument(skip_all)]
     fn get_spacer_left(&self, output_left: &str, output_center: &str, cols: usize) -> String {
         let text_count = console::measure_text_width(output_left)
             + (console::measure_text_width(output_center) as f32 / 2.0).floor() as usize;
@@ -336,10 +337,11 @@ impl ModuleConfig {
         // count of 0 on tab creation
         let space_count = center_pos.saturating_sub(text_count);
 
-        eprintln!("space_count: {:?}", space_count);
+        tracing::debug!("space_count: {:?}", space_count);
         self.format_space.format_string(&" ".repeat(space_count))
     }
 
+    #[tracing::instrument(skip_all)]
     fn get_spacer_right(&self, output_right: &str, output_center: &str, cols: usize) -> String {
         let text_count = console::measure_text_width(output_right)
             + (console::measure_text_width(output_center) as f32 / 2.0).ceil() as usize;
@@ -350,6 +352,7 @@ impl ModuleConfig {
         // count of 0 on tab creation
         let space_count = center_pos.saturating_sub(text_count);
 
+        tracing::debug!("space_count: {:?}", space_count);
         self.format_space.format_string(&" ".repeat(space_count))
     }
 
diff --git a/src/render.rs b/src/render.rs
index c407a6a..cef70d4 100644
--- a/src/render.rs
+++ b/src/render.rs
@@ -121,15 +121,19 @@ impl FormattedPart {
         )
     }
 
+    #[tracing::instrument(skip_all)]
     pub fn format_string_with_widgets(
         &mut self,
         widgets: &BTreeMap<String, Arc<dyn Widget>>,
         state: &ZellijState,
     ) -> String {
         let skip_cache = self.cache_mask & UpdateEventMask::Always as u8 != 0;
+        
         if !skip_cache && self.cache_mask & state.cache_mask == 0 && !self.cache.is_empty() {
+            tracing::debug!(msg = "hit",  typ = "format_string", format = self.content);
             return self.cached_content.to_owned();
         }
+        tracing::debug!(msg = "miss",  typ = "format_string", format = self.content);
 
         let mut output = self.content.clone();
 
@@ -143,12 +147,22 @@ impl FormattedPart {
             }
 
             let widget_mask = event_mask_from_widget_name(widget_key_name);
-            if !skip_cache && widget_mask & state.cache_mask == 0 {
+            let skip_widget_cache = widget_mask & UpdateEventMask::Always as u8 != 0;
+            if !skip_widget_cache && widget_mask & state.cache_mask == 0 {
                 if let Some(res) = self.cache.get(widget_key) {
+                    tracing::debug!(msg = "hit",  typ = "widget", widget = widget_key);
                     output = output.replace(match_name, res);
                     continue;
                 }
             }
+            
+            tracing::debug!(
+                msg = "miss",  
+                typ = "widget", 
+                widget = widget_key, 
+                mask = widget_mask & state.cache_mask,
+                skip_cache = skip_cache,
+            );
 
             let result = match widgets.get(widget_key_name) {
                 Some(widget) => widget.process(widget_key, state),
diff --git a/src/widgets/command.rs b/src/widgets/command.rs
index b842559..05bc94a 100644
--- a/src/widgets/command.rs
+++ b/src/widgets/command.rs
@@ -121,6 +121,7 @@ fn render_dynamic_formatted_content(content: &str) -> String {
         .join("")
 }
 
+#[tracing::instrument(skip(command_config, state))]
 fn run_command_if_needed(command_config: CommandConfig, name: &str, state: &ZellijState) {
     let ts = Local::now();
     let last_run = get_timestamp_from_event_or_default(name, state, command_config.interval);
@@ -135,6 +136,7 @@ fn run_command_if_needed(command_config: CommandConfig, name: &str, state: &Zell
 
         #[allow(unused_variables)]
         let command = commandline_parser(&command_config.command);
+        tracing::debug!("Running command: {:?}", command);
         #[cfg(not(feature = "bench"))]
         run_command(
             &command.iter().map(|x| x.as_str()).collect::<Vec<&str>>(),