add better implementation

rust-tests/src/lib.rs

@@ -81,7 +81,7 @@ mod tests {
             let stdout = String::from_utf8(output.stdout.clone())
                 .expect("Failed to convert output to UTF-8");
 
-            println!(
+            tracing::info!(
                 "Running: {} {}",
                 command,
                 args_vec
@@ -91,7 +91,7 @@ mod tests {
                     .join(" ")
             );
 
-            println!("{}", stdout);
+            tracing::info!("{}", stdout);
 
             output
         }

src/console_utils.rs

@@ -1,64 +1,29 @@
 use console::style;
-use indicatif::MultiProgress;
+use indicatif::{HumanBytes, HumanDuration, MultiProgress, ProgressState, ProgressStyle};
 use std::{
-    io::{self, Write},
+    collections::HashMap,
+    io,
     sync::{Arc, Mutex},
+    time::Instant,
 };
 use tracing::field;
 use tracing_core::{span::Id, Event, Field, Subscriber};
 use tracing_subscriber::{
     fmt::{
         format::{self, Format},
-        FmtContext, FormatEvent, FormatFields, MakeWriter,
+        FmtContext, FormatEvent, FormatFields,
     },
     layer::Context,
     registry::LookupSpan,
     Layer,
 };
 
-#[derive(Clone)]
-pub struct IndicatifWriter {
-    progress_bars: MultiProgress,
-}
-
-impl IndicatifWriter {
-    pub(crate) fn new(pb: MultiProgress) -> Self {
-        Self { progress_bars: pb }
-    }
-}
-
-impl io::Write for IndicatifWriter {
-    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
-        self.progress_bars.suspend(|| io::stderr().write(buf))
-    }
-
-    fn flush(&mut self) -> io::Result<()> {
-        self.progress_bars.suspend(|| io::stderr().flush())
-    }
-}
-
-impl<'a> MakeWriter<'a> for IndicatifWriter {
-    type Writer = IndicatifWriter;
-
-    fn make_writer(&'a self) -> Self::Writer {
-        self.clone()
-    }
-}
-
+#[derive(Default)]
 struct TracingFormatterInner {
     indentation_level: usize,
     current_section: String,
 }
 
-impl Default for TracingFormatterInner {
-    fn default() -> Self {
-        Self {
-            indentation_level: 0,
-            current_section: String::new(),
-        }
-    }
-}
-
 impl Default for TracingFormatter {
     fn default() -> Self {
         Self {
@@ -83,10 +48,6 @@ where
         event: &Event<'_>,
     ) -> std::fmt::Result {
         let metadata = event.metadata();
-        // println!("metadata: {:?}", metadata);
-        // println!("full event: {:?}", event);
-        println!("span: {:?}", ctx.current_span());
-
         fn indent_levels(indent: usize) -> String {
             let mut s = String::new();
             for _ in 0..indent {
@@ -139,28 +100,17 @@ where
     }
 }
 
-pub struct CustomLayer {
-    shared_state: Arc<Mutex<SharedState>>,
-    writer: IndicatifWriter,
-}
-
-impl CustomLayer {
-    pub fn new(writer: IndicatifWriter) -> Self {
-        Self {
-            shared_state: Arc::new(Mutex::new(SharedState::new())),
-            writer,
-        }
-    }
-}
-
+#[derive(Debug)]
 struct SharedState {
     indentation_level: usize,
+    timestamps: HashMap<Id, Instant>,
 }
 
 impl SharedState {
     fn new() -> Self {
         Self {
             indentation_level: 0,
+            timestamps: HashMap::new(),
         }
     }
 }
@@ -215,7 +165,7 @@ fn chunk_string_without_ansi(input: &str, max_chunk_length: usize) -> Vec<String
             current_chunk.push(c);
             while let Some(&next_char) = chars.peek() {
                 current_chunk.push(chars.next().unwrap()); // Add to current chunk
-                if ('a'..='z').contains(&next_char) || ('A'..='Z').contains(&next_char) {
+                if next_char.is_ascii_alphabetic() {
                     break; // End of ANSI escape sequence
                 }
             }
@@ -248,13 +198,13 @@ fn indent_levels(indent: usize) -> String {
     format!("{}", style(s).cyan())
 }
 
-impl<S> Layer<S> for CustomLayer
+impl<S> Layer<S> for LoggingOutputHandler
 where
     S: Subscriber + for<'a> LookupSpan<'a>,
 {
     fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
-        let mut state = self.shared_state.lock().unwrap();
-
+        let mut state = self.state.lock().unwrap();
+        state.timestamps.insert(id.clone(), Instant::now());
         let span = ctx.span(id);
         let ind = indent_levels(state.indentation_level);
 
@@ -265,43 +215,177 @@ where
         state.indentation_level += 1;
     }
 
-    fn on_exit(&self, _id: &Id, _ctx: Context<'_, S>) {
-        let mut state = self.shared_state.lock().unwrap();
+    fn on_exit(&self, id: &Id, _ctx: Context<'_, S>) {
+        let mut state = self.state.lock().unwrap();
+
+        let prev_ind = indent_levels(state.indentation_level);
 
         if state.indentation_level > 0 {
             state.indentation_level -= 1;
         }
 
         let ind = indent_levels(state.indentation_level);
-        println!("{ind} {}", style("╰───────────────────").cyan());
+
+        let elapsed_time = state
+            .timestamps
+            .remove(id)
+            .map(|t| t.elapsed())
+            .unwrap_or_default();
+
+        let human_duration = HumanDuration(elapsed_time);
+
+        println!(
+            "{prev_ind}\n{ind} {} (took {})\n{ind}",
+            style("╰─────────────────── ").cyan(),
+            human_duration
+        );
     }
 
     fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
-        let state = self.shared_state.lock().unwrap();
-
+        let state = self.state.lock().unwrap();
         let indent_str = indent_levels(state.indentation_level);
         let mut s = Vec::new();
         let mut w = io::Cursor::new(&mut s);
         event.record(&mut CustomVisitor::new(&mut w));
-        let s = String::from_utf8_lossy(&w.get_ref());
+        let s = String::from_utf8_lossy(w.get_ref());
 
         let width: usize = terminal_size::terminal_size()
             .map(|(w, _)| w.0)
             .unwrap_or(80) as usize;
 
         let max_width = width - (state.indentation_level * 2) - 1;
-        let mut writer = self.writer.make_writer();
-        for line in s.lines() {
-            // split line into max_width chunks
-            if line.len() <= max_width {
-                writeln!(writer, "{} {}", indent_str, line).unwrap();
-            } else {
-                chunk_string_without_ansi(line, max_width)
-                    .iter()
-                    .for_each(|chunk| {
-                        writeln!(writer, "{} {}", indent_str, chunk).unwrap();
-                    });
+
+        self.progress_bars.suspend(|| {
+            for line in s.lines() {
+                // split line into max_width chunks
+                if line.len() <= max_width {
+                    println!("{} {}", indent_str, line);
+                } else {
+                    chunk_string_without_ansi(line, max_width)
+                        .iter()
+                        .for_each(|chunk| {
+                            println!("{} {}", indent_str, chunk);
+                        });
+                }
             }
+        });
+    }
+}
+
+#[derive(Debug)]
+pub struct LoggingOutputHandler {
+    state: Arc<Mutex<SharedState>>,
+    progress_bars: MultiProgress,
+}
+
+impl Clone for LoggingOutputHandler {
+    fn clone(&self) -> Self {
+        Self {
+            state: self.state.clone(),
+            progress_bars: self.progress_bars.clone(),
+        }
+    }
+}
+
+impl LoggingOutputHandler {
+    pub fn new(pb: MultiProgress) -> Self {
+        Self {
+            state: Arc::new(Mutex::new(SharedState::new())),
+            progress_bars: pb,
         }
     }
+
+    fn with_indent_levels(&self, template: &str) -> String {
+        let state = self.state.lock().unwrap();
+        let indent_str = indent_levels(state.indentation_level);
+        format!("{} {}", indent_str, template)
+    }
+
+    /// Returns the style to use for a progressbar that is currently in progress.
+    pub fn default_bytes_style(&self) -> indicatif::ProgressStyle {
+        let template_str = self.with_indent_levels(
+            "{spinner:.green} {prefix:20!} [{elapsed_precise}] [{bar:40!.bright.yellow/dim.white}] {bytes:>8} @ {smoothed_bytes_per_sec:8}"
+        );
+
+        indicatif::ProgressStyle::default_bar()
+            .template(&template_str)
+            .unwrap()
+            .progress_chars("━━╾─")
+            .with_key(
+                "smoothed_bytes_per_sec",
+                |s: &ProgressState, w: &mut dyn std::fmt::Write| match (
+                    s.pos(),
+                    s.elapsed().as_millis(),
+                ) {
+                    (pos, elapsed_ms) if elapsed_ms > 0 => {
+                        // TODO: log with tracing?
+                        _ = write!(
+                            w,
+                            "{}/s",
+                            HumanBytes((pos as f64 * 1000_f64 / elapsed_ms as f64) as u64)
+                        );
+                    }
+                    _ => {
+                        _ = write!(w, "-");
+                    }
+                },
+            )
+    }
+
+    /// Returns the style to use for a progressbar that is currently in progress.
+    pub fn default_progress_style(&self) -> indicatif::ProgressStyle {
+        let template_str = self.with_indent_levels(
+            "{spinner:.green} {prefix:20!} [{elapsed_precise}] [{bar:40!.bright.yellow/dim.white}] {pos:>7}/{len:7}"
+        );
+        indicatif::ProgressStyle::default_bar()
+            .template(&template_str)
+            .unwrap()
+            .progress_chars("━━╾─")
+    }
+
+    /// Returns the style to use for a progressbar that is in Deserializing state.
+    pub fn deserializing_progress_style(&self) -> indicatif::ProgressStyle {
+        let template_str =
+            self.with_indent_levels("{spinner:.green} {prefix:20!} [{elapsed_precise}] {wide_msg}");
+        indicatif::ProgressStyle::default_bar()
+            .template(&template_str)
+            .unwrap()
+            .progress_chars("━━╾─")
+    }
+
+    /// Returns the style to use for a progressbar that is finished.
+    pub fn finished_progress_style(&self) -> indicatif::ProgressStyle {
+        let template_str = self.with_indent_levels(&format!(
+            "{} {{spinner:.green}} {{prefix:20!}} [{{elapsed_precise}}] {{msg:.bold.green}}",
+            console::style(console::Emoji("✔", " ")).green()
+        ));
+
+        indicatif::ProgressStyle::default_bar()
+            .template(&template_str)
+            .unwrap()
+            .progress_chars("━━╾─")
+    }
+
+    /// Returns the style to use for a progressbar that is in error state.
+    pub fn errored_progress_style(&self) -> indicatif::ProgressStyle {
+        let template_str = self.with_indent_levels(&format!(
+            "{} {{prefix:20!}} [{{elapsed_precise}}] {{msg:.bold.red}}",
+            console::style(console::Emoji("×", " ")).red()
+        ));
+
+        indicatif::ProgressStyle::default_bar()
+            .template(&template_str)
+            .unwrap()
+            .progress_chars("━━╾─")
+    }
+
+    /// Returns the style to use for a progressbar that is indeterminate and simply shows a spinner.
+    pub fn long_running_progress_style(&self) -> indicatif::ProgressStyle {
+        let template_str = self.with_indent_levels("{spinner:.green} {msg}");
+        ProgressStyle::with_template(&template_str).unwrap()
+    }
+
+    pub fn add_progress_bar(&self, progress_bar: indicatif::ProgressBar) -> indicatif::ProgressBar {
+        self.progress_bars.add(progress_bar)
+    }
 }

src/lib.rs

@@ -1,8 +1,9 @@
-#![deny(missing_docs)]
+// #![deny(missing_docs)]
 
 //! The library pieces of rattler-build
 
 pub mod build;
+pub mod console_utils;
 pub mod metadata;
 pub mod package_test;
 pub mod packaging;