feat: more configurable logging levels (#1630)

* feat: make logging level more configurable

* chore: resolve lint warnings

* fix: correct default level for h2

* chore: update text copy

src/cmd/src/cli.rs

@@ -53,8 +53,8 @@ impl Command {
         if let Some(dir) = top_level_opts.log_dir {
             logging_opts.dir = dir;
         }
-        if let Some(level) = top_level_opts.log_level {
-            logging_opts.level = level;
+        if top_level_opts.log_level.is_some() {
+            logging_opts.level = top_level_opts.log_level;
         }
         Ok(Options::Cli(Box::new(logging_opts)))
     }
@@ -107,7 +107,7 @@ mod tests {
         let opts = cmd.load_options(TopLevelOptions::default()).unwrap();
         let logging_opts = opts.logging_options();
         assert_eq!("/tmp/greptimedb/logs", logging_opts.dir);
-        assert_eq!("info", logging_opts.level);
+        assert!(logging_opts.level.is_none());
         assert!(!logging_opts.enable_jaeger_tracing);
     }
 
@@ -129,6 +129,6 @@ mod tests {
             .unwrap();
         let logging_opts = opts.logging_options();
         assert_eq!("/tmp/greptimedb/test/logs", logging_opts.dir);
-        assert_eq!("debug", logging_opts.level);
+        assert_eq!("debug", logging_opts.level.as_ref().unwrap());
     }
 }

src/cmd/src/datanode.rs

@@ -113,8 +113,9 @@ impl StartCommand {
         if let Some(dir) = top_level_opts.log_dir {
             opts.logging.dir = dir;
         }
-        if let Some(level) = top_level_opts.log_level {
-            opts.logging.level = level;
+
+        if top_level_opts.log_level.is_some() {
+            opts.logging.level = top_level_opts.log_level;
         }
 
         if let Some(addr) = &self.rpc_addr {
@@ -300,7 +301,7 @@ mod tests {
             options.storage.manifest,
         );
 
-        assert_eq!("debug".to_string(), options.logging.level);
+        assert_eq!("debug", options.logging.level.unwrap());
         assert_eq!("/tmp/greptimedb/test/logs".to_string(), options.logging.dir);
     }
 
@@ -353,7 +354,7 @@ mod tests {
 
         let logging_opt = options.logging_options();
         assert_eq!("/tmp/greptimedb/test/logs", logging_opt.dir);
-        assert_eq!("debug", logging_opt.level);
+        assert_eq!("debug", logging_opt.level.as_ref().unwrap());
     }
 
     #[test]

src/cmd/src/frontend.rs

@@ -134,8 +134,9 @@ impl StartCommand {
         if let Some(dir) = top_level_opts.log_dir {
             opts.logging.dir = dir;
         }
-        if let Some(level) = top_level_opts.log_level {
-            opts.logging.level = level;
+
+        if top_level_opts.log_level.is_some() {
+            opts.logging.level = top_level_opts.log_level;
         }
 
         let tls_opts = TlsOption::new(
@@ -296,7 +297,7 @@ mod tests {
             [http_options]
             addr = "127.0.0.1:4000"
             timeout = "30s"
-            
+
             [logging]
             level = "debug"
             dir = "/tmp/greptimedb/test/logs"
@@ -321,7 +322,7 @@ mod tests {
             fe_opts.http_options.as_ref().unwrap().timeout
         );
 
-        assert_eq!("debug".to_string(), fe_opts.logging.level);
+        assert_eq!("debug", fe_opts.logging.level.as_ref().unwrap());
         assert_eq!("/tmp/greptimedb/test/logs".to_string(), fe_opts.logging.dir);
     }
 
@@ -365,7 +366,7 @@ mod tests {
 
         let logging_opt = options.logging_options();
         assert_eq!("/tmp/greptimedb/test/logs", logging_opt.dir);
-        assert_eq!("debug", logging_opt.level);
+        assert_eq!("debug", logging_opt.level.as_ref().unwrap());
     }
 
     #[test]
@@ -376,7 +377,7 @@ mod tests {
 
             [http_options]
             addr = "127.0.0.1:4000"
-            
+
             [meta_client_options]
             timeout_millis = 3000
             connect_timeout_millis = 5000

src/cmd/src/metasrv.rs

@@ -111,8 +111,9 @@ impl StartCommand {
         if let Some(dir) = top_level_opts.log_dir {
             opts.logging.dir = dir;
         }
-        if let Some(level) = top_level_opts.log_level {
-            opts.logging.level = level;
+
+        if top_level_opts.log_level.is_some() {
+            opts.logging.level = top_level_opts.log_level;
         }
 
         if let Some(addr) = &self.bind_addr {
@@ -220,7 +221,7 @@ mod tests {
         assert_eq!("127.0.0.1:2379".to_string(), options.store_addr);
         assert_eq!(15, options.datanode_lease_secs);
         assert_eq!(SelectorType::LeaseBased, options.selector);
-        assert_eq!("debug".to_string(), options.logging.level);
+        assert_eq!("debug", options.logging.level.as_ref().unwrap());
         assert_eq!("/tmp/greptimedb/test/logs".to_string(), options.logging.dir);
     }
 
@@ -243,7 +244,7 @@ mod tests {
 
         let logging_opt = options.logging_options();
         assert_eq!("/tmp/greptimedb/test/logs", logging_opt.dir);
-        assert_eq!("debug", logging_opt.level);
+        assert_eq!("debug", logging_opt.level.as_ref().unwrap());
     }
 
     #[test]
@@ -257,7 +258,7 @@ mod tests {
 
             [http_options]
             addr = "127.0.0.1:4000"
-            
+
             [logging]
             level = "debug"
             dir = "/tmp/greptimedb/test/logs"

src/cmd/src/standalone.rs

@@ -227,8 +227,9 @@ impl StartCommand {
         if let Some(dir) = top_level_options.log_dir {
             opts.logging.dir = dir;
         }
-        if let Some(level) = top_level_options.log_level {
-            opts.logging.level = level;
+
+        if top_level_options.log_level.is_some() {
+            opts.logging.level = top_level_options.log_level;
         }
 
         let tls_opts = TlsOption::new(
@@ -462,7 +463,7 @@ mod tests {
             }
         }
 
-        assert_eq!("debug".to_string(), logging_opts.level);
+        assert_eq!("debug", logging_opts.level.as_ref().unwrap());
         assert_eq!("/tmp/greptimedb/test/logs".to_string(), logging_opts.dir);
     }
 
@@ -483,7 +484,7 @@ mod tests {
         };
 
         assert_eq!("/tmp/greptimedb/test/logs", opts.logging.dir);
-        assert_eq!("debug", opts.logging.level);
+        assert_eq!("debug", opts.logging.level.unwrap());
     }
 
     #[test]
@@ -553,7 +554,7 @@ mod tests {
                 assert_eq!(opts.logging.dir, "/other/log/dir");
 
                 // Should be read from config file, config file > env > default values.
-                assert_eq!(opts.logging.level, "debug");
+                assert_eq!(opts.logging.level.as_ref().unwrap(), "debug");
 
                 // Should be read from cli, cli > config file > env > default values.
                 assert_eq!(

src/common/telemetry/src/logging.rs

@@ -36,7 +36,7 @@ pub use crate::{debug, error, info, log, trace, warn};
 #[serde(default)]
 pub struct LoggingOptions {
     pub dir: String,
-    pub level: String,
+    pub level: Option<String>,
     pub enable_jaeger_tracing: bool,
 }
 
@@ -44,7 +44,7 @@ impl Default for LoggingOptions {
     fn default() -> Self {
         Self {
             dir: "/tmp/greptimedb/logs".to_string(),
-            level: "info".to_string(),
+            level: None,
             enable_jaeger_tracing: false,
         }
     }
@@ -74,7 +74,7 @@ pub fn init_default_ut_logging() {
         let level = env::var("UNITTEST_LOG_LEVEL").unwrap_or_else(|_| "DEBUG".to_string());
         let opts = LoggingOptions {
             dir: dir.clone(),
-            level,
+            level: Some(level),
             ..Default::default()
         };
         *g = Some(init_global_logging(
@@ -90,6 +90,9 @@ pub fn init_default_ut_logging() {
 static GLOBAL_UT_LOG_GUARD: Lazy<Arc<Mutex<Option<Vec<WorkerGuard>>>>> =
     Lazy::new(|| Arc::new(Mutex::new(None)));
 
+const DEFAULT_LOG_TARGETS: &str =
+    "info,hyper=warn,tower=warn,datafusion=warn,reqwest=warn,sqlparser=warn,h2=info,opendal=info";
+
 #[allow(clippy::print_stdout)]
 pub fn init_global_logging(
     app_name: &str,
@@ -124,24 +127,18 @@ pub fn init_global_logging(
         BunyanFormattingLayer::new(app_name.to_string(), err_rolling_writer);
     guards.push(err_rolling_writer_guard);
 
-    // Use env RUST_LOG to initialize log if present.
-    // Otherwise use the specified level.
-    let directives = env::var(EnvFilter::DEFAULT_ENV).unwrap_or_else(|_x| level.to_string());
-    let filter = filter::Targets::new()
-        // Only enable WARN and ERROR for 3rd-party crates
-        // TODO(dennis): configure them?
-        .with_target("hyper", Level::WARN)
-        .with_target("tower", Level::WARN)
-        .with_target("datafusion", Level::WARN)
-        .with_target("reqwest", Level::WARN)
-        .with_target("sqlparser", Level::WARN)
-        .with_target("h2", Level::INFO)
-        .with_target("opendal", Level::INFO)
-        .with_default(
-            directives
-                .parse::<filter::LevelFilter>()
-                .expect("error parsing level string"),
-        );
+    // resolve log level settings from:
+    // - options from command line or config files
+    // - environment variable: RUST_LOG
+    // - default settings
+    let rust_log_env = std::env::var(EnvFilter::DEFAULT_ENV).ok();
+    let targets_string = level
+        .as_deref()
+        .or(rust_log_env.as_deref())
+        .unwrap_or(DEFAULT_LOG_TARGETS);
+    let filter = targets_string
+        .parse::<filter::Targets>()
+        .expect("error parsing log level string");
 
     // Must enable 'tokio_unstable' cfg to use this feature.
     // For example: `RUSTFLAGS="--cfg tokio_unstable" cargo run -F common-telemetry/console -- standalone start`

src/meta-client/src/lib.rs

@@ -16,8 +16,6 @@ use serde::{Deserialize, Serialize};
 
 pub mod client;
 pub mod error;
-#[cfg(test)]
-mod mocks;
 
 // Options for meta client in datanode instance.
 #[derive(Clone, Debug, Serialize, Deserialize)]
@@ -38,3 +36,6 @@ impl Default for MetaClientOptions {
         }
     }
 }
+
+#[cfg(test)]
+mod mocks;