Fix log files and remove env_logger

.gitignore

@@ -11,6 +11,7 @@ tags.lock
 tags.temp
 
 youki
+!youki/
 youki_integration_test
 
 .vscode

crates/youki/Cargo.toml

@@ -16,7 +16,7 @@ anyhow = "1.0"
 chrono = { version="0.4", features = ["serde"] }
 libcgroups = { path = "../libcgroups" }
 libcontainer = { path = "../libcontainer" }
-log = "0.4"
+log = {version = "0.4", features = ["std"]}
 nix = "0.23.0"
 oci-spec = { git = "https://github.com/containers/oci-spec-rs",  rev = "d6fb1e91742313cd0d0085937e2d6df5d4669720" }
 once_cell = "1.6.0"
@@ -25,9 +25,7 @@ procfs = "0.11.1"
 serde = { version = "1.0", features = ["derive"] }
 serde_json = "1.0"
 tabwriter = "1"
-env_logger = "0.9.0"
 
 [dev-dependencies]
 serial_test = "0.5.1"
 
-

crates/youki/src/logger.rs

@@ -1,14 +1,22 @@
 //! Default Youki Logger
 
 use anyhow::{bail, Context, Result};
-use log::LevelFilter;
+use log::{LevelFilter, Log, Metadata, Record};
+use once_cell::sync::OnceCell;
 use std::borrow::Cow;
-use std::fs::OpenOptions;
-use std::io::Write;
+use std::fs::{File, OpenOptions};
+use std::io::{stderr, Write};
 use std::path::PathBuf;
 use std::str::FromStr;
 
+pub static LOG_FILE: OnceCell<Option<File>> = OnceCell::new();
 const LOG_LEVEL_ENV_NAME: &str = "YOUKI_LOG_LEVEL";
+const LOG_FORMAT_TEXT: &str = "text";
+const LOG_FORMAT_JSON: &str = "json";
+enum LogFormat {
+    Text,
+    Json,
+}
 
 /// If in debug mode, default level is debug to get maximum logging
 #[cfg(debug_assertions)]
@@ -18,9 +26,6 @@ const DEFAULT_LOG_LEVEL: &str = "debug";
 #[cfg(not(debug_assertions))]
 const DEFAULT_LOG_LEVEL: &str = "warn";
 
-const LOG_FORMAT_TEXT: &str = "text";
-const LOG_FORMAT_JSON: &str = "json";
-
 /// Initialize the logger, must be called before accessing the logger
 /// Multiple parts might call this at once, but the actual initialization
 /// is done only once due to use of OnceCell
@@ -29,32 +34,35 @@ pub fn init(
     log_file: Option<PathBuf>,
     log_format: Option<String>,
 ) -> Result<()> {
-    let log_level = detect_log_level(log_debug_flag);
-    let formatter = match log_format.as_deref() {
-        None | Some(LOG_FORMAT_TEXT) => text_write,
-        Some(LOG_FORMAT_JSON) => json_write,
-        Some(unknown) => bail!("unknown log format: {}", unknown),
-    };
-    let target = if let Some(log_file) = log_file {
-        let file = OpenOptions::new()
-            .create(true)
-            .write(true)
-            .truncate(false)
-            .open(log_file)
-            .context("failed opening log file")?;
-        env_logger::Target::Pipe(Box::new(file))
-    } else {
-        env_logger::Target::Stderr
-    };
-    env_logger::Builder::new()
-        .filter_level(log_level.context("failed to parse log level")?)
-        .format(formatter)
-        .target(target)
-        .init();
+    let level = detect_log_level(log_debug_flag).context("failed to parse log level")?;
+    let format = detect_log_format(log_format).context("failed to detect log format")?;
+    let _ = LOG_FILE.get_or_init(|| -> Option<File> {
+        log_file.map(|path| {
+            OpenOptions::new()
+                .create(true)
+                .write(true)
+                .truncate(false)
+                .open(path)
+                .expect("failed opening log file")
+        })
+    });
+
+    let logger = YoukiLogger::new(level.to_level(), format);
+    log::set_boxed_logger(Box::new(logger))
+        .map(|()| log::set_max_level(level))
+        .expect("set logger failed");
 
     Ok(())
 }
 
+fn detect_log_format(log_format: Option<String>) -> Result<LogFormat> {
+    match log_format.as_deref() {
+        None | Some(LOG_FORMAT_TEXT) => Ok(LogFormat::Text),
+        Some(LOG_FORMAT_JSON) => Ok(LogFormat::Json),
+        Some(unknown) => bail!("unknown log format: {}", unknown),
+    }
+}
+
 fn detect_log_level(is_debug: bool) -> Result<LevelFilter> {
     let filter: Cow<str> = if is_debug {
         "debug".into()
@@ -66,47 +74,94 @@ fn detect_log_level(is_debug: bool) -> Result<LevelFilter> {
     Ok(LevelFilter::from_str(filter.as_ref())?)
 }
 
-fn json_write<F: 'static>(f: &mut F, record: &log::Record) -> std::io::Result<()>
-where
-    F: Write,
-{
-    write!(f, "{{")?;
-    write!(f, "\"level\":\"{}\",", record.level())?;
-    write!(f, "\"time\":\"{}\"", chrono::Local::now().to_rfc3339(),)?;
-    write!(f, ",\"msg\":")?;
-    // Use serde_json here so we don't have to worry about escaping special characters in the string.
-    serde_json::to_writer(f.by_ref(), &record.args().to_string())?;
-    writeln!(f, "}}")?;
+struct YoukiLogger {
+    /// Indicates level up to which logs are to be printed
+    level: Option<log::Level>,
+    format: LogFormat,
+}
 
-    Ok(())
+impl YoukiLogger {
+    /// Create new logger
+    pub fn new(level: Option<log::Level>, format: LogFormat) -> Self {
+        Self { level, format }
+    }
 }
 
-fn text_write<F: 'static>(f: &mut F, record: &log::Record) -> std::io::Result<()>
-where
-    F: Write,
-{
-    match (record.file(), record.line()) {
-        (Some(file), Some(line)) => {
-            write!(f, "[{} {}:{}]", record.level(), file, line)?;
+/// Implements Log interface given by log crate, so we can use its functionality
+impl Log for YoukiLogger {
+    /// Check if level of given log is enabled or not
+    fn enabled(&self, metadata: &Metadata) -> bool {
+        if let Some(level) = self.level {
+            metadata.level() <= level
+        } else {
+            false
+        }
+    }
+
+    /// Function to carry out logging
+    fn log(&self, record: &Record) {
+        if self.enabled(record.metadata()) {
+            let log_msg = match self.format {
+                LogFormat::Text => text_format(record),
+                LogFormat::Json => json_format(record),
+            };
+            // if log file is set, write to it, else write to stderr
+            if let Some(mut log_file) = LOG_FILE.get().unwrap().as_ref() {
+                let _ = writeln!(log_file, "{}", log_msg);
+            } else {
+                let _ = writeln!(stderr(), "{}", log_msg);
+            }
+        }
+    }
+
+    /// Flush logs to file
+    fn flush(&self) {
+        if let Some(mut log_file) = LOG_FILE.get().unwrap().as_ref() {
+            log_file.flush().expect("failed to flush");
+        } else {
+            stderr().flush().expect("failed to flush");
         }
-        (_, _) => write!(f, "[{}]", record.level(),)?,
+    }
+}
+
+fn json_format(record: &log::Record) -> String {
+    serde_json::to_string(&serde_json::json!({
+        "level": record.level().to_string(),
+        "time": chrono::Local::now().to_rfc3339(),
+        "message": record.args(),
+    }))
+    .expect("serde::to_string with string keys will not fail")
+}
+
+fn text_format(record: &log::Record) -> String {
+    let log_msg = match (record.file(), record.line()) {
+        (Some(file), Some(line)) => format!(
+            "[{} {}:{}] {} {}\r",
+            record.level(),
+            file,
+            line,
+            chrono::Local::now().to_rfc3339(),
+            record.args()
+        ),
+        (_, _) => format!(
+            "[{}] {} {}\r",
+            record.level(),
+            chrono::Local::now().to_rfc3339(),
+            record.args()
+        ),
     };
-    write!(
-        f,
-        " {} {}\r\n",
-        chrono::Local::now().to_rfc3339(),
-        record.args()
-    )?;
 
-    Ok(())
+    log_msg
 }
 
 #[cfg(test)]
 mod tests {
     use serial_test::serial;
 
     use super::*;
-    use std::env;
+    use crate::utils::create_temp_dir;
+    use std::{env, path::Path};
+
     struct LogLevelGuard {
         original_level: Option<String>,
     }
@@ -118,6 +173,7 @@ mod tests {
             Ok(Self { original_level })
         }
     }
+
     impl Drop for LogLevelGuard {
         fn drop(self: &mut LogLevelGuard) {
             if let Some(level) = self.original_level.as_ref() {
@@ -152,4 +208,33 @@ mod tests {
         let _guard = LogLevelGuard::new("error").unwrap();
         assert_eq!(detect_log_level(false).unwrap(), LevelFilter::Error)
     }
+
+    #[test]
+    fn test_logfile() {
+        let temp_dir = create_temp_dir("logfile").expect("failed to create tempdir for logfile");
+        let log_file = Path::join(temp_dir.path(), "test.log");
+
+        init(true, Some(log_file.to_owned()), None).expect("failed to initialize logger");
+        assert!(
+            log_file
+                .as_path()
+                .metadata()
+                .expect("failed to get logfile metadata")
+                .len()
+                == 0,
+            "a new logfile should be empty"
+        );
+
+        log::info!("testing this");
+
+        assert!(
+            log_file
+                .as_path()
+                .metadata()
+                .expect("failed to get logfile metadata")
+                .len()
+                > 0,
+            "some log should be written into the logfile"
+        );
+    }
 }