Add verbose logging support with env_logger

9 files changed, 299 insertions, 81 deletions

diff --git a/src/bin/jvn.rs b/src/bin/jvn.rs
index 7ec1f4d..aa438d0 100644
--- a/src/bin/jvn.rs
+++ b/src/bin/jvn.rs
@@ -1,76 +1,87 @@
 use std::process::exit;
 
-use cli_utils::display::md;
-use cli_utils::env::current_locales;
-use cli_utils::levenshtein_distance::levenshtein_distance;
-use just_enough_vcs_cli::systems::cmd::_commands::jv_cmd_nodes;
-use just_enough_vcs_cli::systems::cmd::cmd_system::JVCommandContext;
-use just_enough_vcs_cli::systems::cmd::errors::{CmdExecuteError, CmdPrepareError, CmdRenderError};
-use just_enough_vcs_cli::systems::cmd::{errors::CmdProcessError, processer::jv_cmd_process};
+use cli_utils::{display::md, env::current_locales, levenshtein_distance::levenshtein_distance};
+use just_enough_vcs_cli::{
+    special_argument, special_flag,
+    systems::{
+        cmd::{
+            _commands::jv_cmd_nodes,
+            cmd_system::JVCommandContext,
+            errors::{CmdExecuteError, CmdPrepareError, CmdProcessError, CmdRenderError},
+            processer::jv_cmd_process,
+        },
+        debug::verbose_logger::init_verbose_logger,
+    },
+};
+use log::{LevelFilter, error, info, trace, warn};
 use rust_i18n::{set_locale, t};
 
 rust_i18n::i18n!("resources/locales/jvn", fallback = "en");
 
-macro_rules! special_flag {
-    ($args:expr, $flag:expr) => {{
-        let flag = $flag;
-        let found = $args.iter().any(|arg| arg == flag);
-        $args.retain(|arg| arg != flag);
-        found
-    }};
-}
-
-macro_rules! special_argument {
-    ($args:expr, $flag:expr) => {{
-        let flag = $flag;
-        let mut value: Option<String> = None;
-        let mut i = 0;
-        while i < $args.len() {
-            if $args[i] == flag {
-                if i + 1 < $args.len() {
-                    value = Some($args[i + 1].clone());
-                    $args.remove(i + 1);
-                    $args.remove(i);
-                } else {
-                    value = None;
-                    $args.remove(i);
-                }
-                break;
-            }
-            i += 1;
-        }
-        value
-    }};
-}
-
 #[tokio::main]
 async fn main() {
     // Collect arguments
     let mut args: Vec<String> = std::env::args().skip(1).collect();
 
-    // Init i18n
+    // Init colored
+    #[cfg(windows)]
+    colored::control::set_virtual_terminal(true).unwrap();
+
+    // Output control flags
+    let quiet = special_flag!(args, "--quiet") || special_flag!(args, "-q");
+    let verbose = special_flag!(args, "--verbose") || special_flag!(args, "-V");
+    let verbose_full = special_flag!(args, "--verbose-full");
+
+    // If `--verbose` or `--verbose-full` is enabled and `--quiet` is not enabled, turn on the logger
+    let filter = if (verbose || verbose_full) && !quiet {
+        let filter = if verbose_full {
+            LevelFilter::Trace
+        } else {
+            LevelFilter::Info
+        };
+        Some(filter)
+    } else {
+        None
+    };
+    init_verbose_logger(filter);
+    trace!("{}", t!("verbose.setup_verbose"));
+
+    // I18n flags
     let lang = special_argument!(args, "--lang").unwrap_or(current_locales());
     set_locale(&lang);
+    trace!("{}", t!("verbose.setup_i18n", lang = lang));
 
     // Renderer
     let renderer_override = special_argument!(args, "--renderer").unwrap_or("default".to_string());
+    trace!(
+        "{}",
+        t!("verbose.setup_renderer", renderer = renderer_override)
+    );
 
     // Other flags
     let no_error_logs = special_flag!(args, "--no-error-logs");
-    let quiet = special_flag!(args, "--quiet") || special_flag!(args, "-q");
     let help = special_flag!(args, "--help") || special_flag!(args, "-h");
     let confirmed = special_flag!(args, "--confirm") || special_flag!(args, "-C");
 
-    // Init colored
-    #[cfg(windows)]
-    colored::control::set_virtual_terminal(true).unwrap();
+    if no_error_logs {
+        trace!("{}", t!("verbose.no_error_logs"));
+    }
+    if help {
+        trace!("{}", t!("verbose.help"));
+    }
+    if confirmed {
+        trace!("{}", t!("verbose.confirmed"));
+    }
 
     // Handle help when no arguments provided
     if args.len() < 1 && help {
+        warn!("{}", t!("verbose.no_arguments"));
         eprintln!("{}", md(t!("help")));
         exit(1);
     }
 
+    info!("{}", t!("verbose.user_input", command = args.join(" ")));
+
     // Process commands
     let render_result = match jv_cmd_process(
         &args,
@@ -79,8 +90,12 @@ async fn main() {
     )
     .await
     {
-        Ok(result) => result,
+        Ok(result) => {
+            info!("{}", t!("verbose.process_success"));
+            result
+        }
         Err(e) => {
+            error!("{}", t!("verbose.process_fail"));
             if !no_error_logs {
                 match e {
                     CmdProcessError::Prepare(cmd_prepare_error) => {
@@ -125,6 +140,7 @@ async fn main() {
 
     // Print
     if !quiet {
+        info!("{}", t!("verbose.print_render_result"));
         print!("{}", render_result);
     }
 }
@@ -159,7 +175,10 @@ fn handle_no_matching_command_error(args: Vec<String>) {
 fn handle_prepare_error(cmd_prepare_error: CmdPrepareError) {
     match cmd_prepare_error {
         CmdPrepareError::Io(error) => {
-            eprintln!("{}", md(t!("prepare_error.io", error = error.to_string())));
+            eprintln!(
+                "{}",
+                md(t!("prepare_error.io", error = display_io_error(error)))
+            );
         }
         CmdPrepareError::Error(msg) => {
             eprintln!("{}", md(t!("prepare_error.error", error = msg)));
@@ -213,7 +232,10 @@ fn handle_prepare_error(cmd_prepare_error: CmdPrepareError) {
 fn handle_execute_error(cmd_execute_error: CmdExecuteError) {
     match cmd_execute_error {
         CmdExecuteError::Io(error) => {
-            eprintln!("{}", md(t!("execute_error.io", error = error.to_string())));
+            eprintln!(
+                "{}",
+                md(t!("execute_error.io", error = display_io_error(error)))
+            );
         }
         CmdExecuteError::Prepare(cmd_prepare_error) => handle_prepare_error(cmd_prepare_error),
         CmdExecuteError::Error(msg) => {
@@ -225,7 +247,10 @@ fn handle_execute_error(cmd_execute_error: CmdExecuteError) {
 fn handle_render_error(cmd_render_error: CmdRenderError) {
     match cmd_render_error {
         CmdRenderError::Io(error) => {
-            eprintln!("{}", md(t!("render_error.io", error = error.to_string())));
+            eprintln!(
+                "{}",
+                md(t!("render_error.io", error = display_io_error(error)))
+            );
         }
         CmdRenderError::Prepare(cmd_prepare_error) => handle_prepare_error(cmd_prepare_error),
         CmdRenderError::Execute(cmd_execute_error) => handle_execute_error(cmd_execute_error),
@@ -258,3 +283,66 @@ fn handle_render_error(cmd_render_error: CmdRenderError) {
         }
     }
 }
+
+fn display_io_error(error: std::io::Error) -> std::borrow::Cow<'static, str> {
+    match error.kind() {
+        std::io::ErrorKind::NotFound => t!("io_error.not_found", raw_error = error),
+        std::io::ErrorKind::PermissionDenied => t!("io_error.permission_denied", raw_error = error),
+        std::io::ErrorKind::ConnectionRefused => {
+            t!("io_error.connection_refused", raw_error = error)
+        }
+        std::io::ErrorKind::ConnectionReset => t!("io_error.connection_reset", raw_error = error),
+        std::io::ErrorKind::HostUnreachable => t!("io_error.host_unreachable", raw_error = error),
+        std::io::ErrorKind::NetworkUnreachable => {
+            t!("io_error.network_unreachable", raw_error = error)
+        }
+        std::io::ErrorKind::ConnectionAborted => {
+            t!("io_error.connection_aborted", raw_error = error)
+        }
+        std::io::ErrorKind::NotConnected => t!("io_error.not_connected", raw_error = error),
+        std::io::ErrorKind::AddrInUse => t!("io_error.addr_in_use", raw_error = error),
+        std::io::ErrorKind::AddrNotAvailable => {
+            t!("io_error.addr_not_available", raw_error = error)
+        }
+        std::io::ErrorKind::NetworkDown => t!("io_error.network_down", raw_error = error),
+        std::io::ErrorKind::BrokenPipe => t!("io_error.broken_pipe", raw_error = error),
+        std::io::ErrorKind::AlreadyExists => t!("io_error.already_exists", raw_error = error),
+        std::io::ErrorKind::WouldBlock => t!("io_error.would_block", raw_error = error),
+        std::io::ErrorKind::NotADirectory => t!("io_error.not_a_directory", raw_error = error),
+        std::io::ErrorKind::IsADirectory => t!("io_error.is_a_directory", raw_error = error),
+        std::io::ErrorKind::DirectoryNotEmpty => {
+            t!("io_error.directory_not_empty", raw_error = error)
+        }
+        std::io::ErrorKind::ReadOnlyFilesystem => {
+            t!("io_error.read_only_filesystem", raw_error = error)
+        }
+        std::io::ErrorKind::StaleNetworkFileHandle => {
+            t!("io_error.stale_network_file_handle", raw_error = error)
+        }
+        std::io::ErrorKind::InvalidInput => t!("io_error.invalid_input", raw_error = error),
+        std::io::ErrorKind::InvalidData => t!("io_error.invalid_data", raw_error = error),
+        std::io::ErrorKind::TimedOut => t!("io_error.timed_out", raw_error = error),
+        std::io::ErrorKind::WriteZero => t!("io_error.write_zero", raw_error = error),
+        std::io::ErrorKind::StorageFull => t!("io_error.storage_full", raw_error = error),
+        std::io::ErrorKind::NotSeekable => t!("io_error.not_seekable", raw_error = error),
+        std::io::ErrorKind::QuotaExceeded => t!("io_error.quota_exceeded", raw_error = error),
+        std::io::ErrorKind::FileTooLarge => t!("io_error.file_too_large", raw_error = error),
+        std::io::ErrorKind::ResourceBusy => t!("io_error.resource_busy", raw_error = error),
+        std::io::ErrorKind::ExecutableFileBusy => {
+            t!("io_error.executable_file_busy", raw_error = error)
+        }
+        std::io::ErrorKind::Deadlock => t!("io_error.deadlock", raw_error = error),
+        std::io::ErrorKind::CrossesDevices => t!("io_error.crosses_devices", raw_error = error),
+        std::io::ErrorKind::TooManyLinks => t!("io_error.too_many_links", raw_error = error),
+        std::io::ErrorKind::InvalidFilename => t!("io_error.invalid_filename", raw_error = error),
+        std::io::ErrorKind::ArgumentListTooLong => {
+            t!("io_error.argument_list_too_long", raw_error = error)
+        }
+        std::io::ErrorKind::Interrupted => t!("io_error.interrupted", raw_error = error),
+        std::io::ErrorKind::Unsupported => t!("io_error.unsupported", raw_error = error),
+        std::io::ErrorKind::UnexpectedEof => t!("io_error.unexpected_eof", raw_error = error),
+        std::io::ErrorKind::OutOfMemory => t!("io_error.out_of_memory", raw_error = error),
+        std::io::ErrorKind::Other => t!("io_error.other", error = error.to_string()),
+        _ => t!("io_error.other", error = error.to_string()),
+    }
+}
diff --git a/src/lib.rs b/src/lib.rs
index 74b68f1..13629ce 100644
--- a/src/lib.rs
+++ b/src/lib.rs
@@ -13,3 +13,6 @@ pub mod systems;
 
 /// Commands
 pub mod cmds;
+
+/// Macros
+pub mod macros;
diff --git a/src/macros.rs b/src/macros.rs
new file mode 100644
index 0000000..134b301
--- /dev/null
+++ b/src/macros.rs
@@ -0,0 +1 @@
+pub mod command_flag;
diff --git a/src/macros/command_flag.rs b/src/macros/command_flag.rs
new file mode 100644
index 0000000..894b3f4
--- /dev/null
+++ b/src/macros/command_flag.rs
@@ -0,0 +1,33 @@
+#[macro_export]
+macro_rules! special_flag {
+    ($args:expr, $flag:expr) => {{
+        let flag = $flag;
+        let found = $args.iter().any(|arg| arg == flag);
+        $args.retain(|arg| arg != flag);
+        found
+    }};
+}
+
+#[macro_export]
+macro_rules! special_argument {
+    ($args:expr, $flag:expr) => {{
+        let flag = $flag;
+        let mut value: Option<String> = None;
+        let mut i = 0;
+        while i < $args.len() {
+            if $args[i] == flag {
+                if i + 1 < $args.len() {
+                    value = Some($args[i + 1].clone());
+                    $args.remove(i + 1);
+                    $args.remove(i);
+                } else {
+                    value = None;
+                    $args.remove(i);
+                }
+                break;
+            }
+            i += 1;
+        }
+        value
+    }};
+}
diff --git a/src/systems.rs b/src/systems.rs
index 7f77ca5..2ca53be 100644
--- a/src/systems.rs
+++ b/src/systems.rs
@@ -1,2 +1,3 @@
 pub mod cmd;
+pub mod debug;
 pub mod render;
diff --git a/src/systems/cmd/cmd_system.rs b/src/systems/cmd/cmd_system.rs
index 1fe6e66..57aa15d 100644
--- a/src/systems/cmd/cmd_system.rs
+++ b/src/systems/cmd/cmd_system.rs
@@ -1,3 +1,6 @@
+use log::{error, info};
+use rust_i18n::t;
+
 use crate::{
     r_println,
     systems::{
@@ -6,11 +9,13 @@ use crate::{
     },
 };
 use std::{
-    any::{Any, TypeId},
+    any::{Any, TypeId, type_name},
     collections::HashMap,
     future::Future,
 };
 
+rust_i18n::i18n!("resources/locales/jvn", fallback = "en");
+
 pub struct JVCommandContext {
     pub help: bool,
     pub confirmed: bool,
@@ -42,39 +47,17 @@ where
                 return Err(CmdProcessError::RendererOverrideButRequestHelp);
             }
 
+            info!("{}", t!("verbose.cmd_process"));
             let (data, type_id) = Self::process(args, ctx).await?;
 
-            let renderer_override = renderer_override.as_str();
+            let renderer = renderer_override.as_str();
 
             // Serialize the data based on its concrete type
-            let render_result: Result<JVRenderResult, CmdRenderError> = if type_id
-                == std::any::TypeId::of::<crate::cmds::out::hex::JVHexOutput>()
-            {
-                let concrete_data = data
-                    .downcast::<crate::cmds::out::hex::JVHexOutput>()
-                    .map_err(|_| CmdProcessError::DowncastFailed)?;
-                include!("../render/_override_renderer_dispatcher.rs")
-            } else if type_id
-                == std::any::TypeId::of::<crate::cmds::out::mappings::JVMappingsOutput>()
-            {
-                let concrete_data = data
-                    .downcast::<crate::cmds::out::mappings::JVMappingsOutput>()
-                    .map_err(|_| CmdProcessError::DowncastFailed)?;
-                include!("../render/_override_renderer_dispatcher.rs")
-            } else if type_id == std::any::TypeId::of::<crate::cmds::out::status::JVStatusOutput>()
-            {
-                let concrete_data = data
-                    .downcast::<crate::cmds::out::status::JVStatusOutput>()
-                    .map_err(|_| CmdProcessError::DowncastFailed)?;
-                include!("../render/_override_renderer_dispatcher.rs")
-            } else {
-                return Err(CmdProcessError::NoMatchingCommand);
-            };
-
-            match render_result {
-                Ok(r) => Ok(r),
-                Err(e) => Err(CmdProcessError::Render(e)),
-            }
+            info!(
+                "{}",
+                t!("verbose.render_with_override_renderer", renderer = renderer)
+            );
+            include!("../render/_override_renderer_entry.rs")
         }
     }
 
@@ -93,7 +76,10 @@ where
                 return Ok(r);
             }
 
+            info!("{}", t!("verbose.cmd_process"));
             let (data, id) = Self::process(args, ctx).await?;
+
+            info!("{}", t!("verbose.render_with_specific_renderer"));
             match render(data, id).await {
                 Ok(r) => Ok(r),
                 Err(e) => Err(CmdProcessError::Render(e)),
@@ -111,22 +97,53 @@ where
 
             full_args.extend(args);
 
+            info!(
+                "{}",
+                t!("verbose.cmd_process_parse", t = type_name::<Argument>())
+            );
+
             let parsed_args = match Argument::try_parse_from(full_args) {
                 Ok(args) => args,
-                Err(_) => return Err(CmdProcessError::ParseError(Self::get_help_str())),
+                Err(_) => {
+                    error!(
+                        "{}",
+                        t!(
+                            "verbose.cmd_process_parse_failed",
+                            t = type_name::<Argument>()
+                        )
+                    );
+                    return Err(CmdProcessError::ParseError(Self::get_help_str()));
+                }
             };
 
+            info!(
+                "{}",
+                t!(
+                    "verbose.cmd_process_prepare",
+                    i = type_name::<Input>(),
+                    c = type_name::<Collect>()
+                )
+            );
+
             let (input, collect) = match tokio::try_join!(
                 Self::prepare(&parsed_args, &ctx),
                 Self::collect(&parsed_args, &ctx)
             ) {
                 Ok((input, collect)) => (input, collect),
-                Err(e) => return Err(CmdProcessError::from(e)),
+                Err(e) => {
+                    error!("{}", t!("verbose.cmd_process_prepare_failed"));
+                    return Err(CmdProcessError::from(e));
+                }
             };
 
+            info!("{}", t!("verbose.cmd_process_exec"));
+
             let data = match Self::exec(input, collect).await {
                 Ok(output) => output,
-                Err(e) => return Err(CmdProcessError::from(e)),
+                Err(e) => {
+                    error!("{}", t!("verbose.cmd_process_exec_failed"));
+                    return Err(CmdProcessError::from(e));
+                }
             };
 
             Ok(data)
diff --git a/src/systems/cmd/processer.rs b/src/systems/cmd/processer.rs
index 196764a..0f68afb 100644
--- a/src/systems/cmd/processer.rs
+++ b/src/systems/cmd/processer.rs
@@ -1,13 +1,20 @@
+use log::{error, info, warn};
+use rust_i18n::t;
+
 use crate::systems::cmd::_commands::{jv_cmd_nodes, jv_cmd_process_node};
 use crate::systems::cmd::cmd_system::JVCommandContext;
 use crate::systems::cmd::errors::CmdProcessError;
 use crate::systems::render::renderer::JVRenderResult;
 
+rust_i18n::i18n!("resources/locales/jvn", fallback = "en");
+
 pub async fn jv_cmd_process(
     args: &Vec<String>,
     ctx: JVCommandContext,
     renderer_override: String,
 ) -> Result<JVRenderResult, CmdProcessError> {
+    info!("{}", t!("verbose.cmd_process_start"));
+
     let nodes = jv_cmd_nodes();
 
     // Why add a space?
@@ -27,10 +34,18 @@ pub async fn jv_cmd_process(
     match matching_nodes.len() {
         0 => {
             // No matching node found
+            error!("{}", t!("verbose.cmd_match_no_node"));
             return Err(CmdProcessError::NoMatchingCommand);
         }
         1 => {
             let matched_prefix = matching_nodes[0];
+
+            // DEBUG
+            info!(
+                "{}",
+                t!("verbose.cmd_match_matched_single", node = matched_prefix)
+            );
+
             let prefix_len = matched_prefix.split_whitespace().count();
             let trimmed_args: Vec<String> = args.into_iter().cloned().skip(prefix_len).collect();
             return jv_cmd_process_node(matched_prefix, trimmed_args, ctx, renderer_override).await;
@@ -39,6 +54,22 @@ pub async fn jv_cmd_process(
             // Multiple matching nodes found
             // Find the node with the longest length (most specific match)
             let matched_prefix = matching_nodes.iter().max_by_key(|node| node.len()).unwrap();
+
+            // DEBUG
+            let nodes_str = matching_nodes
+                .iter()
+                .map(|s| s.as_str())
+                .collect::<Vec<_>>()
+                .join(", ");
+            warn!(
+                "{}",
+                t!(
+                    "verbose.cmd_match_matched_multi",
+                    nodes = nodes_str,
+                    node = matched_prefix
+                )
+            );
+
             let prefix_len = matched_prefix.split_whitespace().count();
             let trimmed_args: Vec<String> = args.into_iter().cloned().skip(prefix_len).collect();
             return jv_cmd_process_node(matched_prefix, trimmed_args, ctx, renderer_override).await;
diff --git a/src/systems/debug.rs b/src/systems/debug.rs
new file mode 100644
index 0000000..be544e8
--- /dev/null
+++ b/src/systems/debug.rs
@@ -0,0 +1 @@
+pub mod verbose_logger;
diff --git a/src/systems/debug/verbose_logger.rs b/src/systems/debug/verbose_logger.rs
new file mode 100644
index 0000000..ceb8bd8
--- /dev/null
+++ b/src/systems/debug/verbose_logger.rs
@@ -0,0 +1,43 @@
+use chrono::Local;
+use env_logger::Builder;
+use log::Level;
+use rust_i18n::t;
+use std::io::Write;
+
+rust_i18n::i18n!("resources/locales/jvn", fallback = "en");
+
+pub fn init_verbose_logger(level_filter: Option<log::LevelFilter>) {
+    let mut builder = match level_filter {
+        Some(f) => {
+            let mut b = Builder::new();
+            b.filter_level(f);
+            b
+        }
+        None => return,
+    };
+
+    builder
+        .format(|buf, record| {
+            let now = Local::now();
+            let timestamp = now.format("%y-%-m-%-d %H:%M:%S");
+            let level = record.level();
+            let args = record.args();
+
+            let (prefix, color_code) = match level {
+                Level::Error => (t!("logger.error").trim().to_string(), "\x1b[31m"),
+                Level::Warn => (t!("logger.warn").trim().to_string(), "\x1b[33m"),
+                Level::Info => (t!("logger.info").trim().to_string(), "\x1b[37m"),
+                Level::Debug => (t!("logger.debug").trim().to_string(), "\x1b[90m"),
+                Level::Trace => (t!("logger.trace").trim().to_string(), "\x1b[36m"),
+            };
+
+            let colored_prefix = if prefix.is_empty() {
+                String::new()
+            } else {
+                format!("{}[{}] {}: \x1b[0m", color_code, timestamp, prefix)
+            };
+
+            writeln!(buf, "{}{}", colored_prefix, args)
+        })
+        .init();
+}