Implemented proper logging, with support for file logging, timestamp and syslog (this last one is untested)

.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
 

.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

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"

Cargo.toml

@@ -3,6 +3,9 @@ name = "bitwarden_rs"
 version = "1.0.0"
 authors = ["Daniel García <dani-garcia@users.noreply.github.com>"]
 
+[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"] }

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<Value>, 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));
     }

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<EnableU2FData>, 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;
             }
         }

src/api/icons.rs

@@ -43,7 +43,7 @@ fn get_icon (domain: &str) -> Vec<u8> {
             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<Vec<u8>, 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<u8> {
             icon
         },
         Err(e) => {
-            println!("Error downloading fallback icon: {:?}", e);
+            error!("Error downloading fallback icon: {:?}", e);
             vec![]
         }
     }

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

src/auth.rs

@@ -51,7 +51,7 @@ pub fn decode_jwt(token: &str) -> Result<JWTClaims, String> {
     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())
         }
     }

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
                     }

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);
             };
         };
     }

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<String>,
+
     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),

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));
     }}
 }