feat: Improve logging output (#139)

Cargo.toml

@@ -10,6 +10,9 @@ categories = ["command-line-utilities"]
 
 [workspace.dependencies]
 anyhow = "1"
+chrono = "0.4.35"
+colored = "2.1.0"
+env_logger = "0.11"
 format_serde_error = "0.3.0"
 log = "0.4"
 serde = { version = "1", features = ["derive"] }
@@ -54,8 +57,6 @@ clap = { version = "4", features = ["derive", "cargo", "unicode"] }
 clap-verbosity-flag = "2"
 clap_complete = "4"
 clap_complete_nushell = "4"
-colorized = "1"
-env_logger = "0.11"
 fuzzy-matcher = "0.3"
 once_cell = "1.19.0"
 open = "5"
@@ -68,6 +69,9 @@ users = "0.11.0"
 
 # Workspace dependencies
 anyhow.workspace = true
+chrono.workspace = true
+colored.workspace = true
+env_logger.workspace = true
 log.workspace = true
 serde.workspace = true
 serde_json.workspace = true

src/bin/bluebuild.rs

@@ -1,14 +1,17 @@
 use blue_build::commands::{BlueBuildArgs, BlueBuildCommand, CommandArgs};
+use blue_build_utils::logging;
 use clap::Parser;
-use env_logger::WriteStyle;
+use log::LevelFilter;
 
 fn main() {
     let args = BlueBuildArgs::parse();
 
+    let log_level = args.verbosity.log_level_filter();
+
     env_logger::builder()
         .filter_level(args.verbosity.log_level_filter())
-        .filter_module("hyper::proto", log::LevelFilter::Info)
-        .write_style(WriteStyle::Always)
+        .filter_module("hyper::proto", LevelFilter::Info)
+        .format(logging::format_log(log_level))
         .init();
 
     log::trace!("Parsed arguments: {args:#?}");

src/commands/bug_report.rs

@@ -6,6 +6,7 @@ use blue_build_utils::constants::{
 };
 use clap::Args;
 use clap_complete::Shell;
+use colored::Colorize;
 use fuzzy_matcher::{skim::SkimMatcherV2, FuzzyMatcher};
 use log::{debug, error, trace};
 use requestty::question::{completions, Completions};
@@ -54,8 +55,6 @@ impl BugReportCommand {
     ///
     /// This function will panic if it fails to get the current shell or terminal version.
     pub fn create_bugreport(&self) -> anyhow::Result<()> {
-        use colorized::{Color, Colors};
-
         let os_info = os_info::get();
         let recipe = self.get_recipe();
 
@@ -69,31 +68,27 @@ impl BugReportCommand {
         let issue_body = match generate_github_issue(&environment, &recipe) {
             Ok(body) => body,
             Err(e) => {
-                println!(
-                    "{}: {e}",
-                    "Failed to generate bug report".color(Colors::BrightRedFg)
-                );
+                println!("{}: {e}", "Failed to generate bug report".bright_red());
                 return Err(e);
             }
         };
 
         println!(
             "\n{}\n{}\n",
-            "Generated bug report:".color(Colors::BrightGreenFg),
-            issue_body
-                .color(Colors::BrightBlackBg)
-                .color(Colors::BrightWhiteFg)
+            "Generated bug report:".bright_green(),
+            issue_body.on_bright_black().bright_white()
         );
 
         let question = requestty::Question::confirm("anonymous")
             .message(
                 "Forward the pre-filled report above to GitHub in your browser?"
-                    .color(Colors::BrightYellowFg),
+                    .bright_yellow()
+                    .to_string(),
             )
             .default(true)
             .build();
 
-        println!("{} To avoid any sensitive data from being exposed, please review the included information before proceeding.", "Warning:".color(Colors::BrightRedBg).color(Colors::BrightWhiteFg));
+        println!("{} To avoid any sensitive data from being exposed, please review the included information before proceeding.", "Warning:".on_bright_red().bright_white());
         println!("Data forwarded to GitHub is subject to GitHub's privacy policy. For more information, see https://docs.github.com/en/github/site-policy/github-privacy-statement.\n");
         match requestty::prompt_one(question) {
             Ok(answer) => {
@@ -115,7 +110,7 @@ impl BugReportCommand {
 
         println!(
             "\n{}",
-            "Thanks for using the BlueBuild bug report tool!".color(Colors::BrightCyanFg)
+            "Thanks for using the BlueBuild bug report tool!".bright_cyan()
         );
 
         Ok(())

src/commands/build.rs

@@ -14,7 +14,7 @@ use blue_build_utils::constants::{
     RECIPE_PATH, SIGSTORE_ID_TOKEN,
 };
 use clap::Args;
-use colorized::{Color, Colors};
+use colored::Colorize;
 use log::{debug, info, trace, warn};
 use typed_builder::TypedBuilder;
 
@@ -146,7 +146,8 @@ impl BlueBuildCommand for BuildCommand {
                         } else {
                             NO_LABEL_ERROR_MESSAGE
                         }
-                        .color(Colors::BrightYellowFg),
+                        .bright_yellow()
+                        .to_string(),
                     )
                     .default(true)
                     .build();

template/templates/modules/modules.j2

@@ -29,8 +29,10 @@ RUN \
       {%- endif %}
   --mount=type=bind,from=stage-exports,src=/exports.sh,dst=/tmp/exports.sh \
   --mount=type=cache,dst=/var/cache/rpm-ostree,id=rpm-ostree-cache-{{ recipe.name }}-{{ recipe.image_version }},sharing=locked \
-  chmod +x /tmp/modules/{{ type }}/{{ type }}.sh \
+  echo "========== Start {{ type|capitalize }} module ==========" \
+  && chmod +x /tmp/modules/{{ type }}/{{ type }}.sh \
   && source /tmp/exports.sh && /tmp/modules/{{ type }}/{{ type }}.sh '{{ module.print_module_context() }}' \
+  && echo "========== End {{ type|capitalize }} module ==========" \
   && ostree container commit
     {%- endif %}
   {%- endif %}

utils/Cargo.toml

@@ -14,6 +14,9 @@ process_control = { version = "4.0.3", features = ["crossbeam-channel"] }
 which = "6"
 
 anyhow.workspace = true
+chrono.workspace = true
+colored.workspace = true
+env_logger.workspace = true
 format_serde_error.workspace = true
 log.workspace = true
 serde.workspace = true

utils/src/lib.rs

@@ -1,5 +1,6 @@
 pub mod command_output;
 pub mod constants;
+pub mod logging;
 
 use std::{ffi::OsStr, io::Write, path::PathBuf, process::Command, thread, time::Duration};
 

utils/src/logging.rs

@@ -0,0 +1,60 @@
+use std::io::{self, Write};
+
+use chrono::Local;
+use colored::{ColoredString, Colorize};
+use env_logger::fmt::Formatter;
+use log::{Level, LevelFilter, Record};
+
+fn colored_level(level: Level) -> ColoredString {
+    match level {
+        Level::Error => Level::Error.as_str().bright_red(),
+        Level::Warn => Level::Warn.as_str().yellow(),
+        Level::Info => Level::Info.as_str().bright_green(),
+        Level::Debug => Level::Debug.as_str().blue(),
+        Level::Trace => Level::Trace.as_str().bright_cyan(),
+    }
+}
+
+/// Given a `LevelFilter`, returns the function
+/// used to format logs. The more verbose the log level,
+/// the more info is displayed in each log header.
+pub fn format_log(
+    log_level: LevelFilter,
+) -> impl Fn(&mut Formatter, &Record) -> io::Result<()> + Sync + Send {
+    move |buf: &mut Formatter, record: &Record| match log_level {
+        LevelFilter::Error | LevelFilter::Warn | LevelFilter::Info => {
+            writeln!(
+                buf,
+                "{:width$} => {}",
+                colored_level(record.level()),
+                record.args(),
+                width = 5,
+            )
+        }
+        LevelFilter::Debug => writeln!(
+            buf,
+            "[{} {:>width$}] => {}",
+            Local::now().format("%H:%M:%S"),
+            colored_level(record.level()),
+            record.args(),
+            width = 5,
+        ),
+        LevelFilter::Trace => writeln!(
+            buf,
+            "[{} {:width$} {}:{}] => {}",
+            Local::now().format("%H:%M:%S"),
+            colored_level(record.level()),
+            record
+                .module_path()
+                .map_or_else(|| "", |p| p)
+                .bright_yellow(),
+            record
+                .line()
+                .map_or_else(String::new, |l| l.to_string())
+                .bright_green(),
+            record.args(),
+            width = 5,
+        ),
+        LevelFilter::Off => Ok(()),
+    }
+}