Merge pull request #309 from tmuehlbacher/improve-logging-exiting

Improve logging and exiting

Cargo.lock

@@ -80,8 +80,8 @@ dependencies = [
  "byteorder",
  "clap",
  "clap_complete",
- "colored",
  "either",
+ "env_logger",
  "errno 0.2.8",
  "libc",
  "log",
@@ -246,22 +246,23 @@ version = "1.0.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "acbf1af155f9b9ef647e42cdc158db4b64a1b61f743629225fde6f3e0be2a7c7"
 
-[[package]]
-name = "colored"
-version = "2.1.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "cbf2150cce219b664a8a70df7a1f933836724b503f8a413af9365b4dcc4d90b8"
-dependencies = [
- "lazy_static",
- "windows-sys 0.48.0",
-]
-
 [[package]]
 name = "either"
 version = "1.9.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "a26ae43d7bcc3b814de94796a5e736d4029efb0ee900c12e2d54c993ad1a1e07"
 
+[[package]]
+name = "env_logger"
+version = "0.10.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4cd405aab171cb85d6735e5c8d9db038c17d3ca007a4d2c25f337935c3d90580"
+dependencies = [
+ "is-terminal",
+ "log",
+ "termcolor",
+]
+
 [[package]]
 name = "errno"
 version = "0.2.8"
@@ -305,6 +306,12 @@ version = "0.4.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "95505c38b4572b2d910cecb0281560f54b440a19336cbbcb27bf6ce6adc6f5a8"
 
+[[package]]
+name = "hermit-abi"
+version = "0.3.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d231dfb89cfffdbc30e7fc41579ed6066ad03abda9e567ccafae602b97ec5024"
+
 [[package]]
 name = "home"
 version = "0.5.9"
@@ -314,6 +321,17 @@ dependencies = [
  "windows-sys 0.52.0",
 ]
 
+[[package]]
+name = "is-terminal"
+version = "0.4.12"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f23ff5ef2b80d608d61efee834934d862cd92461afc0560dedf493e4c033738b"
+dependencies = [
+ "hermit-abi",
+ "libc",
+ "windows-sys 0.52.0",
+]
+
 [[package]]
 name = "itertools"
 version = "0.12.1"
@@ -369,9 +387,9 @@ checksum = "01cda141df6706de531b6c46c3a33ecca755538219bd484262fa09410c13539c"
 
 [[package]]
 name = "log"
-version = "0.4.20"
+version = "0.4.22"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "b5e6163cb8c49088c2c36f57875e58ccd8c87c7427f7fbd50ea6710b2f3f2e8f"
+checksum = "a7a70ba024b9dc04c27ea2f0c0548feb474ec5c54bba33a7f72f873a39d07b24"
 
 [[package]]
 name = "memchr"
@@ -570,6 +588,15 @@ dependencies = [
  "unicode-ident",
 ]
 
+[[package]]
+name = "termcolor"
+version = "1.4.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "06794f8f6c5c898b3275aebefa6b8a1cb24cd2c6c79397ab15774837a0bc5755"
+dependencies = [
+ "winapi-util",
+]
+
 [[package]]
 name = "terminal_size"
 version = "0.3.0"
@@ -637,6 +664,15 @@ version = "0.4.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6"
 
+[[package]]
+name = "winapi-util"
+version = "0.1.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4d4cc384e1e73b93bafa6fb4f1df8c41695c8a91cf9c4c64358067d15a7b6c6b"
+dependencies = [
+ "windows-sys 0.52.0",
+]
+
 [[package]]
 name = "winapi-x86_64-pc-windows-gnu"
 version = "0.4.0"

Cargo.toml

@@ -11,7 +11,6 @@ path = "src/bcachefs.rs"
 
 [dependencies]
 log = { version = "0.4", features = ["std"] }
-colored = "2"
 clap = { version = "4.0.32", features = ["derive", "wrap_help"] }
 clap_complete = "4.3.2"
 anyhow = "1.0"
@@ -26,3 +25,8 @@ byteorder = "1.3"
 strum = { version = "0.26", features = ["derive"] }
 strum_macros = "0.26"
 zeroize = { version = "1", features = ["std", "zeroize_derive"] }
+
+[dependencies.env_logger]
+version = "0.10"
+default-features = false
+features = ["auto-color"]

src/bcachefs.rs

@@ -1,11 +1,14 @@
 mod commands;
 mod key;
+mod logging;
 mod wrappers;
 
-use std::ffi::{c_char, CString};
+use std::{
+    ffi::{c_char, CString},
+    process::{ExitCode, Termination},
+};
 
 use bch_bindgen::c;
-use commands::logger::SimpleLogger;
 
 #[derive(Debug)]
 pub struct ErrnoError(pub errno::Errno);
@@ -71,7 +74,7 @@ fn handle_c_command(mut argv: Vec<String>, symlink_cmd: Option<&str>) -> i32 {
     }
 }
 
-fn main() {
+fn main() -> ExitCode {
     let args: Vec<String> = std::env::args().collect();
 
     let symlink_cmd: Option<&str> = if args[0].contains("mkfs") {
@@ -89,28 +92,24 @@ fn main() {
     if symlink_cmd.is_none() && args.len() < 2 {
         println!("missing command");
         unsafe { c::bcachefs_usage() };
-        std::process::exit(1);
+        return ExitCode::from(1);
     }
 
     unsafe { c::raid_init() };
 
-    log::set_boxed_logger(Box::new(SimpleLogger)).unwrap();
-    log::set_max_level(log::LevelFilter::Warn);
-
     let cmd = match symlink_cmd {
         Some(s) => s,
         None => args[1].as_str(),
     };
 
-    let ret = match cmd {
+    match cmd {
-        "completions" => commands::completions(args[1..].to_vec()),
+        "completions" => {
-        "list" => commands::list(args[1..].to_vec()),
+            commands::completions(args[1..].to_vec());
-        "mount" => commands::mount(args, symlink_cmd),
+            ExitCode::SUCCESS
-        "subvolume" => commands::subvolume(args[1..].to_vec()),
+        }
-        _ => handle_c_command(args, symlink_cmd),
+        "list" => commands::list(args[1..].to_vec()).report(),
-    };
+        "mount" => commands::mount(args, symlink_cmd).report(),
-
+        "subvolume" => commands::subvolume(args[1..].to_vec()).report(),
-    if ret != 0 {
+        _ => ExitCode::from(u8::try_from(handle_c_command(args, symlink_cmd)).unwrap()),
-        std::process::exit(1);
     }
 }

src/commands/completions.rs

@@ -12,8 +12,7 @@ fn print_completions<G: Generator>(gen: G, cmd: &mut Command) {
     generate(gen, cmd, cmd.get_name().to_string(), &mut io::stdout());
 }
 
-pub fn completions(argv: Vec<String>) -> i32 {
+pub fn completions(argv: Vec<String>) {
     let cli = Cli::parse_from(argv);
     print_completions(cli.shell, &mut super::Cli::command());
-    0
 }

src/commands/list.rs

@@ -1,3 +1,4 @@
+use anyhow::Result;
 use bch_bindgen::bcachefs;
 use bch_bindgen::bkey::BkeySC;
 use bch_bindgen::btree::BtreeIter;
@@ -7,9 +8,10 @@ use bch_bindgen::btree::BtreeTrans;
 use bch_bindgen::fs::Fs;
 use bch_bindgen::opt_set;
 use clap::Parser;
-use log::error;
 use std::io::{stdout, IsTerminal};
 
+use crate::logging;
+
 fn list_keys(fs: &Fs, opt: &Cli) -> anyhow::Result<()> {
     let trans = BtreeTrans::new(fs);
     let mut iter = BtreeIter::new(
@@ -145,13 +147,18 @@ pub struct Cli {
     #[arg(short, long)]
     fsck: bool,
 
+    // FIXME: would be nicer to have `--color[=WHEN]` like diff or ls?
     /// Force color on/off. Default: autodetect tty
     #[arg(short, long, action = clap::ArgAction::Set, default_value_t=stdout().is_terminal())]
     colorize: bool,
 
-    /// Verbose mode
+    /// Quiet mode
     #[arg(short, long)]
-    verbose: bool,
+    quiet: bool,
+
+    /// Verbose mode
+    #[arg(short, long, action = clap::ArgAction::Count)]
+    verbose: u8,
 
     #[arg(required(true))]
     devices: Vec<std::path::PathBuf>,
@@ -180,7 +187,7 @@ fn cmd_list_inner(opt: &Cli) -> anyhow::Result<()> {
         opt_set!(fs_opts, norecovery, 0);
     }
 
-    if opt.verbose {
+    if opt.verbose > 0 {
         opt_set!(fs_opts, verbose, 1);
     }
 
@@ -194,13 +201,11 @@ fn cmd_list_inner(opt: &Cli) -> anyhow::Result<()> {
     }
 }
 
-pub fn list(argv: Vec<String>) -> i32 {
+pub fn list(argv: Vec<String>) -> Result<()> {
     let opt = Cli::parse_from(argv);
-    colored::control::set_override(opt.colorize);
+
-    if let Err(e) = cmd_list_inner(&opt) {
+    // TODO: centralize this on the top level CLI
-        error!("Fatal error: {}", e);
+    logging::setup(opt.quiet, opt.verbose, opt.colorize);
-        1
+
-    } else {
+    cmd_list_inner(&opt)
-        0
-    }
 }

src/commands/logger.rs

@@ -1,28 +0,0 @@
-use colored::Colorize;
-use log::{Level, Metadata, Record};
-
-pub struct SimpleLogger;
-
-impl log::Log for SimpleLogger {
-    fn enabled(&self, _: &Metadata) -> bool {
-        true
-    }
-
-    fn log(&self, record: &Record) {
-        let debug_prefix = match record.level() {
-            Level::Error => "ERROR".bright_red(),
-            Level::Warn => "WARN".bright_yellow(),
-            Level::Info => "INFO".green(),
-            Level::Debug => "DEBUG".bright_blue(),
-            Level::Trace => "TRACE".into(),
-        };
-        eprintln!(
-            "{} - {}: {}",
-            debug_prefix,
-            record.module_path().unwrap_or_default().bright_black(),
-            record.args()
-        );
-    }
-
-    fn flush(&self) {}
-}

src/commands/mod.rs

@@ -2,7 +2,6 @@ use clap::Subcommand;
 
 pub mod completions;
 pub mod list;
-pub mod logger;
 pub mod mount;
 pub mod subvolume;
 

src/commands/mount.rs

@@ -11,10 +11,13 @@ use std::{
 use anyhow::{ensure, Result};
 use bch_bindgen::{bcachefs, bcachefs::bch_sb_handle, opt_set, path_to_cstr};
 use clap::Parser;
-use log::{debug, error, info, LevelFilter};
+use log::{debug, info};
 use uuid::Uuid;
 
-use crate::key::{KeyHandle, Passphrase, UnlockPolicy};
+use crate::{
+    key::{KeyHandle, Passphrase, UnlockPolicy},
+    logging,
+};
 
 fn mount_inner(
     src: String,
@@ -242,10 +245,15 @@ pub struct Cli {
     #[arg(short, default_value = "")]
     options: String,
 
+    // FIXME: would be nicer to have `--color[=WHEN]` like diff or ls?
     /// Force color on/off. Autodetect tty is used to define default:
     #[arg(short, long, action = clap::ArgAction::Set, default_value_t=stdout().is_terminal())]
     colorize: bool,
 
+    /// Quiet mode
+    #[arg(short, long)]
+    quiet: bool,
+
     /// Verbose mode
     #[arg(short, long, action = clap::ArgAction::Count)]
     verbose: u8,
@@ -364,7 +372,7 @@ fn cmd_mount_inner(cli: &Cli) -> Result<()> {
     }
 }
 
-pub fn mount(mut argv: Vec<String>, symlink_cmd: Option<&str>) -> i32 {
+pub fn mount(mut argv: Vec<String>, symlink_cmd: Option<&str>) -> Result<()> {
     // If the bcachefs tool is being called as "bcachefs mount dev ..." (as opposed to via a
     // symlink like "/usr/sbin/mount.bcachefs dev ...", then we need to pop the 0th argument
     // ("bcachefs") since the CLI parser here expects the device at position 1.
@@ -374,19 +382,8 @@ pub fn mount(mut argv: Vec<String>, symlink_cmd: Option<&str>) -> i32 {
 
     let cli = Cli::parse_from(argv);
 
-    // @TODO : more granular log levels via mount option
+    // TODO: centralize this on the top level CLI
-    log::set_max_level(match cli.verbose {
+    logging::setup(cli.quiet, cli.verbose, cli.colorize);
-        0 => LevelFilter::Warn,
-        1 => LevelFilter::Trace,
-        2_u8..=u8::MAX => todo!(),
-    });
 
-    colored::control::set_override(cli.colorize);
+    cmd_mount_inner(&cli)
-    if let Err(e) = cmd_mount_inner(&cli) {
-        error!("Fatal error: {}", e);
-        1
-    } else {
-        info!("Successfully mounted");
-        0
-    }
 }

src/commands/subvolume.rs

@@ -1,5 +1,6 @@
 use std::{env, path::PathBuf};
 
+use anyhow::{Context, Result};
 use bch_bindgen::c::BCH_SUBVOL_SNAPSHOT_RO;
 use clap::{Parser, Subcommand};
 
@@ -36,7 +37,7 @@ enum Subcommands {
     },
 }
 
-pub fn subvolume(argv: Vec<String>) -> i32 {
+pub fn subvolume(argv: Vec<String>) -> Result<()> {
     let cli = Cli::parse_from(argv);
 
     match cli.subcommands {
@@ -47,25 +48,25 @@ pub fn subvolume(argv: Vec<String>) -> i32 {
                 } else {
                     env::current_dir()
                         .map(|p| p.join(target))
-                        .expect("unable to get current directory")
+                        .context("unable to get current directory")?
                 };
 
                 if let Some(dirname) = target.parent() {
                     let fs = unsafe { BcachefsHandle::open(dirname) };
                     fs.create_subvolume(target)
-                        .expect("Failed to create the subvolume");
+                        .context("Failed to create the subvolume")?;
                 }
             }
         }
         Subcommands::Delete { target } => {
             let target = target
                 .canonicalize()
-                .expect("subvolume path does not exist or can not be canonicalized");
+                .context("subvolume path does not exist or can not be canonicalized")?;
 
             if let Some(dirname) = target.parent() {
                 let fs = unsafe { BcachefsHandle::open(dirname) };
                 fs.delete_subvolume(target)
-                    .expect("Failed to delete the subvolume");
+                    .context("Failed to delete the subvolume")?;
             }
         }
         Subcommands::Snapshot {
@@ -91,10 +92,10 @@ pub fn subvolume(argv: Vec<String>) -> i32 {
                     source,
                     dest,
                 )
-                .expect("Failed to snapshot the subvolume");
+                .context("Failed to snapshot the subvolume")?;
             }
         }
     }
 
-    0
+    Ok(())
 }

src/logging.rs

@@ -0,0 +1,26 @@
+use env_logger::WriteStyle;
+use log::LevelFilter;
+
+pub fn setup(quiet: bool, verbose: u8, color: bool) {
+    let level_filter = if quiet {
+        LevelFilter::Off
+    } else {
+        match verbose {
+            0 => LevelFilter::Info,
+            1 => LevelFilter::Debug,
+            _ => LevelFilter::Trace,
+        }
+    };
+
+    let style = if color {
+        WriteStyle::Always
+    } else {
+        WriteStyle::Never
+    };
+
+    env_logger::Builder::new()
+        .filter_level(level_filter)
+        .write_style(style)
+        .parse_env("BCACHEFS_LOG")
+        .init();
+}