feature: add --debug flag for logging (#259)

Adds a `--debug` flag to aid in debugging issues.  This saves to `/tmp/bottom_debug.log`.

README.md

@@ -200,6 +200,7 @@ Run using `btm`.
     -S, --case_sensitive                       Enables case sensitivity by default.
     -c, --celsius                              Sets the temperature type to Celsius.
     -C, --config <CONFIG PATH>                 Sets the location of the config file.
+        --debug                                Enables debug logging.
     -t, --default_time_value <MS>              Default time value for graphs in ms.
         --default_widget_count <INT>           Sets the n'th selected widget type as the default.
         --default_widget_type <WIDGET TYPE>    Sets which widget type to use as the default widget.

src/app.rs

@@ -30,6 +30,7 @@ const MAX_SEARCH_LENGTH: usize = 200;
 
 /// AppConfigFields is meant to cover basic fields that would normally be set
 /// by config files or launch options.
+#[derive(Debug)]
 pub struct AppConfigFields {
     pub update_rate_in_milliseconds: u64,
     pub temperature_type: temperature::TemperatureType,
@@ -1228,6 +1229,7 @@ impl App {
             'k' => self.on_up_key(),
             'j' => self.on_down_key(),
             'f' => {
+                // FIXME: [FROZEN] Add an indicator if frozen!
                 self.is_frozen = !self.is_frozen;
                 if self.is_frozen {
                     self.data_collection.set_frozen_time();

src/app/data_farmer.rs

@@ -101,6 +101,7 @@ impl DataCollection {
     }
 
     pub fn clean_data(&mut self, max_time_millis: u64) {
+        trace!("Cleaning data.");
         let current_time = Instant::now();
 
         let mut remove_index = 0;
@@ -116,7 +117,10 @@ impl DataCollection {
     }
 
     pub fn eat_data(&mut self, harvested_data: &Data) {
+        trace!("Eating data now...");
         let harvested_time = harvested_data.last_collection_time;
+        trace!("Harvested time: {:?}", harvested_time);
+        trace!("New current instant: {:?}", self.current_instant);
         let mut new_entry = TimedData::default();
 
         // Network
@@ -166,6 +170,7 @@ impl DataCollection {
     fn eat_memory_and_swap(
         &mut self, memory: &mem::MemHarvest, swap: &mem::MemHarvest, new_entry: &mut TimedData,
     ) {
+        trace!("Eating mem and swap.");
         // Memory
         let mem_percent = match memory.mem_total_in_mb {
             0 => 0f64,
@@ -188,6 +193,7 @@ impl DataCollection {
     }
 
     fn eat_network(&mut self, network: &network::NetworkHarvest, new_entry: &mut TimedData) {
+        trace!("Eating network.");
         // FIXME [NETWORKING; CONFIG]: The ability to config this?
         // FIXME [NETWORKING]: Support bits, support switching between decimal and binary units (move the log part to conversion and switch on the fly)
         // RX
@@ -209,6 +215,7 @@ impl DataCollection {
     }
 
     fn eat_cpu(&mut self, cpu: &[cpu::CpuData], new_entry: &mut TimedData) {
+        trace!("Eating CPU.");
         // Note this only pre-calculates the data points - the names will be
         // within the local copy of cpu_harvest.  Since it's all sequential
         // it probably doesn't matter anyways.
@@ -219,6 +226,7 @@ impl DataCollection {
     }
 
     fn eat_temp(&mut self, temperature_sensors: &[temperature::TempHarvest]) {
+        trace!("Eating temps.");
         // TODO: [PO] To implement
         self.temp_harvest = temperature_sensors.to_vec();
     }
@@ -226,6 +234,7 @@ impl DataCollection {
     fn eat_disks(
         &mut self, disks: &[disks::DiskHarvest], io: &disks::IOHarvest, harvested_time: Instant,
     ) {
+        trace!("Eating disks.");
         // TODO: [PO] To implement
 
         let time_since_last_harvest = harvested_time
@@ -300,10 +309,12 @@ impl DataCollection {
     }
 
     fn eat_proc(&mut self, list_of_processes: &[processes::ProcessHarvest]) {
+        trace!("Eating proc.");
         self.process_harvest = list_of_processes.to_vec();
     }
 
     fn eat_battery(&mut self, list_of_batteries: &[battery_harvester::BatteryHarvest]) {
+        trace!("Eating batteries.");
         self.battery_harvest = list_of_batteries.to_vec();
     }
 }

src/app/data_harvester.rs

@@ -53,7 +53,7 @@ impl Default for Data {
 }
 
 impl Data {
-    pub fn first_run_cleanup(&mut self) {
+    pub fn cleanup(&mut self) {
         self.io = None;
         self.temperature_sensors = None;
         self.list_of_processes = None;
@@ -68,6 +68,7 @@ impl Data {
     }
 }
 
+#[derive(Debug)]
 pub struct DataCollector {
     pub data: Data,
     sys: System,
@@ -134,9 +135,14 @@ impl DataCollector {
             }
         }
 
+        trace!("Running first run.");
         futures::executor::block_on(self.update_data());
         std::thread::sleep(std::time::Duration::from_millis(250));
-        self.data.first_run_cleanup();
+
+        trace!("Running first run cleanup now.");
+        self.data.cleanup();
+
+        trace!("Enabled widgets to harvest: {:#?}", self.widgets_to_harvest);
     }
 
     pub fn set_collected_data(&mut self, used_widgets: UsedWidgets) {
@@ -193,6 +199,13 @@ impl DataCollector {
         // CPU
         if self.widgets_to_harvest.use_cpu {
             self.data.cpu = Some(cpu::get_cpu_data_list(&self.sys, self.show_average_cpu));
+            if log_enabled!(log::Level::Trace) {
+                if let Some(cpus) = &self.data.cpu {
+                    trace!("cpus: {:#?} results", cpus.len());
+                } else {
+                    trace!("Found no cpus.");
+                }
+            }
         }
 
         // Batteries
@@ -203,6 +216,14 @@ impl DataCollector {
                     battery_list,
                 ));
             }
+
+            if log_enabled!(log::Level::Trace) {
+                if let Some(batteries) = &self.data.list_of_batteries {
+                    trace!("batteries: {:#?} results", batteries.len());
+                } else {
+                    trace!("Found no batteries.");
+                }
+            }
         }
 
         if self.widgets_to_harvest.use_proc {
@@ -244,6 +265,14 @@ impl DataCollector {
             } {
                 self.data.list_of_processes = Some(process_list);
             }
+
+            if log_enabled!(log::Level::Trace) {
+                if let Some(processes) = &self.data.list_of_processes {
+                    trace!("processes: {:#?} results", processes.len());
+                } else {
+                    trace!("Found no processes.");
+                }
+            }
         }
 
         // Async if Heim
@@ -350,26 +379,63 @@ impl DataCollector {
             self.total_rx = net_data.total_rx;
             self.total_tx = net_data.total_tx;
             self.data.network = Some(net_data);
+            if log_enabled!(log::Level::Trace) {
+                trace!("Total rx: {:#?}", self.total_rx);
+                trace!("Total tx: {:#?}", self.total_tx);
+                if let Some(network) = &self.data.network {
+                    trace!("network rx: {:#?}", network.rx);
+                    trace!("network tx: {:#?}", network.tx);
+                } else {
+                    trace!("Could not find any networks.");
+                }
+            }
         }
 
         if let Ok(memory) = mem_res {
             self.data.memory = memory;
+            if log_enabled!(log::Level::Trace) {
+                trace!("mem: {:?} results", self.data.memory);
+            }
         }
 
         if let Ok(swap) = swap_res {
             self.data.swap = swap;
+            if log_enabled!(log::Level::Trace) {
+                trace!("swap: {:?} results", self.data.swap);
+            }
         }
 
         if let Ok(disks) = disk_res {
             self.data.disks = disks;
+            if log_enabled!(log::Level::Trace) {
+                if let Some(disks) = &self.data.disks {
+                    trace!("disks: {:#?} results", disks.len());
+                } else {
+                    trace!("Could not find any disks.");
+                }
+            }
         }
 
         if let Ok(io) = io_res {
             self.data.io = io;
+            if log_enabled!(log::Level::Trace) {
+                if let Some(io) = &self.data.io {
+                    trace!("io: {:#?} results", io.len());
+                } else {
+                    trace!("Could not find any io results.");
+                }
+            }
         }
 
         if let Ok(temp) = temp_res {
             self.data.temperature_sensors = temp;
+            if log_enabled!(log::Level::Trace) {
+                if let Some(sensors) = &self.data.temperature_sensors {
+                    trace!("temp: {:#?} results", sensors.len());
+                } else {
+                    trace!("Could not find any temp sensors.");
+                }
+            }
         }
 
         // Update time

src/app/layout_manager.rs

@@ -968,7 +968,7 @@ Supported widget names:
     }
 }
 
-#[derive(Clone, Default)]
+#[derive(Clone, Default, Debug)]
 pub struct UsedWidgets {
     pub use_cpu: bool,
     pub use_mem: bool,

src/bin/main.rs

@@ -26,11 +26,16 @@ use crossterm::{
 use tui::{backend::CrosstermBackend, Terminal};
 
 fn main() -> Result<()> {
-    #[cfg(debug_assertions)]
-    {
-        utils::logging::init_logger()?;
-    }
     let matches = clap::get_matches();
+    let is_debug = matches.is_present("debug");
+    if is_debug {
+        utils::logging::init_logger(log::LevelFilter::Trace, "/tmp/bottom_debug.log")?;
+    } else {
+        #[cfg(debug_assertions)]
+        {
+            utils::logging::init_logger(log::LevelFilter::Debug, "debug.log")?;
+        }
+    }
 
     let config_path = read_config(matches.value_of("config_location"))
         .context("Unable to access the given config file location.")?;
@@ -109,6 +114,13 @@ fn main() -> Result<()> {
 
     while !is_terminated.load(Ordering::SeqCst) {
         if let Ok(recv) = receiver.recv_timeout(Duration::from_millis(TICK_RATE_IN_MILLISECONDS)) {
+            if log_enabled!(log::Level::Trace) {
+                if let BottomEvent::Update(_) = recv {
+                    trace!("Main/drawing thread received Update event.");
+                } else {
+                    trace!("Main/drawing thread received event: {:#?}", recv);
+                }
+            }
             match recv {
                 BottomEvent::KeyInput(event) => {
                     if handle_key_event_or_break(event, &mut app, &reset_sender) {
@@ -203,9 +215,10 @@ fn main() -> Result<()> {
         }
 
         // TODO: [OPT] Should not draw if no change (ie: scroll max)
-        try_drawing(&mut terminal, &mut app, &mut painter)?;
+        try_drawing(&mut terminal, &mut app, &mut painter, is_debug)?;
     }
 
-    cleanup_terminal(&mut terminal)?;
+    trace!("Main/drawing thread is cleaning up.");
+    cleanup_terminal(&mut terminal, is_debug)?;
     Ok(())
 }

src/clap.rs

@@ -81,6 +81,13 @@ custom layouts.\n\n",
             "\
 When searching for a process, enables case sensitivity by default.\n\n",
         );
+    let debug = Arg::with_name("debug")
+        .long("debug")
+        .help("Enables debug logging.")
+        .long_help(
+            "\
+Enables debug logging to /tmp/bottom_debug.log.",
+        );
     let disable_click = Arg::with_name("disable_click")
         .long("disable_click")
         .help("Disables mouse clicks.")
@@ -305,6 +312,7 @@ The minimum is 1s (1000), and defaults to 15s (15000).\n\n\n",
         .arg(battery)
         .arg(case_sensitive)
         .arg(config_location)
+        .arg(debug)
         .arg(default_time_value)
         .arg(default_widget_count)
         .arg(default_widget_type)

src/lib.rs

@@ -48,6 +48,7 @@ pub type Pid = usize;
 #[cfg(target_family = "unix")]
 pub type Pid = libc::pid_t;
 
+#[derive(Debug)]
 pub enum BottomEvent<I, J> {
     KeyInput(I),
     MouseInput(J),
@@ -55,6 +56,7 @@ pub enum BottomEvent<I, J> {
     Clean,
 }
 
+#[derive(Debug)]
 pub enum CollectionThreadEvent {
     Reset,
     UpdateConfig(Box<app::AppConfigFields>),
@@ -229,10 +231,10 @@ pub fn create_or_get_config(config_path: &Option<PathBuf>) -> error::Result<Conf
 
 pub fn try_drawing(
     terminal: &mut tui::terminal::Terminal<tui::backend::CrosstermBackend<std::io::Stdout>>,
-    app: &mut App, painter: &mut canvas::Painter,
+    app: &mut App, painter: &mut canvas::Painter, is_debug: bool,
 ) -> error::Result<()> {
     if let Err(err) = painter.draw_data(terminal, app) {
-        cleanup_terminal(terminal)?;
+        cleanup_terminal(terminal, is_debug)?;
         return Err(err);
     }
 
@@ -241,6 +243,7 @@ pub fn try_drawing(
 
 pub fn cleanup_terminal(
     terminal: &mut tui::terminal::Terminal<tui::backend::CrosstermBackend<std::io::Stdout>>,
+    is_debug: bool,
 ) -> error::Result<()> {
     disable_raw_mode()?;
     execute!(
@@ -250,6 +253,10 @@ pub fn cleanup_terminal(
     )?;
     terminal.show_cursor()?;
 
+    if is_debug {
+        println!("Your debug file is located at \"/tmp/bottom_debug.log\".",);
+    }
+
     Ok(())
 }
 
@@ -556,18 +563,23 @@ pub fn create_input_thread(
         BottomEvent<crossterm::event::KeyEvent, crossterm::event::MouseEvent>,
     >,
 ) {
+    trace!("Creating input thread.");
     thread::spawn(move || {
+        trace!("Spawned input thread.");
         let mut mouse_timer = Instant::now();
         let mut keyboard_timer = Instant::now();
 
         loop {
+            trace!("Waiting for an input event...");
             if poll(Duration::from_millis(20)).is_ok() {
                 if let Ok(event) = read() {
+                    trace!("Input thread received an event: {:?}", event);
                     if let Event::Key(key) = event {
                         if Instant::now().duration_since(keyboard_timer).as_millis() >= 20 {
                             if sender.send(BottomEvent::KeyInput(key)).is_err() {
                                 break;
                             }
+                            trace!("Input thread sent data.");
                             keyboard_timer = Instant::now();
                         }
                     } else if let Event::Mouse(mouse) = event {
@@ -575,6 +587,7 @@ pub fn create_input_thread(
                             if sender.send(BottomEvent::MouseInput(mouse)).is_err() {
                                 break;
                             }
+                            trace!("Input thread sent data.");
                             mouse_timer = Instant::now();
                         }
                     }
@@ -591,12 +604,14 @@ pub fn create_collection_thread(
     reset_receiver: std::sync::mpsc::Receiver<CollectionThreadEvent>,
     app_config_fields: &app::AppConfigFields, used_widget_set: UsedWidgets,
 ) {
+    trace!("Creating collection thread.");
     let temp_type = app_config_fields.temperature_type.clone();
     let use_current_cpu_total = app_config_fields.use_current_cpu_total;
     let show_average_cpu = app_config_fields.show_average_cpu;
     let update_rate_in_milliseconds = app_config_fields.update_rate_in_milliseconds;
 
     thread::spawn(move || {
+        trace!("Spawned collection thread.");
         let mut data_state = data_harvester::DataCollector::default();
         data_state.set_collected_data(used_widget_set);
         data_state.set_temperature_type(temp_type);
@@ -605,11 +620,13 @@ pub fn create_collection_thread(
 
         data_state.init();
         loop {
+            trace!("Collecting...");
             let mut update_time = update_rate_in_milliseconds;
             if let Ok(message) = reset_receiver.try_recv() {
+                trace!("Received message: {:?}", message);
                 match message {
                     CollectionThreadEvent::Reset => {
-                        data_state.data.first_run_cleanup();
+                        data_state.data.cleanup();
                     }
                     CollectionThreadEvent::UpdateConfig(app_config_fields) => {
                         data_state.set_temperature_type(app_config_fields.temperature_type.clone());
@@ -626,11 +643,14 @@ pub fn create_collection_thread(
                 }
             }
             futures::executor::block_on(data_state.update_data());
+            trace!("Collection thread is updating...");
             let event = BottomEvent::Update(Box::from(data_state.data));
+            trace!("Collection thread done updating.  Sending data now...");
             data_state.data = data_harvester::Data::default();
             if sender.send(event).is_err() {
                 break;
             }
+            trace!("No problem sending from collection thread!");
             thread::sleep(Duration::from_millis(update_time));
         }
     });

src/utils/logging.rs

@@ -1,5 +1,6 @@
-#[cfg(debug_assertions)]
+pub fn init_logger(
-pub fn init_logger() -> Result<(), fern::InitError> {
+    min_level: log::LevelFilter, debug_file_name: &str,
+) -> Result<(), fern::InitError> {
     fern::Dispatch::new()
         .format(|out, message, record| {
             out.finish(format_args!(
@@ -10,12 +11,8 @@ pub fn init_logger() -> Result<(), fern::InitError> {
                 message
             ))
         })
-        .level(if cfg!(debug_assertions) {
+        .level(min_level)
-            log::LevelFilter::Debug
+        .chain(fern::log_file(debug_file_name)?)
-        } else {
-            log::LevelFilter::Info
-        })
-        .chain(fern::log_file("debug.log")?)
         .apply()?;
 
     Ok(())