diff --git a/components/monitors/cu_consolemon/Cargo.toml b/components/monitors/cu_consolemon/Cargo.toml index a0bfbb0fd..a53cf7051 100644 --- a/components/monitors/cu_consolemon/Cargo.toml +++ b/components/monitors/cu_consolemon/Cargo.toml @@ -10,8 +10,14 @@ categories.workspace = true homepage.workspace = true repository.workspace = true +[features] +default = ["debug_pane"] +# Enables 'Debug Output' Pane +debug_pane = ["dep:log", "dep:chrono", "dep:dashmap"] + [dependencies] cu29 = { workspace = true } +cu29-log-runtime = { workspace = true } compact_str = { workspace = true } ratatui = "0.29" pfetch-logo-parser = "0.1" @@ -23,3 +29,6 @@ tui-nodes = "0.8" tui-widgets = "0.4" # 0.4.0 brings ratatui 0.29 color-eyre = "0.6" gag = "1.0.0" +log = { version = "0.4", optional = true } +chrono = { version = "0.4", optional = true } +dashmap = { version = "6.1", optional = true } \ No newline at end of file diff --git a/components/monitors/cu_consolemon/README.md b/components/monitors/cu_consolemon/README.md index ffc7a927a..e06c8937f 100644 --- a/components/monitors/cu_consolemon/README.md +++ b/components/monitors/cu_consolemon/README.md @@ -35,11 +35,14 @@ And in you copperconfig.ron: ``` -The monitor has 3 screens: +The monitor has 4 screens: - **SysInfo**: A quick system information screen (CPU, Memory, Distrib ...) - **DAG**: A Directed Acyclic Graph of the tasks with their real time error status and short string info. - **Latencies**: A list of the tasks with their real time latencies & assorted statistics (Jitter, Min, Max, Avg). +- **Debug Output** [`debug_pane`](#debug_pane-feature): A pane that displays debug logs in real-time. +## `debug_pane` feature - +Enabled by default. Disable with `default-features = false`. Displays real-time logs +from [log](https://crates.io/crates/log), [cu29-log](https://crates.io/crates/cu29-log) and `stderr`. diff --git a/components/monitors/cu_consolemon/src/lib.rs b/components/monitors/cu_consolemon/src/lib.rs index d724e85d7..a4fce84eb 100644 --- a/components/monitors/cu_consolemon/src/lib.rs +++ b/components/monitors/cu_consolemon/src/lib.rs @@ -8,7 +8,6 @@ use cu29::config::{CuConfig, Node}; use cu29::cutask::CuMsgMetadata; use cu29::monitoring::{CuDurationStatistics, CuMonitor, CuTaskState, Decision}; use cu29::{CuError, CuResult}; -use gag::Gag; use ratatui::backend::CrosstermBackend; use ratatui::buffer::Buffer; use ratatui::crossterm::event::{DisableMouseCapture, EnableMouseCapture, Event, KeyCode}; @@ -33,11 +32,28 @@ use std::{io, thread}; use tui_nodes::{Connection, NodeGraph, NodeLayout}; use tui_widgets::scrollview::{ScrollView, ScrollViewState}; +#[cfg(feature = "debug_pane")] +use { + compact_str::CompactStringExt, + log::{Level, LevelFilter, Log, Metadata, Record}, + std::collections::VecDeque, + std::io::Read, + std::sync::atomic::AtomicU16, + std::sync::mpsc::{Receiver, SyncSender}, +}; + +#[cfg(feature = "debug_pane")] +const MENU_CONTENT: &str = " [1] SysInfo [2] DAG [3] Latencies [4] Debug Output [q] Quit "; +#[cfg(not(feature = "debug_pane"))] +const MENU_CONTENT: &str = " [1] SysInfo [2] DAG [3] Latencies [q] Quit "; + #[derive(PartialEq)] enum Screen { Neofetch, Dag, Latency, + #[cfg(feature = "debug_pane")] + DebugOutput, } struct TaskStats { @@ -282,18 +298,141 @@ struct UI { sysinfo: String, task_stats: Arc>, nodes_scrollable_widget_state: NodesScrollableWidgetState, + #[cfg(feature = "debug_pane")] + error_redirect: gag::BufferRedirect, + #[cfg(feature = "debug_pane")] + debug_output: DebugLog, +} + +#[cfg(feature = "debug_pane")] +struct DebugLog { + debug_log: VecDeque, + max_rows: AtomicU16, + rx: Receiver, +} + +#[cfg(feature = "debug_pane")] +impl DebugLog { + fn new(max_lines: u16) -> (Self, SyncSender) { + let (tx, rx) = std::sync::mpsc::sync_channel(1000); + ( + Self { + debug_log: VecDeque::new(), + max_rows: AtomicU16::new(max_lines), + rx, + }, + tx, + ) + } + + fn push_logs(&mut self, logs: String) { + if logs.is_empty() { + return; + } + + self.debug_log.push_back(logs); + let max_row = self.max_rows.load(Ordering::SeqCst) as usize; + while self.debug_log.len() > max_row { + self.debug_log.pop_front(); + } + } + + fn update_logs(&mut self) { + let max_row = self.max_rows.load(Ordering::SeqCst) as usize; + + for log in self.rx.try_iter() { + if log.is_empty() { + continue; + } + + self.debug_log.push_back(log); + if self.debug_log.len() > max_row { + self.debug_log.pop_front(); + } + } + } + + fn get_logs(&mut self) -> String { + self.update_logs(); + self.debug_log.join_compact("").to_string() + } +} + +#[cfg(feature = "debug_pane")] +#[derive(Clone)] +struct LogSubscriber { + tx: SyncSender, +} + +#[cfg(feature = "debug_pane")] +impl LogSubscriber { + fn new(tx: SyncSender) -> Self { + let log_subscriber = Self { tx }; + log::set_boxed_logger(Box::new(log_subscriber.clone())).unwrap(); + log::set_max_level(LevelFilter::Info); + log_subscriber + } + + fn push_logs(&self, log: String) { + if let Err(err) = self.tx.send(log) { + eprintln!("Error Sending Logs to MPSC Channel: {}", err.0) + } + } +} + +#[cfg(feature = "debug_pane")] +impl Log for LogSubscriber { + fn enabled(&self, metadata: &Metadata) -> bool { + metadata.level() <= Level::Debug + } + + fn log(&self, record: &Record) { + if self.enabled(record.metadata()) { + let message = format!("[{}] - {}\n", record.level(), record.args()); + + self.push_logs(message); + } + } + + fn flush(&self) {} } impl UI { + #[cfg(feature = "debug_pane")] fn new( config: CuConfig, task_ids: &'static [&'static str], task_stats: Arc>, task_statuses: Arc>>, + error_redirect: gag::BufferRedirect, + debug_output: DebugLog, ) -> UI { init_error_hooks(); let nodes_scrollable_widget_state = NodesScrollableWidgetState::new(&config, task_statuses.clone()); + + Self { + task_ids, + active_screen: Screen::Neofetch, + sysinfo: sysinfo::pfetch_info(), + task_stats, + nodes_scrollable_widget_state, + error_redirect, + debug_output, + } + } + + #[cfg(not(feature = "debug_pane"))] + fn new( + config: CuConfig, + task_ids: &'static [&'static str], + task_stats: Arc>, + task_statuses: Arc>>, + ) -> UI { + init_error_hooks(); + let nodes_scrollable_widget_state = + NodesScrollableWidgetState::new(&config, task_statuses.clone()); + Self { task_ids, active_screen: Screen::Neofetch, @@ -431,6 +570,25 @@ impl UI { ) } + #[cfg(feature = "debug_pane")] + fn draw_debug_output(&mut self, f: &mut Frame, area: Rect) { + let mut error_buffer = String::new(); + self.error_redirect + .read_to_string(&mut error_buffer) + .unwrap(); + self.debug_output.push_logs(error_buffer); + + let debug_output = self.debug_output.get_logs(); + + let p = Paragraph::new(debug_output).block( + Block::default() + .title(" Debug Output ") + .title_bottom(format!("{} log entries", self.debug_output.debug_log.len())) + .borders(Borders::ALL), + ); + f.render_widget(p, area); + } + fn draw(&mut self, f: &mut Frame) { let layout = Layout::default() .direction(Direction::Vertical) @@ -443,7 +601,7 @@ impl UI { ) .split(f.area()); - let menu = Paragraph::new(" [1] SysInfo [2] DAG [3] Latencies [q] Quit") + let menu = Paragraph::new(MENU_CONTENT) .style( Style::default() .fg(Color::Yellow) @@ -469,6 +627,8 @@ impl UI { self.draw_nodes(f, layout[1]); } Screen::Latency => self.draw_latency_table(f, layout[1]), + #[cfg(feature = "debug_pane")] + Screen::DebugOutput => self.draw_debug_output(f, layout[1]), }; } @@ -484,6 +644,8 @@ impl UI { KeyCode::Char('1') => self.active_screen = Screen::Neofetch, KeyCode::Char('2') => self.active_screen = Screen::Dag, KeyCode::Char('3') => self.active_screen = Screen::Latency, + #[cfg(feature = "debug_pane")] + KeyCode::Char('4') => self.active_screen = Screen::DebugOutput, KeyCode::Char('r') => { if self.active_screen == Screen::Latency { self.task_stats.lock().unwrap().reset() @@ -531,6 +693,11 @@ impl UI { _ => {} } } + + #[cfg(feature = "debug_pane")] + if let Event::Resize(_columns, rows) = event::read()? { + self.debug_output.max_rows.store(rows, Ordering::SeqCst) + } } } Ok(()) @@ -570,16 +737,52 @@ impl CuMonitor for CuConsoleMon { setup_terminal(); - // nukes stderr into orbit as anything in the stack can corrupt the terminal - let print_gag = Gag::stderr().unwrap(); - let mut terminal = Terminal::new(backend).expect("Failed to initialize terminal backend"); - let mut ui = UI::new(config_dup, taskids, task_stats_ui, error_states); - ui.run_app(&mut terminal).expect("Failed to run app"); + + #[cfg(feature = "debug_pane")] + { + let max_lines = terminal.size().unwrap().height - 5; + let (debug_log, tx) = DebugLog::new(max_lines); + + // redirect stderr, so it doesn't pop in the terminal + let error_redirect = gag::BufferRedirect::stderr().unwrap(); + + let mut ui = UI::new( + config_dup, + taskids, + task_stats_ui, + error_states, + error_redirect, + debug_log, + ); + + #[allow(unused_variables)] + let log_subscriber = LogSubscriber::new(tx); + + // Override the cu29-log-runtime Log Subscriber + #[cfg(debug_assertions)] + if cu29_log_runtime::EXTRA_TEXT_LOGGER + .set(Some(Box::new(log_subscriber) as Box)).is_err() + { + eprintln!("Failed to override default log subscriber of cu29-log-runtime\nIf you are using `basic_copper_setup` function provided by `cu29-helper` crate, please pass `monitor_subscriber` as true"); + } + + ui.run_app(&mut terminal).expect("Failed to run app"); + } + + #[cfg(not(feature = "debug_pane"))] + { + let stderr_gag = gag::Gag::stderr().unwrap(); + + let mut ui = UI::new(config_dup, taskids, task_stats_ui, error_states); + ui.run_app(&mut terminal).expect("Failed to run app"); + + drop(stderr_gag); + } + quitting.store(true, Ordering::SeqCst); // restoring the terminal - drop(print_gag); restore_terminal(); }); diff --git a/core/cu29_helpers/src/lib.rs b/core/cu29_helpers/src/lib.rs index 4b5153684..a01f1e103 100644 --- a/core/cu29_helpers/src/lib.rs +++ b/core/cu29_helpers/src/lib.rs @@ -21,12 +21,14 @@ use std::sync::{Arc, Mutex}; /// It will create a LoggerRuntime that can be used as a robot clock source too. /// /// slab_size: The logger will pre-allocate large files of those sizes. With the name of the given file _0, _1 etc. +/// monitor_subscriber -> true means that `cu-consolemon` will be subscribed to the LogRuntime /// clock: if you let it to None it will create a default clock otherwise you can provide your own, for example a simulation clock. /// with let (clock , mock) = RobotClock::mock(); pub fn basic_copper_setup( unifiedlogger_output_base_name: &Path, slab_size: Option, _text_log: bool, + monitor_subscriber: bool, clock: Option, ) -> CuResult { let preallocated_size = slab_size.unwrap_or(1024 * 1024 * 10); @@ -64,7 +66,8 @@ pub fn basic_copper_setup( let extra: Option = None; let clock = clock.unwrap_or_default(); - let structured_logging = LoggerRuntime::init(clock.clone(), structured_stream, extra); + let structured_logging = + LoggerRuntime::init(clock.clone(), structured_stream, monitor_subscriber, extra); Ok(CopperContext { unified_logger: unified_logger.clone(), logger_runtime: structured_logging, diff --git a/core/cu29_log_runtime/src/lib.rs b/core/cu29_log_runtime/src/lib.rs index 31023b55b..d2fe3a89d 100644 --- a/core/cu29_log_runtime/src/lib.rs +++ b/core/cu29_log_runtime/src/lib.rs @@ -36,7 +36,7 @@ type WriterPair = (Mutex, RobotClock); static WRITER: OnceLock = OnceLock::new(); #[cfg(debug_assertions)] -static EXTRA_TEXT_LOGGER: OnceLock>> = OnceLock::new(); +pub static EXTRA_TEXT_LOGGER: OnceLock>> = OnceLock::new(); pub struct NullLog {} impl Log for NullLog { @@ -53,10 +53,12 @@ pub struct LoggerRuntime {} impl LoggerRuntime { /// destination is the binary stream in which we will log the structured log. - /// extra_text_logger is the logger that will log the text logs in real time. This is slow and only for debug builds. + /// `extra_text_logger` is the logger that will log the text logs in real time. This is slow and only for debug builds. + /// `custom_logger`, if true _(only in `dev` profile)_ will not set `extra_text_logger` and will allow you to set the same using [EXTRA_TEXT_LOGGER] pub fn init( clock: RobotClock, destination: impl WriteStream + 'static, + #[allow(unused_variables)] custom_logger: bool, #[allow(unused_variables)] extra_text_logger: Option, ) -> Self { let runtime = LoggerRuntime {}; @@ -72,8 +74,10 @@ impl LoggerRuntime { .unwrap(); } #[cfg(debug_assertions)] - let _ = - EXTRA_TEXT_LOGGER.set(extra_text_logger.map(|logger| Box::new(logger) as Box)); + if !custom_logger { + let _ = EXTRA_TEXT_LOGGER + .set(extra_text_logger.map(|logger| Box::new(logger) as Box)); + } runtime } diff --git a/examples/cu_caterpillar/src/main.rs b/examples/cu_caterpillar/src/main.rs index e83de34a5..44946f4b5 100644 --- a/examples/cu_caterpillar/src/main.rs +++ b/examples/cu_caterpillar/src/main.rs @@ -12,8 +12,9 @@ fn main() { let tmp_dir = tempfile::TempDir::new().expect("could not create a tmp dir"); let logger_path = tmp_dir.path().join("caterpillar.copper"); - let copper_ctx = - basic_copper_setup(&logger_path, SLAB_SIZE, false, None).expect("Failed to setup logger."); + let copper_ctx = basic_copper_setup(&logger_path, SLAB_SIZE, false, true, None) + .expect("Failed to setup logger."); + let mut application = CaterpillarApplicationBuilder::new() .with_context(&copper_ctx) .build() diff --git a/examples/cu_config_variation/src/main.rs b/examples/cu_config_variation/src/main.rs index 9cd40f7f1..be75d293d 100644 --- a/examples/cu_config_variation/src/main.rs +++ b/examples/cu_config_variation/src/main.rs @@ -7,7 +7,7 @@ struct MyApp {} fn main() { let mut copperconfig: CuConfig = read_configuration("copperconfig.ron").unwrap(); - let copper_ctx = basic_copper_setup(Path::new("/tmp/test.copper"), None, true, None) + let copper_ctx = basic_copper_setup(Path::new("/tmp/test.copper"), None, true, false, None) .expect("Failed to setup logger."); // First run with the base configuration diff --git a/examples/cu_iceoryx2/src/bin/downstream.rs b/examples/cu_iceoryx2/src/bin/downstream.rs index 63569e112..43faf7766 100644 --- a/examples/cu_iceoryx2/src/bin/downstream.rs +++ b/examples/cu_iceoryx2/src/bin/downstream.rs @@ -12,7 +12,7 @@ fn main() { // the iceoryx logger does break if you attach a debugger to it. set_log_level(LogLevel::Fatal); let logger_path = "/tmp/downstream.copper"; - let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, None) + let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, true, None) .expect("Failed to setup logger."); let mut application = DownstreamApplicationBuilder::new() .with_context(&copper_ctx) diff --git a/examples/cu_iceoryx2/src/bin/upstream.rs b/examples/cu_iceoryx2/src/bin/upstream.rs index 3777e8d76..c8726b6b4 100644 --- a/examples/cu_iceoryx2/src/bin/upstream.rs +++ b/examples/cu_iceoryx2/src/bin/upstream.rs @@ -9,7 +9,7 @@ const SLAB_SIZE: Option = Some(100 * 1024 * 1024); fn main() { let logger_path = "/tmp/upstream.copper"; - let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, None) + let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, true, None) .expect("Failed to setup logger."); let mut application = UpstreamApplicationBuilder::new() .with_context(&copper_ctx) diff --git a/examples/cu_logging_size/src/main.rs b/examples/cu_logging_size/src/main.rs index 195ca6b88..75e792dbc 100644 --- a/examples/cu_logging_size/src/main.rs +++ b/examples/cu_logging_size/src/main.rs @@ -82,8 +82,8 @@ fn main() { let dir = tempdir().expect("Could not get a temporary directory"); // construct dir/logger_path let logger_path = dir.path().join(logger_path); - let copper_ctx = - basic_copper_setup(&logger_path, SLAB_SIZE, true, None).expect("Failed to setup logger."); + let copper_ctx = basic_copper_setup(&logger_path, SLAB_SIZE, true, false, None) + .expect("Failed to setup logger."); debug!("Logger created at {}.", path = &logger_path); let clock = copper_ctx.clock; debug!("Creating application... "); diff --git a/examples/cu_monitoring/src/main.rs b/examples/cu_monitoring/src/main.rs index f843e76f0..010fbf51b 100644 --- a/examples/cu_monitoring/src/main.rs +++ b/examples/cu_monitoring/src/main.rs @@ -115,7 +115,7 @@ const SLAB_SIZE: Option = Some(1024 * 1024); fn main() { let logger_path = "monitor.copper"; - let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, true, None) + let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, true, true, None) .expect("Failed to setup logger."); debug!("Logger created at {}.", path = logger_path); debug!("Creating application... "); diff --git a/examples/cu_multisources/src/main.rs b/examples/cu_multisources/src/main.rs index b5f264ade..0760b9157 100644 --- a/examples/cu_multisources/src/main.rs +++ b/examples/cu_multisources/src/main.rs @@ -13,7 +13,7 @@ const SLAB_SIZE: Option = Some(1024 * 1024); fn main() { let logger_path = "/tmp/caterpillar.copper"; - let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, true, None) + let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, true, true, None) .expect("Failed to setup logger."); debug!("Logger created at {}.", path = logger_path); debug!("Creating application... "); diff --git a/examples/cu_pointclouds/src/main.rs b/examples/cu_pointclouds/src/main.rs index 2a28a3c6c..cbbe6debd 100644 --- a/examples/cu_pointclouds/src/main.rs +++ b/examples/cu_pointclouds/src/main.rs @@ -53,8 +53,8 @@ fn main() { const PACKET_SIZE: usize = size_of::(); let tmp_dir = tempfile::TempDir::new().expect("could not create a tmp dir"); let logger_path = tmp_dir.path().join("ptclouds.copper"); - let copper_ctx = - basic_copper_setup(&logger_path, SLAB_SIZE, false, None).expect("Failed to setup copper."); + let copper_ctx = basic_copper_setup(&logger_path, SLAB_SIZE, false, false, None) + .expect("Failed to setup copper."); let mut application = PtCloudsApplicationBuilder::new() .with_context(&copper_ctx) .build() diff --git a/examples/cu_rp_balancebot/src/main.rs b/examples/cu_rp_balancebot/src/main.rs index fa5ac4f86..1af7cfa0f 100644 --- a/examples/cu_rp_balancebot/src/main.rs +++ b/examples/cu_rp_balancebot/src/main.rs @@ -22,7 +22,7 @@ fn main() { } } - let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, None) + let copper_ctx = basic_copper_setup(&PathBuf::from(logger_path), SLAB_SIZE, false, false, None) .expect("Failed to setup logger."); debug!("Logger created at {}.", path = logger_path); diff --git a/examples/cu_rp_balancebot/src/resim.rs b/examples/cu_rp_balancebot/src/resim.rs index 81e1ce79a..ff2af959c 100644 --- a/examples/cu_rp_balancebot/src/resim.rs +++ b/examples/cu_rp_balancebot/src/resim.rs @@ -83,6 +83,7 @@ fn main() { &PathBuf::from(logger_path), LOG_SLAB_SIZE, false, + false, Some(robot_clock.clone()), ) .expect("Failed to setup logger."); diff --git a/examples/cu_rp_balancebot/src/sim.rs b/examples/cu_rp_balancebot/src/sim.rs index 0b71c6be9..90f5d39e8 100644 --- a/examples/cu_rp_balancebot/src/sim.rs +++ b/examples/cu_rp_balancebot/src/sim.rs @@ -63,6 +63,7 @@ fn setup_copper(mut commands: Commands) { &PathBuf::from(logger_path), LOG_SLAB_SIZE, false, + false, Some(robot_clock.clone()), ) .expect("Failed to setup logger."); diff --git a/examples/cu_standalone_structlog/src/structlog_perf.rs b/examples/cu_standalone_structlog/src/structlog_perf.rs index 42aa8a889..40891784f 100644 --- a/examples/cu_standalone_structlog/src/structlog_perf.rs +++ b/examples/cu_standalone_structlog/src/structlog_perf.rs @@ -8,7 +8,7 @@ fn main() { let clock = RobotClock::new(); let bf = { let writer = SimpleFileWriter::new(&PathBuf::from(LOG_FILE)).unwrap(); - let _log_runtime = LoggerRuntime::init(clock.clone(), writer, None::); + let _log_runtime = LoggerRuntime::init(clock.clone(), writer, false, None::); let bf: CuTime = clock.now(); for i in 0..1_000_000 { debug!(