Refactoring for better logging mechanism

Allow user to use log macros with default logger.

README.md

@@ -17,11 +17,11 @@ exit status or collect all of its output. However, when
 [Redirection](https://en.wikipedia.org/wiki/Redirection_(computing)) or
 [Piping](https://en.wikipedia.org/wiki/Redirection_(computing)#Piping) is needed, you need to
 set up the parent and child IO handles manually, like this in the
-[rust cookbook](https://rust-lang-nursery.github.io/rust-cookbook/os/external.html), which is often a tedious
-work.
+[rust cookbook](https://rust-lang-nursery.github.io/rust-cookbook/os/external.html), which is often tedious
+and [error prone](https://github.com/ijackson/rust-rfcs/blob/command/text/0000-command-ergonomics.md#currently-accepted-wrong-programs).
 
 A lot of developers just choose shell(sh, bash, ...) scripts for such tasks, by using `<` to redirect input,
-`>` to redirect output and '|' to pipe outputs. In my experience, this is **the only good parts** of shell script.
+`>` to redirect output and `|` to pipe outputs. In my experience, this is **the only good parts** of shell script.
 You can find all kinds of pitfalls and mysterious tricks to make other parts of shell script work. As the shell
 scripts grow, they will ultimately be unmaintainable and no one wants to touch them any more.
 
@@ -52,11 +52,10 @@ let now = Instant::now();
         | awk r#"/copied/{print $(NF-1) " " $NF}"#
     )
     .unwrap_or_else(|_| cmd_die!("thread $i failed"));
-    log::info!("thread {i} bandwidth: {bandwidth}");
+    info!("thread {i} bandwidth: {bandwidth}");
 });
-let total_bandwidth = Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128)
-    .get_appropriate_unit(true);
-log::info!("Total bandwidth: {total_bandwidth}/s");
+let total_bandwidth = Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128).get_appropriate_unit(true);
+info!("Total bandwidth: {total_bandwidth}/s");
 ```
 
 Output will be like this:
@@ -168,15 +167,16 @@ Right now piping and stdin, stdout, stderr redirection are supported. Most parts
 #### Logging
 
 This library provides convenient macros and builtin commands for logging. All messages which
-are printed to stderr will be logged. Since it is returning result type, you can also log the
-errors if command execution fails.
+are printed to stderr will be logged. It will also include the full running commands in the error
+result.
 
 ```rust
 let dir: &str = "folder with spaces";
-assert!(run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir).is_ok());
-assert!(run_cmd!(mkdir /tmp/"$dir"; ls /tmp/"$dir"; rmdir /tmp/"$dir").is_err());
+run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir)?;
+run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir; rmdir /tmp/$dir)?;
 // output:
 // [INFO ] mkdir: cannot create directory ‘/tmp/folder with spaces’: File exists
+// Error: Running ["mkdir" "/tmp/folder with spaces"] exited with error; status code: 1
 ```
 
 It is using rust [log crate](https://crates.io/crates/log), and you can use your actual favorite

examples/dd_test.rs

@@ -54,11 +54,11 @@ fn main() -> MainResult {
             | awk r#"/copied/{print $(NF-1) " " $NF}"#
         )
         .unwrap_or_else(|_| cmd_die!("thread $i failed"));
-        log::info!("thread {i} bandwidth: {bandwidth}");
+        info!("thread {i} bandwidth: {bandwidth}");
     });
-    let total_bandwidth = Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128)
-        .get_appropriate_unit(true);
-    log::info!("Total bandwidth: {total_bandwidth}/s");
+    let total_bandwidth =
+        Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128).get_appropriate_unit(true);
+    info!("Total bandwidth: {total_bandwidth}/s");
 
     Ok(())
 }

examples/pipes.rs

@@ -148,7 +148,7 @@ fn parse() -> CmdResult {
     // $arg and $OPTARG are the option name and argument set by getopts.
     fn pearg(arg: &str, msg: &str) -> ! {
         let arg0 = prog_name();
-        log::info!("{arg0}: -{arg} invalid argument; {msg}");
+        info!("{arg0}: -{arg} invalid argument; {msg}");
         print_help();
         std::process::exit(1)
     }

macros/src/lib.rs

@@ -176,7 +176,7 @@ pub fn spawn(input: proc_macro::TokenStream) -> proc_macro::TokenStream {
 ///
 /// for (i, mut proc) in procs.into_iter().enumerate() {
 ///     let bandwidth = proc.wait_with_output()?;
-///     log::info!("thread {i} bandwidth: {bandwidth} MB/s")?;
+///     info!("thread {i} bandwidth: {bandwidth} MB/s")?;
 /// }
 /// # Ok::<(), std::io::Error>(())
 /// ```
@@ -210,9 +210,9 @@ pub fn spawn_with_output(input: proc_macro::TokenStream) -> proc_macro::TokenStr
 pub fn cmd_die(input: proc_macro::TokenStream) -> proc_macro::TokenStream {
     let msg = parse_msg(input.into());
     quote!({
+        use ::cmd_lib::error;
         use ::cmd_lib::AsOsStr;
-        let _ = ::cmd_lib::try_init_default_logger();
-        ::cmd_lib::log::error!("FATAL: {}", #msg);
+        error!("FATAL: {}", #msg);
         std::process::exit(1)
     })
     .into()

src/builtins.rs

@@ -1,6 +1,5 @@
-use crate::logger::try_init_default_logger;
+use crate::{debug, error, info, trace, warn};
 use crate::{CmdEnv, CmdResult};
-use log::*;
 use std::io::Write;
 
 pub(crate) fn builtin_echo(env: &mut CmdEnv) -> CmdResult {
@@ -9,31 +8,26 @@ pub(crate) fn builtin_echo(env: &mut CmdEnv) -> CmdResult {
 }
 
 pub(crate) fn builtin_error(env: &mut CmdEnv) -> CmdResult {
-    let _ = try_init_default_logger();
     error!("{}", env.args()[1..].join(" "));
     Ok(())
 }
 
 pub(crate) fn builtin_warn(env: &mut CmdEnv) -> CmdResult {
-    let _ = try_init_default_logger();
     warn!("{}", env.args()[1..].join(" "));
     Ok(())
 }
 
 pub(crate) fn builtin_info(env: &mut CmdEnv) -> CmdResult {
-    let _ = try_init_default_logger();
     info!("{}", env.args()[1..].join(" "));
     Ok(())
 }
 
 pub(crate) fn builtin_debug(env: &mut CmdEnv) -> CmdResult {
-    let _ = try_init_default_logger();
     debug!("{}", env.args()[1..].join(" "));
     Ok(())
 }
 
 pub(crate) fn builtin_trace(env: &mut CmdEnv) -> CmdResult {
-    let _ = try_init_default_logger();
     trace!("{}", env.args()[1..].join(" "));
     Ok(())
 }

src/child.rs

@@ -1,6 +1,5 @@
-use crate::logger::try_init_default_logger;
+use crate::{info, warn};
 use crate::{process, CmdResult, FunResult};
-use log::{info, warn};
 use os_pipe::PipeReader;
 use std::io::{BufRead, BufReader, Error, ErrorKind, Read, Result};
 use std::process::{Child, ExitStatus};
@@ -285,10 +284,7 @@ impl StderrLogging {
                 BufReader::new(stderr)
                     .lines()
                     .map_while(Result::ok)
-                    .for_each(|line| {
-                        let _ = try_init_default_logger();
-                        info!("{}", line)
-                    })
+                    .for_each(|line| info!("{}", line))
             });
             Self {
                 cmd: cmd.into(),
@@ -307,7 +303,6 @@ impl Drop for StderrLogging {
     fn drop(&mut self) {
         if let Some(thread) = self.thread.take() {
             if let Err(e) = thread.join() {
-                let _ = try_init_default_logger();
                 warn!("[{}] logging thread exited with error: {:?}", self.cmd, e);
             }
         }

src/io.rs

@@ -3,7 +3,6 @@ use std::fs::File;
 use std::io::{Read, Result, Write};
 use std::process::Stdio;
 
-#[derive(Debug)]
 pub enum CmdIn {
     Null,
     File(File),
@@ -30,7 +29,6 @@ impl From<CmdIn> for Stdio {
     }
 }
 
-#[derive(Debug)]
 pub enum CmdOut {
     Null,
     File(File),

src/lib.rs

@@ -15,11 +15,11 @@
 //! [Redirection](https://en.wikipedia.org/wiki/Redirection_(computing)) or
 //! [Piping](https://en.wikipedia.org/wiki/Redirection_(computing)#Piping) is needed, you need to
 //! set up the parent and child IO handles manually, like this in the
-//! [rust cookbook](https://rust-lang-nursery.github.io/rust-cookbook/os/external.html), which is often a tedious
-//! work.
+//! [rust cookbook](https://rust-lang-nursery.github.io/rust-cookbook/os/external.html), which is often tedious
+//! and [error prone](https://github.com/ijackson/rust-rfcs/blob/command/text/0000-command-ergonomics.md#currently-accepted-wrong-programs).
 //!
 //! A lot of developers just choose shell(sh, bash, ...) scripts for such tasks, by using `<` to redirect input,
-//! `>` to redirect output and '|' to pipe outputs. In my experience, this is **the only good parts** of shell script.
+//! `>` to redirect output and `|` to pipe outputs. In my experience, this is **the only good parts** of shell script.
 //! You can find all kinds of pitfalls and mysterious tricks to make other parts of shell script work. As the shell
 //! scripts grow, they will ultimately be unmaintainable and no one wants to touch them any more.
 //!
@@ -58,11 +58,10 @@
 //!         | awk r#"/copied/{print $(NF-1) " " $NF}"#
 //!     )
 //!     .unwrap_or_else(|_| cmd_die!("thread $i failed"));
-//!     log::info!("thread {i} bandwidth: {bandwidth}");
+//!     info!("thread {i} bandwidth: {bandwidth}");
 //! });
-//! let total_bandwidth = Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128)
-//!     .get_appropriate_unit(true);
-//! log::info!("Total bandwidth: {total_bandwidth}/s");
+//! let total_bandwidth = Byte::from_bytes((DATA_SIZE / now.elapsed().as_secs()) as u128).get_appropriate_unit(true);
+//! info!("Total bandwidth: {total_bandwidth}/s");
 //! # Ok::<(), std::io::Error>(())
 //! ```
 //!
@@ -185,16 +184,18 @@
 //! ### Logging
 //!
 //! This library provides convenient macros and builtin commands for logging. All messages which
-//! are printed to stderr will be logged. Since it is returning result type, you can also log the
-//! errors if command execution fails.
+//! are printed to stderr will be logged. It will also include the full running commands in the error
+//! result.
 //!
 //! ```no_run
 //! # use cmd_lib::*;
 //! let dir: &str = "folder with spaces";
-//! assert!(run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir).is_ok());
-//! assert!(run_cmd!(mkdir /tmp/"$dir"; ls /tmp/"$dir"; rmdir /tmp/"$dir").is_err());
+//! run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir)?;
+//! run_cmd!(mkdir /tmp/$dir; ls /tmp/$dir; rmdir /tmp/$dir)?;
 //! // output:
 //! // [INFO ] mkdir: cannot create directory ‘/tmp/folder with spaces’: File exists
+//! // Error: Running ["mkdir" "/tmp/folder with spaces"] exited with error; status code: 1
+//! # Ok::<(), std::io::Error>(())
 //! ```
 //!
 //! It is using rust [log crate](https://crates.io/crates/log), and you can use your actual favorite
@@ -361,9 +362,10 @@ pub type FunResult = std::io::Result<String>;
 pub type CmdResult = std::io::Result<()>;
 pub use child::{CmdChildren, FunChildren};
 #[doc(hidden)]
-pub use log;
+pub use log as inner_log;
 #[doc(hidden)]
 pub use logger::try_init_default_logger;
+#[doc(hidden)]
 pub use main_error::MainError;
 pub use main_error::MainResult;
 #[doc(hidden)]

src/logger.rs

@@ -1,10 +1,53 @@
 use env_logger::Env;
-use log::SetLoggerError;
 
-#[doc(hidden)]
-pub fn try_init_default_logger() -> Result<(), SetLoggerError> {
-    env_logger::Builder::from_env(Env::default().default_filter_or("info"))
+pub fn try_init_default_logger() {
+    let _ = env_logger::Builder::from_env(Env::default().default_filter_or("info"))
         .format_target(false)
         .format_timestamp(None)
-        .try_init()
+        .try_init();
+}
+
+#[doc(hidden)]
+#[macro_export]
+macro_rules! error {
+    ($($arg:tt)*) => {{
+        $crate::try_init_default_logger();
+        $crate::inner_log::error!($($arg)*);
+    }}
+}
+
+#[doc(hidden)]
+#[macro_export]
+macro_rules! warn {
+    ($($arg:tt)*) => {{
+        $crate::try_init_default_logger();
+        $crate::inner_log::warn!($($arg)*);
+    }}
+}
+
+#[doc(hidden)]
+#[macro_export]
+macro_rules! info {
+    ($($arg:tt)*) => {{
+        $crate::try_init_default_logger();
+        $crate::inner_log::info!($($arg)*);
+    }}
+}
+
+#[doc(hidden)]
+#[macro_export]
+macro_rules! debug {
+    ($($arg:tt)*) => {{
+        $crate::try_init_default_logger();
+        $crate::inner_log::debug!($($arg)*);
+    }}
+}
+
+#[doc(hidden)]
+#[macro_export]
+macro_rules! trace {
+    ($($arg:tt)*) => {{
+        $crate::try_init_default_logger();
+        $crate::inner_log::trace!($($arg)*);
+    }}
 }

src/process.rs

@@ -1,11 +1,10 @@
 use crate::builtins::*;
 use crate::child::{CmdChild, CmdChildHandle, CmdChildren, FunChildren};
 use crate::io::{CmdIn, CmdOut};
-use crate::logger::try_init_default_logger;
+use crate::{debug, warn};
 use crate::{CmdResult, FunResult};
 use faccess::{AccessMode, PathExt};
 use lazy_static::lazy_static;
-use log::{debug, warn};
 use os_pipe::{self, PipeReader, PipeWriter};
 use std::collections::HashMap;
 use std::ffi::{OsStr, OsString};
@@ -172,7 +171,6 @@ impl Cmds {
                 // first command in the pipe
                 self.ignore_error = true;
             } else {
-                let _ = try_init_default_logger();
                 warn!("Builtin {IGNORE_CMD:?} command at wrong position");
             }
         }
@@ -183,7 +181,6 @@ impl Cmds {
     fn spawn(&mut self, current_dir: &mut PathBuf, with_output: bool) -> Result<CmdChildren> {
         let full_cmds = format!("[{}]", self.full_cmds);
         if debug_enabled() {
-            let _ = try_init_default_logger();
             debug!("Running {full_cmds} ...");
         }