Merge pull request #25 from LAPKB/tui-logs

Reworked terminal user interface (TUI) and logging using `tracing`

src/algorithms.rs

@@ -1,4 +1,4 @@
-use crate::prelude::{self, output::NPCycle, settings::run::Data};
+use crate::prelude::{self, settings::run::Data};
 
 use output::NPResult;
 use prelude::{datafile::Scenario, *};
@@ -22,7 +22,7 @@ pub fn initialize_algorithm<S>(
     engine: Engine<S>,
     settings: Data,
     scenarios: Vec<Scenario>,
-    tx: mpsc::UnboundedSender<NPCycle>,
+    tx: mpsc::UnboundedSender<Comm>,
 ) -> Box<dyn Algorithm>
 where
     S: Predict<'static> + std::marker::Sync + Clone + 'static,

src/algorithms/npag.rs

@@ -1,15 +1,18 @@
-use crate::prelude::{
-    algorithms::Algorithm,
-    datafile::Scenario,
-    evaluation::sigma::{ErrorPoly, ErrorType},
-    ipm,
-    optimization::expansion::adaptative_grid,
-    output::NPResult,
-    output::{CycleLog, NPCycle},
-    prob, qr,
-    settings::run::Data,
-    simulation::predict::Engine,
-    simulation::predict::{sim_obs, Predict},
+use crate::{
+    prelude::{
+        algorithms::Algorithm,
+        datafile::Scenario,
+        evaluation::sigma::{ErrorPoly, ErrorType},
+        ipm,
+        optimization::expansion::adaptative_grid,
+        output::NPResult,
+        output::{CycleLog, NPCycle},
+        prob, qr,
+        settings::run::Data,
+        simulation::predict::Engine,
+        simulation::predict::{sim_obs, Predict},
+    },
+    tui::ui::Comm,
 };
 
 use ndarray::{Array, Array1, Array2, Axis};
@@ -45,7 +48,7 @@ where
     cache: bool,
     scenarios: Vec<Scenario>,
     c: (f64, f64, f64, f64),
-    tx: UnboundedSender<NPCycle>,
+    tx: UnboundedSender<Comm>,
     settings: Data,
 }
 
@@ -95,7 +98,7 @@ where
         theta: Array2<f64>,
         scenarios: Vec<Scenario>,
         c: (f64, f64, f64, f64),
-        tx: UnboundedSender<NPCycle>,
+        tx: UnboundedSender<Comm>,
         settings: Data,
     ) -> Self
     where
@@ -196,8 +199,9 @@ where
     pub fn run(&mut self) -> NPResult {
         while self.eps > THETA_E {
             // Enter a span for each cycle, provding context for further errors
-            let cycle_span = tracing::span!(tracing::Level::INFO, "Cycle", cycle = self.cycle);
+            let cycle_span = tracing::span!(tracing::Level::INFO, "Cycle",  cycle = self.cycle);
             let _enter = cycle_span.enter();
+
             // psi n_sub rows, nspp columns
             let cache = if self.cycle == 1 { false } else { self.cache };
             let ypred = sim_obs(&self.engine, &self.scenarios, &self.theta, cache);
@@ -246,9 +250,8 @@ where
             // If a support point is dropped, log it
             if self.psi.ncols() != keep.len() {
                 tracing::info!(
-                    "QR decomposition dropped {} SPP, kept {}",
+                    "QRD dropped {} support point(s)",
                     self.psi.ncols() - keep.len(),
-                    keep.len(),
                 );
             }
 
@@ -265,16 +268,15 @@ where
 
             self.optim_gamma();
 
-            let mut state = NPCycle {
+            let state = NPCycle {
                 cycle: self.cycle,
                 objf: -2. * self.objf,
                 delta_objf: (self.last_objf - self.objf).abs(),
                 nspp: self.theta.shape()[0],
-                stop_text: "".to_string(),
                 theta: self.theta.clone(),
                 gamlam: self.gamma,
             };
-            self.tx.send(state.clone()).unwrap();
+            self.tx.send(Comm::NPCycle(state.clone())).unwrap();
 
             // Increasing objf signals instability or model misspecification.
             if self.last_objf > self.objf {
@@ -294,10 +296,8 @@ where
                 if self.eps <= THETA_E {
                     self.f1 = pyl.mapv(|x| x.ln()).sum();
                     if (self.f1 - self.f0).abs() <= THETA_F {
-                        tracing::info!("Likelihood criteria convergence, -2LL: {:.1}", self.objf);
+                        tracing::info!("The run converged");
                         self.converged = true;
-                        state.stop_text = "The run converged!".to_string();
-                        self.tx.send(state).unwrap();
                         break;
                     } else {
                         self.f0 = self.f1;
@@ -308,17 +308,13 @@ where
 
             // Stop if we have reached maximum number of cycles
             if self.cycle >= self.settings.parsed.config.cycles {
-                tracing::info!("Maximum number of cycles reached");
-                state.stop_text = "No (max cycle)".to_string();
-                self.tx.send(state).unwrap();
+                tracing::warn!("Maximum number of cycles reached");
                 break;
             }
 
             // Stop if stopfile exists
             if std::path::Path::new("stop").exists() {
-                tracing::info!("Stopfile detected - breaking");
-                state.stop_text = "No (stopped)".to_string();
-                self.tx.send(state).unwrap();
+                tracing::warn!("Stopfile detected - breaking");
                 break;
             }
             self.cycle_log
@@ -329,6 +325,7 @@ where
             self.last_objf = self.objf;
         }
 
+        self.tx.send(Comm::Stop(true)).unwrap();
         self.to_npresult()
     }
 }

src/algorithms/postprob.rs

@@ -1,14 +1,16 @@
-use crate::prelude::{
-    algorithms::Algorithm,
-    datafile::Scenario,
-    evaluation::sigma::{ErrorPoly, ErrorType},
-    ipm,
-    output::NPCycle,
-    output::NPResult,
-    prob,
-    settings::run::Data,
-    simulation::predict::Engine,
-    simulation::predict::{sim_obs, Predict},
+use crate::{
+    prelude::{
+        algorithms::Algorithm,
+        datafile::Scenario,
+        evaluation::sigma::{ErrorPoly, ErrorType},
+        ipm,
+        output::NPResult,
+        prob,
+        settings::run::Data,
+        simulation::predict::Engine,
+        simulation::predict::{sim_obs, Predict},
+    },
+    tui::ui::Comm,
 };
 
 use ndarray::{Array1, Array2};
@@ -32,7 +34,7 @@ where
     scenarios: Vec<Scenario>,
     c: (f64, f64, f64, f64),
     #[allow(dead_code)]
-    tx: UnboundedSender<NPCycle>,
+    tx: UnboundedSender<Comm>,
     settings: Data,
 }
 
@@ -66,7 +68,7 @@ where
         theta: Array2<f64>,
         scenarios: Vec<Scenario>,
         c: (f64, f64, f64, f64),
-        tx: UnboundedSender<NPCycle>,
+        tx: UnboundedSender<Comm>,
         settings: Data,
     ) -> Self
     where

src/entrypoints.rs

@@ -1,5 +1,4 @@
 use crate::algorithms::initialize_algorithm;
-use crate::prelude::output::NPCycle;
 use crate::prelude::{
     output::NPResult,
     predict::{Engine, Predict},
@@ -60,9 +59,9 @@ where
 {
     let now = Instant::now();
     let settings = settings::run::read(settings_path);
-    logger::setup_log(&settings);
+    let (tx, rx) = mpsc::unbounded_channel::<Comm>();
+    logger::setup_log(&settings, tx.clone());
     tracing::info!("Starting NPcore");
-    let (tx, rx) = mpsc::unbounded_channel::<NPCycle>();
     let mut scenarios = datafile::parse(&settings.parsed.paths.data).unwrap();
     if let Some(exclude) = &settings.parsed.config.exclude {
         for val in exclude {
@@ -86,6 +85,7 @@ where
     if let Some(write) = &settings.parsed.config.pmetrics_outputs {
         result.write_outputs(*write, &engine, idelta, tad);
     }
+    tracing::info!("Program complete");
 
     Ok(result)
 }
@@ -100,8 +100,8 @@ where
 {
     let now = Instant::now();
     let settings = settings::run::read(settings_path);
-    logger::setup_log(&settings);
-    let (tx, rx) = mpsc::unbounded_channel::<NPCycle>();
+    let (tx, rx) = mpsc::unbounded_channel::<Comm>();
+    logger::setup_log(&settings, tx.clone());
 
     let mut algorithm = initialize_algorithm(engine.clone(), settings.clone(), scenarios, tx);
     // Spawn new thread for TUI

src/logger.rs

@@ -1,56 +1,80 @@
+use crate::routines::settings::run::Data;
+use crate::tui::ui::Comm;
+use std::io::{self, Write};
+use tokio::sync::mpsc::UnboundedSender;
 use tracing_subscriber::fmt::time::FormatTime;
-use tracing_subscriber::fmt::{self, format::Format};
+use tracing_subscriber::fmt::{self};
 use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt;
 use tracing_subscriber::registry::Registry;
 use tracing_subscriber::util::SubscriberInitExt;
 use tracing_subscriber::EnvFilter;
 
-use crate::routines::settings::run::Data;
-
-pub fn setup_log(settings: &Data) {
+pub fn setup_log(settings: &Data, ui_tx: UnboundedSender<Comm>) {
+    // Use the log level defined in configuration file, or default to info
     let log_level = settings
         .parsed
         .config
         .log_level
         .as_ref()
         .map(|level| level.as_str())
-        .unwrap_or("info"); // Default to 'info' if not set
+        .unwrap_or("info")
+        .to_lowercase();
 
     let env_filter = EnvFilter::new(log_level);
 
-    let stdout_log = Format::default().compact().with_timer(CompactTimestamp);
-
-    // Start with a base subscriber from the registry
+    // Define a registry with that level as an environment filter
     let subscriber = Registry::default().with(env_filter);
 
-    // Check if a log file path is provided
-    if let Some(log_path) = &settings.parsed.paths.log_out {
-        // Ensure the log file is created or truncated
-        let file = std::fs::OpenOptions::new()
-            .create(true)
-            .write(true)
-            .truncate(true)
-            .open(log_path)
-            .expect("Failed to open log file");
+    // Define a layer for the log file
+    let file = std::fs::OpenOptions::new()
+        .create(true)
+        .write(true)
+        .truncate(true)
+        .open(&settings.parsed.paths.log_out)
+        .expect("Failed to open log file - does the directory exist?");
 
-        let file_layer = fmt::layer()
-            .with_writer(file)
-            .with_ansi(false)
-            .event_format(stdout_log.clone());
+    let file_layer = fmt::layer()
+        .with_writer(file)
+        .with_ansi(false)
+        .with_timer(CompactTimestamp);
 
-        // Add the file layer to the subscriber
-        subscriber.with(file_layer).init();
+    // Define layer for stdout
+    let stdout_layer = if !settings.parsed.config.tui {
+        let layer = fmt::layer()
+            .with_writer(std::io::stdout)
+            .with_ansi(true)
+            .with_target(false)
+            .with_timer(CompactTimestamp);
+        Some(layer)
     } else {
-        // Add stdout layer only if no log file is specified
-        let stdout_layer = fmt::layer()
-            .event_format(stdout_log)
-            .with_writer(std::io::stdout);
+        None
+    };
 
-        // Add the stdout layer to the subscriber
-        subscriber.with(stdout_layer).init();
-    }
+    // Define layer for TUI
+    let tui_writer_closure = move || {
+        TuiWriter {
+            ui_tx: ui_tx.clone(), // Ensure this clone is okay with your design (consider the lifetime of _ui_tx)
+        }
+    };
+
+    let tui_layer = if settings.parsed.config.tui {
+        let layer = fmt::layer()
+            .with_writer(tui_writer_closure)
+            .with_ansi(false)
+            .with_target(false)
+            .with_timer(CompactTimestamp);
+        Some(layer)
+    } else {
+        None
+    };
 
-    tracing::info!("Logging is configured with level: {}", log_level);
+    // Combine layers with subscriber
+    subscriber
+        .with(file_layer)
+        .with(stdout_layer)
+        .with(tui_layer)
+        .init();
+    tracing::debug!("Logging is configured with level: {}", log_level);
 }
 
 #[derive(Clone)]
@@ -64,3 +88,23 @@ impl FormatTime for CompactTimestamp {
         write!(w, "{}", chrono::Local::now().format("%H:%M:%S"))
     }
 }
+
+struct TuiWriter {
+    ui_tx: UnboundedSender<Comm>,
+}
+
+impl Write for TuiWriter {
+    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+        let msg = String::from_utf8_lossy(buf);
+        // Send the message through the channel
+        self.ui_tx
+            .send(Comm::LogMessage(msg.to_string()))
+            .map_err(|_| io::Error::new(io::ErrorKind::Other, "Failed to send log message"))?;
+        Ok(buf.len())
+    }
+
+    fn flush(&mut self) -> io::Result<()> {
+        // Flushing is not required for this use case
+        Ok(())
+    }
+}