Skip to content

Commit

Permalink
Allow to set and override module log_level
Browse files Browse the repository at this point in the history
  • Loading branch information
Timshel committed Jul 6, 2024
1 parent fda77af commit 37f28fe
Show file tree
Hide file tree
Showing 3 changed files with 90 additions and 44 deletions.
6 changes: 3 additions & 3 deletions .env.template
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
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
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

0 comments on commit 37f28fe

Please sign in to comment.