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.

Sign up for GitHub

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

Jump to bottom

Allow to override log level for specific target #4305

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open

Allow to override log level for specific target #4305

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
6 changes: 3 additions & 3 deletions .env.template
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -362,9 +362,9 @@
## Log level
## Change the verbosity of the log output
## Valid values are "trace", "debug", "info", "warn", "error" and "off"
## Setting it to "trace" or "debug" would also show logs for mounted
## routes and static file, websocket and alive requests
# LOG_LEVEL=info
## Setting it to "trace" or "debug" would also show logs for mounted routes and static file, websocket and alive requests
## For a specific module append a comma separated `path::to::module=log_level`
# LOG_LEVEL=info,path::to::module=debug

## Token for the admin interface, preferably an Argon2 PCH string
## Vaultwarden has a built-in generator by calling `vaultwarden hash`
Expand Down
2 changes: 1 addition & 1 deletion src/config.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -564,7 +564,7 @@ make_config! {
use_syslog: bool, false, def, false;
/// Log file path
log_file: String, false, option;
/// Log level
/// Log level: `info,path::to::module=warn`
log_level: String, false, def, "Info".to_string();

/// Enable DB WAL |> Turning this off might lead to worse performance, but might help if using vaultwarden on some exotic filesystems,
Expand Down
126 changes: 86 additions & 40 deletions src/main.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ extern crate diesel;
extern crate diesel_migrations;

use std::{
collections::HashMap,
fs::{canonicalize, create_dir_all},
panic,
path::Path,
Expand Down Expand Up @@ -64,15 +65,9 @@ async fn main() -> Result<(), Error> {
parse_args();
launch_info();

use log::LevelFilter as LF;
let level = LF::from_str(&CONFIG.log_level()).unwrap_or_else(|_| {
let valid_log_levels = LF::iter().map(|lvl| lvl.as_str().to_lowercase()).collect::<Vec<String>>().join(", ");
println!("Log level must be one of the following: {valid_log_levels}");
exit(1);
});
init_logging(level).ok();
let level = init_logging()?;

let extra_debug = matches!(level, LF::Trace | LF::Debug);
let extra_debug = matches!(level, log::LevelFilter::Trace | log::LevelFilter::Debug);

check_data_folder().await;
auth::initialize_keys().unwrap_or_else(|_| {
Expand Down Expand Up @@ -210,7 +205,39 @@ fn launch_info() {
);
}

fn init_logging(level: log::LevelFilter) -> Result<(), fern::InitError> {
fn init_logging() -> Result<log::LevelFilter, Error> {
let levels = log::LevelFilter::iter().map(|lvl| lvl.as_str().to_lowercase()).collect::<Vec<String>>().join("|");
let log_level_rgx_str = format!("^({levels})((,[^,=]+=({levels}))*)$");
let log_level_rgx = regex::Regex::new(&log_level_rgx_str)?;
let config_str = CONFIG.log_level().to_lowercase();

let (level, levels_override) = if let Some(caps) = log_level_rgx.captures(&config_str) {
let level = caps
.get(1)
.and_then(|m| log::LevelFilter::from_str(m.as_str()).ok())
.ok_or(Error::new("Failed to parse global log level".to_string(), ""))?;

let levels_override: Vec<(&str, log::LevelFilter)> = caps
.get(2)
.map(|m| {
m.as_str()
.split(',')
.collect::<Vec<&str>>()
.into_iter()
.flat_map(|s| match s.split('=').collect::<Vec<&str>>()[..] {
[log, lvl_str] => log::LevelFilter::from_str(lvl_str).ok().map(|lvl| (log, lvl)),
_ => None,
})
.collect()
})
.ok_or(Error::new("Failed to parse overrides".to_string(), ""))?;

(level, levels_override)
} else {
println!("[WARNING] Log level set to info, LOG_LEVEL should match {log_level_rgx_str}");
(log::LevelFilter::Info, Vec::new())
};

// Depending on the main log level we either want to disable or enable logging for hickory.
// Else if there are timeouts it will clutter the logs since hickory uses warn for this.
let hickory_level = if level >= log::LevelFilter::Debug {
Expand Down Expand Up @@ -241,47 +268,64 @@ fn init_logging(level: log::LevelFilter) -> Result<(), fern::InitError> {
log::LevelFilter::Warn
};

let mut logger = fern::Dispatch::new()
.level(level)
// Enable smtp debug logging only specifically for smtp when need.
// This can contain sensitive information we do not want in the default debug/trace logging.
let smtp_log_level = if CONFIG.smtp_debug() {
log::LevelFilter::Debug
} else {
log::LevelFilter::Off
};

let mut default_levels = HashMap::from([
// Hide unknown certificate errors if using self-signed
.level_for("rustls::session", log::LevelFilter::Off)
("rustls::session", log::LevelFilter::Off),
// Hide failed to close stream messages
.level_for("hyper::server", log::LevelFilter::Warn)
("hyper::server", log::LevelFilter::Warn),
// Silence Rocket `_` logs
.level_for("_", rocket_underscore_level)
.level_for("rocket::response::responder::_", rocket_underscore_level)
.level_for("rocket::server::_", rocket_underscore_level)
.level_for("vaultwarden::api::admin::_", rocket_underscore_level)
.level_for("vaultwarden::api::notifications::_", rocket_underscore_level)
("_", rocket_underscore_level),
("rocket::response::responder::_", rocket_underscore_level),
("rocket::server::_", rocket_underscore_level),
("vaultwarden::api::admin::_", rocket_underscore_level),
("vaultwarden::api::notifications::_", rocket_underscore_level),
// Silence Rocket logs
.level_for("rocket::launch", log::LevelFilter::Error)
.level_for("rocket::launch_", log::LevelFilter::Error)
.level_for("rocket::rocket", log::LevelFilter::Warn)
.level_for("rocket::server", log::LevelFilter::Warn)
.level_for("rocket::fairing::fairings", log::LevelFilter::Warn)
.level_for("rocket::shield::shield", log::LevelFilter::Warn)
.level_for("hyper::proto", log::LevelFilter::Off)
.level_for("hyper::client", log::LevelFilter::Off)
("rocket::launch", log::LevelFilter::Error),
("rocket::launch_", log::LevelFilter::Error),
("rocket::rocket", log::LevelFilter::Warn),
("rocket::server", log::LevelFilter::Warn),
("rocket::fairing::fairings", log::LevelFilter::Warn),
("rocket::shield::shield", log::LevelFilter::Warn),
("hyper::proto", log::LevelFilter::Off),
("hyper::client", log::LevelFilter::Off),
// Filter handlebars logs
.level_for("handlebars::render", handlebars_level)
("handlebars::render", handlebars_level),
// Prevent cookie_store logs
.level_for("cookie_store", log::LevelFilter::Off)
("cookie_store", log::LevelFilter::Off),
// Variable level for hickory used by reqwest
.level_for("hickory_resolver::name_server::name_server", hickory_level)
.level_for("hickory_proto::xfer", hickory_level)
.level_for("diesel_logger", diesel_logger_level)
.chain(std::io::stdout());
("hickory_resolver::name_server::name_server", hickory_level),
("hickory_proto::xfer", hickory_level),
("diesel_logger", diesel_logger_level),
// SMTP
("lettre::transport::smtp", smtp_log_level),
]);

for (path, level) in levels_override.into_iter() {
let _ = default_levels.insert(path, level);
}

// Enable smtp debug logging only specifically for smtp when need.
// This can contain sensitive information we do not want in the default debug/trace logging.
if CONFIG.smtp_debug() {
if Some(&log::LevelFilter::Debug) == default_levels.get("lettre::transport::smtp") {
println!(
"[WARNING] SMTP Debugging is enabled (SMTP_DEBUG=true). Sensitive information could be disclosed via logs!\n\
[WARNING] Only enable SMTP_DEBUG during troubleshooting!\n"
);
logger = logger.level_for("lettre::transport::smtp", log::LevelFilter::Debug)
} else {
logger = logger.level_for("lettre::transport::smtp", log::LevelFilter::Off)
}

let mut logger = fern::Dispatch::new().level(level).chain(std::io::stdout());

let mut sorted_levels = default_levels.into_iter().collect::<Vec<(&str, log::LevelFilter)>>();
sorted_levels.sort_by_key(|a| a.0);

for (path, level) in sorted_levels {
logger = logger.level_for(path.to_string(), level);
}

if CONFIG.extended_logging() {
Expand Down Expand Up @@ -318,7 +362,9 @@ fn init_logging(level: log::LevelFilter) -> Result<(), fern::InitError> {
}
}

logger.apply()?;
if let Err(err) = logger.apply() {
error!("Failed to activate logger: {err}")
}

// Catch panics and log them instead of default output to StdErr
panic::set_hook(Box::new(|info| {
Expand Down Expand Up @@ -356,7 +402,7 @@ fn init_logging(level: log::LevelFilter) -> Result<(), fern::InitError> {
}
}));

Ok(())
Ok(level)
}

#[cfg(not(windows))]
Expand Down