Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use RUST_LOG env to configure logging if present #247

Merged
merged 1 commit into from
Mar 6, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 6 additions & 1 deletion crates/shim/src/asynchronous/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -166,7 +166,12 @@ where
}
_ => {
if !config.no_setup_logger {
logger::init(flags.debug, &flags.namespace, &flags.id)?;
logger::init(
flags.debug,
&config.default_log_level,
&flags.namespace,
&flags.id,
)?;
}

let publisher = RemotePublisher::new(&ttrpc_address).await?;
Expand Down
15 changes: 14 additions & 1 deletion crates/shim/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -109,16 +109,29 @@ cfg_async! {
const TTRPC_ADDRESS: &str = "TTRPC_ADDRESS";

/// Config of shim binary options provided by shim implementations
#[derive(Debug, Default)]
#[derive(Debug)]
pub struct Config {
/// Disables automatic configuration of logrus to use the shim FIFO
pub no_setup_logger: bool,
// Sets the the default log level. Default is info
pub default_log_level: String,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: Is this case sensitive?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

from my testing it was not

Copy link
Member

@mxpv mxpv Feb 23, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

default_log_level is a bit confusing to me. We have a default one and env variable to customize it if default doesn't work. Customizing both default value and env log is a bit excessive?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was thinking that some shims owners would want to set it different from info with requiring customization through an Environment variable

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

but they can use environment variable to customize it, if they don't like default value, right?

/// Disables the shim binary from reaping any child process implicitly
pub no_reaper: bool,
/// Disables setting the shim as a child subreaper.
pub no_sub_reaper: bool,
}

impl Default for Config {
fn default() -> Self {
Self {
no_setup_logger: false,
default_log_level: "info".to_string(),
no_reaper: false,
no_sub_reaper: false,
}
}
}

/// Startup options received from containerd to start new shim instance.
///
/// These will be passed via [`Shim::start_shim`] to shim.
Expand Down
78 changes: 70 additions & 8 deletions crates/shim/src/logger.rs
Original file line number Diff line number Diff line change
Expand Up @@ -18,9 +18,9 @@ use std::{
borrow::BorrowMut,
fmt::Write as fmtwrite,
fs::{File, OpenOptions},
io,
io::Write,
io::{self, Write},
path::Path,
str::FromStr,
sync::Mutex,
};

Expand All @@ -34,6 +34,8 @@ use crate::error::Error;
#[cfg(windows)]
use crate::sys::windows::NamedPipeLogger;

pub const LOG_ENV: &str = "RUST_LOG";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if we should name the env var to be SHIM_LOG because this is probably not specific to rust, no?

Copy link
Member

@mxpv mxpv Feb 23, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

RUST_LOG is used by another popular (128m downloads) logging crate - env_logger to customize log output. We could integrate env_logger with pipes to offer same level of functionality or use other name here to avoid confusion - users might expect same level of customization, which we don't offer.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did consider trying to integrate env_logger initially and can take closer look if we want to add that level of customization or can change the name


pub struct FifoLogger {
file: Mutex<File>,
}
Expand Down Expand Up @@ -118,7 +120,12 @@ impl log::Log for FifoLogger {
}
}

pub fn init(debug: bool, _namespace: &str, _id: &str) -> Result<(), Error> {
pub fn init(
debug: bool,
default_log_level: &str,
_namespace: &str,
_id: &str,
) -> Result<(), Error> {
#[cfg(unix)]
let logger = FifoLogger::new().map_err(io_error!(e, "failed to init logger"))?;

Expand All @@ -132,15 +139,20 @@ pub fn init(debug: bool, _namespace: &str, _id: &str) -> Result<(), Error> {
let logger =
NamedPipeLogger::new(_namespace, _id).map_err(io_error!(e, "failed to init logger"))?;

let level = if debug {
configure_logging_level(debug, default_log_level);
log::set_boxed_logger(Box::new(logger))?;
Ok(())
}

fn configure_logging_level(debug: bool, default_log_level: &str) {
let debug_level = std::env::var(LOG_ENV).unwrap_or(default_log_level.to_string());
let debug_level = log::LevelFilter::from_str(&debug_level).unwrap_or(log::LevelFilter::Info);
let level = if debug && log::LevelFilter::Debug > debug_level {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you still need this special handling of debug logic?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I kept it there so that it was backwards compatible. If a user turns that value on they would expect logs and I didn't want to break that.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some context about defaults is above, but we may simplify this a bit to:

  • level = DEFAULT_LOG_LEVEL
  • if there is an env - parse & set level from env
  • if debug { level = debug } (may be output a warning that containerd forced debug mode)
    ?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wasn't sure that we could push out a warning as the logger wasn't fully set up at this point but I can try it

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the reason for if debug && log::LevelFilter::Debug > debug_level was I wanted to ensure that if the ENV variable was more verbose than debug that we honor it.

log::LevelFilter::Debug
} else {
log::LevelFilter::Info
debug_level
};

log::set_boxed_logger(Box::new(logger))?;
log::set_max_level(level);
Ok(())
}

pub(crate) fn rfc3339_formated() -> String {
Expand All @@ -156,6 +168,56 @@ mod tests {
use log::{Log, Record};

use super::*;
use crate::Config;

#[test]
fn test_init_log_level() -> Result<(), Error> {
let config = Config::default();

configure_logging_level(false, &config.default_log_level);
assert_eq!(log::LevelFilter::Info, log::max_level());

// Default for debug flag from containerd
configure_logging_level(true, &config.default_log_level);
assert_eq!(log::LevelFilter::Debug, log::max_level());

// ENV different than default
std::env::set_var(LOG_ENV, "error");
configure_logging_level(false, &config.default_log_level);
assert_eq!(log::LevelFilter::Error, log::max_level());

std::env::set_var(LOG_ENV, "warn");
configure_logging_level(false, &config.default_log_level);
assert_eq!(log::LevelFilter::Warn, log::max_level());

std::env::set_var(LOG_ENV, "off");
configure_logging_level(false, &config.default_log_level);
assert_eq!(log::LevelFilter::Off, log::max_level());

std::env::set_var(LOG_ENV, "trace");
configure_logging_level(false, &config.default_log_level);
assert_eq!(log::LevelFilter::Trace, log::max_level());

std::env::set_var(LOG_ENV, "debug");
configure_logging_level(false, &config.default_log_level);

// ENV Different than default from debug flag
configure_logging_level(true, &config.default_log_level);
assert_eq!(log::LevelFilter::Debug, log::max_level());

std::env::set_var(LOG_ENV, "trace");
configure_logging_level(true, &config.default_log_level);
assert_eq!(log::LevelFilter::Trace, log::max_level());

std::env::set_var(LOG_ENV, "info");
configure_logging_level(true, &config.default_log_level);
assert_eq!(log::LevelFilter::Debug, log::max_level());

std::env::set_var(LOG_ENV, "off");
configure_logging_level(true, &config.default_log_level);
assert_eq!(log::LevelFilter::Debug, log::max_level());
Ok(())
}

#[test]
fn test_fifo_log() {
Expand Down
7 changes: 6 additions & 1 deletion crates/shim/src/synchronous/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -255,7 +255,12 @@ where
util::setup_debugger_event();

if !config.no_setup_logger {
logger::init(flags.debug, &flags.namespace, &flags.id)?;
logger::init(
flags.debug,
&config.default_log_level,
&flags.namespace,
&flags.id,
)?;
}

let publisher = publisher::RemotePublisher::new(&ttrpc_address)?;
Expand Down
Loading