From 2fde4e693363266a93d450f26ad0b5cc9cebb53a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Garc=C3=ADa?= Date: Thu, 6 Dec 2018 20:35:25 +0100 Subject: [PATCH] Implemented proper logging, with support for file logging, timestamp and syslog (this last one is untested) --- .env | 11 +++++ .travis.yml | 2 + Cargo.lock | 34 ++++++++++++++++ Cargo.toml | 8 ++++ src/api/core/ciphers.rs | 12 +++--- src/api/core/two_factor.rs | 8 ++-- src/api/icons.rs | 6 +-- src/api/notifications.rs | 2 +- src/auth.rs | 2 +- src/db/models/attachment.rs | 4 +- src/db/models/user.rs | 2 +- src/main.rs | 80 ++++++++++++++++++++++++++++++++----- src/util.rs | 4 +- 13 files changed, 146 insertions(+), 29 deletions(-) diff --git a/.env b/.env index 0f73893..7ad0e89 100644 --- a/.env +++ b/.env @@ -18,6 +18,17 @@ # WEBSOCKET_ADDRESS=0.0.0.0 # WEBSOCKET_PORT=3012 +## Enable extended logging +## This shows timestamps and allows logging to file and to syslog +### To enable logging to file, use the LOG_FILE env variable +### To enable syslog, you need to compile with `cargo build --features=enable_syslog' +# EXTENDED_LOGGING=true + +## Logging to file +## This requires extended logging +## It's recommended to also set 'ROCKET_CLI_COLORS=off' +# LOG_FILE=/path/to/log + ## Controls if new users can register # SIGNUPS_ALLOWED=true diff --git a/.travis.yml b/.travis.yml index c37ede5..977b06e 100644 --- a/.travis.yml +++ b/.travis.yml @@ -5,3 +5,5 @@ dist: trusty # so we get a VM with higher specs cache: cargo rust: - nightly +script: +- cargo build --verbose --all-features diff --git a/Cargo.lock b/Cargo.lock index 0ab6b56..e8af51f 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -93,11 +93,13 @@ dependencies = [ "diesel 1.3.3 (registry+https://github.com/rust-lang/crates.io-index)", "diesel_migrations 1.3.0 (registry+https://github.com/rust-lang/crates.io-index)", "dotenv 0.13.0 (registry+https://github.com/rust-lang/crates.io-index)", + "fern 0.5.7 (registry+https://github.com/rust-lang/crates.io-index)", "jsonwebtoken 5.0.1 (registry+https://github.com/rust-lang/crates.io-index)", "lazy_static 1.2.0 (registry+https://github.com/rust-lang/crates.io-index)", "lettre 0.9.0 (git+https://github.com/lettre/lettre?rev=c988b1760ad81)", "lettre_email 0.9.0 (git+https://github.com/lettre/lettre?rev=c988b1760ad81)", "libsqlite3-sys 0.9.3 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", "multipart 0.15.4 (registry+https://github.com/rust-lang/crates.io-index)", "native-tls 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", "num-derive 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)", @@ -111,6 +113,7 @@ dependencies = [ "serde 1.0.80 (registry+https://github.com/rust-lang/crates.io-index)", "serde_derive 1.0.80 (registry+https://github.com/rust-lang/crates.io-index)", "serde_json 1.0.33 (registry+https://github.com/rust-lang/crates.io-index)", + "syslog 4.0.1 (registry+https://github.com/rust-lang/crates.io-index)", "u2f 0.1.2 (git+https://github.com/wisespace-io/u2f-rs?rev=75b9fa5afb4c5)", "uuid 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)", "ws 0.7.9 (registry+https://github.com/rust-lang/crates.io-index)", @@ -448,6 +451,14 @@ dependencies = [ "cfg-if 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "error-chain" +version = "0.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "backtrace 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "failure" version = "0.1.3" @@ -481,6 +492,15 @@ dependencies = [ "ascii_utils 0.9.3 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "fern" +version = "0.5.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "log 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", + "syslog 4.0.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "filetime" version = "0.2.4" @@ -1928,6 +1948,17 @@ dependencies = [ "unicode-xid 0.1.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "syslog" +version = "4.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "error-chain 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)", + "libc 0.2.44 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", + "time 0.1.40 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "tempdir" version = "0.3.7" @@ -2505,10 +2536,12 @@ dependencies = [ "checksum encoding-index-tradchinese 1.20141219.5 (registry+https://github.com/rust-lang/crates.io-index)" = "fd0e20d5688ce3cab59eb3ef3a2083a5c77bf496cb798dc6fcdb75f323890c18" "checksum encoding_index_tests 0.1.4 (registry+https://github.com/rust-lang/crates.io-index)" = "a246d82be1c9d791c5dfde9a2bd045fc3cbba3fa2b11ad558f27d01712f00569" "checksum encoding_rs 0.8.13 (registry+https://github.com/rust-lang/crates.io-index)" = "1a8fa54e6689eb2549c4efed8d00d7f3b2b994a064555b0e8df4ae3764bcc4be" +"checksum error-chain 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)" = "ff511d5dc435d703f4971bc399647c9bc38e20cb41452e3b9feb4765419ed3f3" "checksum failure 0.1.3 (registry+https://github.com/rust-lang/crates.io-index)" = "6dd377bcc1b1b7ce911967e3ec24fa19c3224394ec05b54aa7b083d498341ac7" "checksum failure_derive 0.1.3 (registry+https://github.com/rust-lang/crates.io-index)" = "64c2d913fe8ed3b6c6518eedf4538255b989945c14c2a7d5cbff62a5e2120596" "checksum fake-simd 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "e88a8acf291dafb59c2d96e8f59828f3838bb1a70398823ade51a84de6a6deed" "checksum fast_chemail 0.9.5 (registry+https://github.com/rust-lang/crates.io-index)" = "115e1df89e36c3300a0f88b8b81c41ad24f7bf2b291912e405824d98a553704b" +"checksum fern 0.5.7 (registry+https://github.com/rust-lang/crates.io-index)" = "b48af88aaf938b11baef948a5599e66e709cf92854aa2b87c71f1bcf20f80a01" "checksum filetime 0.2.4 (registry+https://github.com/rust-lang/crates.io-index)" = "a2df5c1a8c4be27e7707789dc42ae65976e60b394afd293d1419ab915833e646" "checksum fnv 1.0.6 (registry+https://github.com/rust-lang/crates.io-index)" = "2fad85553e09a6f881f739c29f0b00b0f01357c743266d478b68951ce23285f3" "checksum foreign-types 0.3.2 (registry+https://github.com/rust-lang/crates.io-index)" = "f6f339eb8adc052cd2ca78910fda869aefa38d22d5cb648e6485e4d3fc06f3b1" @@ -2664,6 +2697,7 @@ dependencies = [ "checksum syn 0.15.22 (registry+https://github.com/rust-lang/crates.io-index)" = "ae8b29eb5210bc5cf63ed6149cbf9adfc82ac0be023d8735c176ee74a2db4da7" "checksum synom 0.11.3 (registry+https://github.com/rust-lang/crates.io-index)" = "a393066ed9010ebaed60b9eafa373d4b1baac186dd7e008555b0f702b51945b6" "checksum synstructure 0.10.1 (registry+https://github.com/rust-lang/crates.io-index)" = "73687139bf99285483c96ac0add482c3776528beac1d97d444f6e91f203a2015" +"checksum syslog 4.0.1 (registry+https://github.com/rust-lang/crates.io-index)" = "a0641142b4081d3d44beffa4eefd7346a228cdf91ed70186db2ca2cef762d327" "checksum tempdir 0.3.7 (registry+https://github.com/rust-lang/crates.io-index)" = "15f2b5fb00ccdf689e0149d1b1b3c03fead81c2b37735d812fa8bddbbf41b6d8" "checksum tempfile 3.0.5 (registry+https://github.com/rust-lang/crates.io-index)" = "7e91405c14320e5c79b3d148e1c86f40749a36e490642202a31689cb1a3452b2" "checksum thread-id 3.3.0 (registry+https://github.com/rust-lang/crates.io-index)" = "c7fbf4c9d56b320106cd64fd024dadfa0be7cb4706725fc44a7d7ce952d820c1" diff --git a/Cargo.toml b/Cargo.toml index aa85e6d..c4e4452 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -3,6 +3,9 @@ name = "bitwarden_rs" version = "1.0.0" authors = ["Daniel García "] +[features] +enable_syslog = ["syslog", "fern/syslog-4"] + [dependencies] # Web framework for nightly with a focus on ease-of-use, expressibility, and speed. rocket = { version = "0.4.0", features = ["tls"], default-features = false } @@ -28,6 +31,11 @@ serde = "1.0.80" serde_derive = "1.0.80" serde_json = "1.0.33" +# Logging +log = "0.4.6" +fern = "0.5.7" +syslog = { version = "4.0.1", optional = true } + # A safe, extensible ORM and Query builder diesel = { version = "1.3.3", features = ["sqlite", "chrono", "r2d2"] } diesel_migrations = { version = "1.3.0", features = ["sqlite"] } diff --git a/src/api/core/ciphers.rs b/src/api/core/ciphers.rs index d148017..41e704d 100644 --- a/src/api/core/ciphers.rs +++ b/src/api/core/ciphers.rs @@ -599,15 +599,15 @@ fn post_attachment(uuid: String, data: Data, content_type: &ContentType, headers .with_path(path) { SaveResult::Full(SavedData::File(_, size)) => size as i32, SaveResult::Full(other) => { - println!("Attachment is not a file: {:?}", other); + error!("Attachment is not a file: {:?}", other); return; }, SaveResult::Partial(_, reason) => { - println!("Partial result: {:?}", reason); + error!("Partial result: {:?}", reason); return; }, SaveResult::Error(e) => { - println!("Error: {:?}", e); + error!("Error: {:?}", e); return; } }; @@ -616,10 +616,10 @@ fn post_attachment(uuid: String, data: Data, content_type: &ContentType, headers attachment.key = attachment_key.clone(); match attachment.save(&conn) { Ok(()) => (), - Err(_) => println!("Error: failed to save attachment") + Err(_) => error!("Failed to save attachment") }; }, - _ => println!("Error: invalid multipart name") + _ => error!("Invalid multipart name") } }).expect("Error processing multipart data"); @@ -751,7 +751,7 @@ fn move_cipher_selected(data: JsonUpcase, headers: Headers, conn: DbConn, } match cipher.save(&conn) { Ok(()) => (), - Err(_) => println!("Error: Failed to save cipher") + Err(_) => err!("Failed to save cipher") }; ws.send_cipher_update(UpdateType::SyncCipherUpdate, &cipher, &cipher.update_users_revision(&conn)); } diff --git a/src/api/core/two_factor.rs b/src/api/core/two_factor.rs index 5af2415..a236138 100644 --- a/src/api/core/two_factor.rs +++ b/src/api/core/two_factor.rs @@ -243,7 +243,7 @@ fn _generate_recover_code(user: &mut User, conn: &DbConn) { let totp_recover = BASE32.encode(&crypto::get_random(vec![0u8; 20])); user.totp_recover = Some(totp_recover); if user.save(conn).is_err() { - println!("Error: Failed to save the user's two factor recovery code") + error!("Failed to save the user's two factor recovery code") } } } @@ -400,7 +400,7 @@ fn activate_u2f(data: JsonUpcase, headers: Headers, conn: DbConn) }))) } Err(e) => { - println!("Error: {:#?}", e); + error!("{:#?}", e); err!("Error activating u2f") } } @@ -504,11 +504,11 @@ pub fn validate_u2f_login(user_uuid: &str, response: &str, conn: &DbConn) -> Api match response { Ok(new_counter) => { _counter = new_counter; - println!("O {:#}", new_counter); + info!("O {:#}", new_counter); return Ok(()); } Err(e) => { - println!("E {:#}", e); + info!("E {:#}", e); break; } } diff --git a/src/api/icons.rs b/src/api/icons.rs index a29ede6..585a2c2 100644 --- a/src/api/icons.rs +++ b/src/api/icons.rs @@ -43,7 +43,7 @@ fn get_icon (domain: &str) -> Vec { icon }, Err(e) => { - println!("Error downloading icon: {:?}", e); + error!("Error downloading icon: {:?}", e); get_fallback_icon() } } @@ -71,7 +71,7 @@ fn get_icon_url(domain: &str) -> String { } fn download_icon(url: &str) -> Result, reqwest::Error> { - println!("Downloading icon for {}...", url); + info!("Downloading icon for {}...", url); let mut res = reqwest::get(url)?; res = res.error_for_status()?; @@ -105,7 +105,7 @@ fn get_fallback_icon() -> Vec { icon }, Err(e) => { - println!("Error downloading fallback icon: {:?}", e); + error!("Error downloading fallback icon: {:?}", e); vec![] } } diff --git a/src/api/notifications.rs b/src/api/notifications.rs index c44a95e..df40cf8 100644 --- a/src/api/notifications.rs +++ b/src/api/notifications.rs @@ -169,7 +169,7 @@ impl Handler for WSHandler { } fn on_message(&mut self, msg: Message) -> ws::Result<()> { - println!("Server got message '{}'. ", msg); + info!("Server got message '{}'. ", msg); if let Message::Text(text) = msg.clone() { let json = &text[..text.len() - 1]; // Remove last char diff --git a/src/auth.rs b/src/auth.rs index 0c0623a..28f706d 100644 --- a/src/auth.rs +++ b/src/auth.rs @@ -51,7 +51,7 @@ pub fn decode_jwt(token: &str) -> Result { match jwt::decode(token, &PUBLIC_RSA_KEY, &validation) { Ok(decoded) => Ok(decoded.claims), Err(msg) => { - println!("Error validating jwt - {:#?}", msg); + error!("Error validating jwt - {:#?}", msg); Err(msg.to_string()) } } diff --git a/src/db/models/attachment.rs b/src/db/models/attachment.rs index 97a4d75..29c3f61 100644 --- a/src/db/models/attachment.rs +++ b/src/db/models/attachment.rs @@ -78,11 +78,11 @@ impl Attachment { Ok(_) => break, Err(err) => { if retries < 1 { - println!("ERROR: Failed with 10 retries"); + error!("Failed with 10 retries"); return Err(err) } else { retries -= 1; - println!("Had to retry! Retries left: {}", retries); + info!("Had to retry! Retries left: {}", retries); thread::sleep(time::Duration::from_millis(500)); continue } diff --git a/src/db/models/user.rs b/src/db/models/user.rs index c958a51..283ec3c 100644 --- a/src/db/models/user.rs +++ b/src/db/models/user.rs @@ -180,7 +180,7 @@ impl User { pub fn update_uuid_revision(uuid: &str, conn: &DbConn) { if let Some(mut user) = User::find_by_uuid(&uuid, conn) { if user.update_revision(conn).is_err(){ - println!("Warning: Failed to update revision for {}", user.email); + warn!("Failed to update revision for {}", user.email); }; }; } diff --git a/src/main.rs b/src/main.rs index 560d77c..3731f61 100644 --- a/src/main.rs +++ b/src/main.rs @@ -16,6 +16,11 @@ extern crate serde_derive; #[macro_use] extern crate serde_json; #[macro_use] +extern crate log; +extern crate fern; +#[cfg(feature = "enable_syslog")] +extern crate syslog; +#[macro_use] extern crate diesel; #[macro_use] extern crate diesel_migrations; @@ -78,6 +83,10 @@ mod migrations { } fn main() { + if CONFIG.extended_logging { + init_logging().ok(); + } + check_db(); check_rsa_keys(); check_web_vault(); @@ -86,13 +95,60 @@ fn main() { init_rocket().launch(); } +fn init_logging() -> Result<(), fern::InitError> { + let mut logger = fern::Dispatch::new() + .format(|out, message, record| { + out.finish(format_args!( + "{}[{}][{}] {}", + chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"), + record.target(), + record.level(), + message + )) + }) + .level(log::LevelFilter::Debug) + .level_for("hyper", log::LevelFilter::Warn) + .level_for("ws", log::LevelFilter::Info) + .chain(std::io::stdout()); + + if let Some(log_file) = CONFIG.log_file.as_ref() { + logger = logger.chain(fern::log_file(log_file)?); + } + + logger = chain_syslog(logger); + logger.apply()?; + + Ok(()) +} + +#[cfg(not(feature = "enable_syslog"))] +fn chain_syslog(logger: fern::Dispatch) -> fern::Dispatch { logger } + +#[cfg(feature = "enable_syslog")] +fn chain_syslog(logger: fern::Dispatch) -> fern::Dispatch { + let syslog_fmt = syslog::Formatter3164 { + facility: syslog::Facility::LOG_USER, + hostname: None, + process: "bitwarden_rs".into(), + pid: 0, + }; + + match syslog::unix(syslog_fmt) { + Ok(sl) => logger.chain(sl), + Err(e) => { + error!("Unable to connect to syslog: {:?}", e); + logger + } + } +} + fn check_db() { let path = Path::new(&CONFIG.database_url); if let Some(parent) = path.parent() { use std::fs; if fs::create_dir_all(parent).is_err() { - println!("Error creating database directory"); + error!("Error creating database directory"); exit(1); } } @@ -107,16 +163,16 @@ fn check_rsa_keys() { // If the RSA keys don't exist, try to create them if !util::file_exists(&CONFIG.private_rsa_key) || !util::file_exists(&CONFIG.public_rsa_key) { - println!("JWT keys don't exist, checking if OpenSSL is available..."); + info!("JWT keys don't exist, checking if OpenSSL is available..."); Command::new("openssl") .arg("version") .output().unwrap_or_else(|_| { - println!("Can't create keys because OpenSSL is not available, make sure it's installed and available on the PATH"); + info!("Can't create keys because OpenSSL is not available, make sure it's installed and available on the PATH"); exit(1); }); - println!("OpenSSL detected, creating keys..."); + info!("OpenSSL detected, creating keys..."); let mut success = Command::new("openssl").arg("genrsa") .arg("-out").arg(&CONFIG.private_rsa_key_pem) @@ -140,9 +196,9 @@ fn check_rsa_keys() { .status.success(); if success { - println!("Keys created correctly."); + info!("Keys created correctly."); } else { - println!("Error creating keys, exiting..."); + error!("Error creating keys, exiting..."); exit(1); } } @@ -156,7 +212,7 @@ fn check_web_vault() { let index_path = Path::new(&CONFIG.web_vault_folder).join("index.html"); if !index_path.exists() { - println!("Web vault is not found. Please follow the steps in the README to install it"); + error!("Web vault is not found. Please follow the steps in the README to install it"); exit(1); } } @@ -187,7 +243,7 @@ impl MailConfig { }; let smtp_from = get_env("SMTP_FROM").unwrap_or_else(|| { - println!("Please specify SMTP_FROM to enable SMTP support."); + error!("Please specify SMTP_FROM to enable SMTP support."); exit(1); }); @@ -203,7 +259,7 @@ impl MailConfig { let smtp_username = get_env("SMTP_USERNAME"); let smtp_password = get_env("SMTP_PASSWORD").or_else(|| { if smtp_username.as_ref().is_some() { - println!("SMTP_PASSWORD is mandatory when specifying SMTP_USERNAME."); + error!("SMTP_PASSWORD is mandatory when specifying SMTP_USERNAME."); exit(1); } else { None @@ -237,6 +293,9 @@ pub struct Config { websocket_enabled: bool, websocket_url: String, + extended_logging: bool, + log_file: Option, + local_icon_extractor: bool, signups_allowed: bool, invitations_allowed: bool, @@ -282,6 +341,9 @@ impl Config { websocket_enabled: get_env_or("WEBSOCKET_ENABLED", false), websocket_url: format!("{}:{}", get_env_or("WEBSOCKET_ADDRESS", "0.0.0.0".to_string()), get_env_or("WEBSOCKET_PORT", 3012)), + + extended_logging: get_env_or("EXTENDED_LOGGING", true), + log_file: get_env("LOG_FILE"), local_icon_extractor: get_env_or("LOCAL_ICON_EXTRACTOR", false), signups_allowed: get_env_or("SIGNUPS_ALLOWED", true), diff --git a/src/util.rs b/src/util.rs index 69f6404..05c38b2 100644 --- a/src/util.rs +++ b/src/util.rs @@ -4,7 +4,7 @@ #[macro_export] macro_rules! err { ($err:expr, $msg:expr) => {{ - println!("ERROR: {}", $msg); + error!("{}", $msg); err_json!(json!({ "error": $err, "error_description": $err, @@ -30,7 +30,7 @@ macro_rules! err_json { #[macro_export] macro_rules! err_handler { ($expr:expr) => {{ - println!("ERROR: {}", $expr); + error!("{}", $expr); return $crate::rocket::Outcome::Failure(($crate::rocket::http::Status::Unauthorized, $expr)); }} }