Revamp logging

backend/src/confirmation.rs

@@ -1,11 +1,12 @@
 use chrono::Utc;
 use lettre::message::header::ContentType;
+use log::{warn, debug};
 
 use crate::errors::SpecialErrors;
 use crate::management::{delete_key, Action, Pending};
-use crate::pending_path;
 use crate::settings::{MAILER, ROOT_FOLDER, SETTINGS};
-use crate::utils::{get_email_from_cert, parse_pem, read_file};
+use crate::utils::{extract_domain, get_email_from_cert, parse_pem, read_file};
+use crate::{log_err, pending_path};
 use anyhow::Result;
 
 use lettre::{Message, Transport};
@@ -15,20 +16,20 @@ use std::path::Path;
 pub fn confirm_action(token: &str) -> Result<(Action, String)> {
     let pending_path = pending_path().join(token);
     let content = read_file(&pending_path)?;
-    let key = toml::from_str::<Pending>(&content)?;
+    let key = log_err!(toml::from_str::<Pending>(&content), warn)?;
     if Utc::now().timestamp() - key.timestamp() > SETTINGS.max_age {
-        fs::remove_file(&pending_path)?;
+        log_err!(fs::remove_file(&pending_path), warn)?;
         Err(SpecialErrors::ExpiredRequest)?
     } else {
         let address = match key.action() {
             Action::Add => {
                 let cert = parse_pem(key.data())?;
                 let email = get_email_from_cert(&cert)?;
-                let domain = match email.split('@').last() {
-                    Some(domain) => domain.to_string(),
-                    None => Err(SpecialErrors::MalformedEmail)?,
-                };
-                sequoia_net::wkd::insert(ROOT_FOLDER, domain, SETTINGS.variant, &cert)?;
+                let domain = extract_domain(&email)?;
+                log_err!(
+                    sequoia_net::wkd::insert(ROOT_FOLDER, domain, SETTINGS.variant, &cert),
+                    warn
+                )?;
                 email
             }
             Action::Delete => {
@@ -57,7 +58,7 @@ pub fn send_confirmation_email(address: &str, action: &Action, token: &str) -> R
                 panic!("Unable to parse the email in the settings!")
             }
         })
-        .to(match address.parse() {
+        .to(match log_err!(address.parse(), debug) {
             Ok(mbox) => mbox,
             Err(_) => Err(SpecialErrors::MalformedEmail)?,
         })
@@ -72,8 +73,10 @@ pub fn send_confirmation_email(address: &str, action: &Action, token: &str) -> R
             template
                 .replace("{{%u}}", url.as_ref())
                 .replace("{{%a}}", &action.to_string().to_lowercase()),
-        )?;
+        );
 
-    MAILER.send(&email)?;
+    let email = log_err!(email, warn)?;
+
+    log_err!(MAILER.send(&email), warn)?;
     Ok(())
 }

backend/src/errors.rs

@@ -10,7 +10,11 @@ macro_rules! log_err {
     ($var: expr, $level: ident) => {{
         let test = $var;
         if test.is_err() {
-            $level!("{} {}", $crate::settings::ERROR_TEXT, test.as_ref().unwrap_err());
+            $level!(
+                "{} {}",
+                $crate::settings::ERROR_TEXT,
+                test.as_ref().unwrap_err()
+            );
             test
         } else {
             test

backend/src/main.rs

@@ -6,6 +6,7 @@ mod utils;
 
 use crate::confirmation::{confirm_action, send_confirmation_email};
 use crate::errors::CompatErr;
+use crate::errors::SpecialErrors;
 use crate::management::{clean_stale, store_pending_addition, store_pending_deletion, Action};
 use crate::settings::{ROOT_FOLDER, SETTINGS};
 use crate::utils::{
@@ -18,9 +19,8 @@ use actix_web::http::StatusCode;
 use actix_web::{
     get, post, web, App, HttpRequest, HttpResponse, HttpResponseBuilder, HttpServer, Result,
 };
-use errors::SpecialErrors;
+use log::{debug, error, info, trace};
 use serde::Deserialize;
-use std::env;
 use std::fs;
 use std::path::Path;
 use tokio::{task, time};
@@ -43,21 +43,21 @@ struct Email {
 
 #[actix_web::main]
 async fn main() -> std::io::Result<()> {
-    if let Ok(value) = env::var("RUST_LOG") {
-        env::set_var("RUST_LOG", format!("simple_wkd={}", value));
-    }
     if init_logger().is_err() {
         panic!("Could not set up logger!")
     };
-    fs::create_dir_all(pending_path())?;
+    log_err!(fs::create_dir_all(pending_path()), error)?;
     task::spawn(async {
         let mut metronome = time::interval(time::Duration::from_secs(SETTINGS.cleanup_interval));
         loop {
             metronome.tick().await;
+            debug!("Cleaning up stale data...");
             clean_stale(SETTINGS.max_age);
+            debug!("Cleanup completed!")
         }
     });
-    HttpServer::new(|| {
+    debug!("Starting server...");
+    let server = HttpServer::new(|| {
         App::new()
             .service(submit)
             .service(confirm)
@@ -69,8 +69,13 @@ async fn main() -> std::io::Result<()> {
             .route("/{filename:.*}", web::get().to(index))
     })
     .bind((SETTINGS.bind_host.to_string(), SETTINGS.port))?
-    .run()
-    .await
+    .run();
+    debug!("Server started successfully!");
+    info!(
+        "Listening on: {}:{} (External url: {})",
+        SETTINGS.bind_host, SETTINGS.port, SETTINGS.external_url
+    );
+    server.await
 }
 
 async fn index(req: HttpRequest) -> Result<HttpResponse, CompatErr> {
@@ -89,6 +94,7 @@ async fn index(req: HttpRequest) -> Result<HttpResponse, CompatErr> {
                 .body(page));
         }
     }
+    trace!("The requested file {} could not be found", path.display());
     Err(SpecialErrors::MissingFile)?
 }
 
@@ -99,13 +105,16 @@ async fn submit(pem: web::Form<Key>) -> Result<HttpResponse, CompatErr> {
     is_email_allowed(&email)?;
     let token = gen_random_token();
     store_pending_addition(pem.key.clone(), &email, &token)?;
+    debug!("Sending email to {} to add a key... (Request token: {})", email, token);
     send_confirmation_email(&email, &Action::Add, &token)?;
+    info!("User {} requested to add a key successfully!", email);
     Ok(return_outcome(Ok("You submitted your key successfully!"))?)
 }
 
 #[get("/api/confirm")]
 async fn confirm(token: web::Query<Token>) -> Result<HttpResponse, CompatErr> {
-    let (action, _email) = confirm_action(&token.token)?;
+    let (action, email) = confirm_action(&token.token)?;
+    info!("User {} confirmed to {} his key successfully!", email, action.to_string().to_lowercase());
     match action {
         Action::Add => Ok(return_outcome(Ok("Your key was added successfully!"))?),
         Action::Delete => Ok(return_outcome(Ok("Your key was deleted successfully!"))?),
@@ -116,7 +125,9 @@ async fn confirm(token: web::Query<Token>) -> Result<HttpResponse, CompatErr> {
 async fn delete(email: web::Query<Email>) -> Result<HttpResponse, CompatErr> {
     let token = gen_random_token();
     store_pending_deletion(email.email.clone(), &token)?;
+    debug!("Sending email to {} to add a key... (Request token: {})", email.email, token);
     send_confirmation_email(&email.email, &Action::Delete, &token)?;
+    info!("User {} requested to delete his key successfully!", email.email);
     Ok(return_outcome(Ok(
         "You requested the deletion of your key successfully!",
     ))?)

backend/src/management.rs

@@ -1,8 +1,10 @@
-use crate::settings::ROOT_FOLDER;
-use crate::utils::{get_user_file_path, key_exists, read_file, pending_path};
+use crate::log_err;
+use crate::settings::{ERROR_TEXT, ROOT_FOLDER};
+use crate::utils::{get_user_file_path, key_exists, pending_path, read_file};
 
 use anyhow::Result;
 use chrono::Utc;
+use log::{debug, warn};
 use serde::{Deserialize, Serialize};
 use std::{fmt::Display, fs, path::Path};
 
@@ -53,8 +55,8 @@ impl Pending {
 }
 
 fn store_pending(pending: &Pending, token: &str) -> Result<()> {
-    let serialized = toml::to_string(pending)?;
-    fs::write(pending_path().join(token), serialized)?;
+    let serialized = log_err!(toml::to_string(pending), warn)?;
+    log_err!(fs::write(pending_path().join(token), serialized), warn)?;
     Ok(())
 }
 
@@ -82,19 +84,23 @@ pub fn clean_stale(max_age: i64) {
         };
         let key = match toml::from_str::<Pending>(&content) {
             Ok(key) => key,
-            Err(_) => {
+            Err(error) => {
+                warn!("{} {}", ERROR_TEXT, error);
                 continue;
             }
         };
         let now = Utc::now().timestamp();
         if now - key.timestamp() > max_age {
-            let _ = fs::remove_file(&file_path);
+            match fs::remove_file(&file_path) {
+                Ok(_) => debug!("Deleted {}, since it was stale", file_path.display()),
+                Err(error) => warn!("{} {}", ERROR_TEXT, error),
+            };
         }
     }
 }
 
 pub fn delete_key(email: &str) -> Result<()> {
     let path = Path::new(&ROOT_FOLDER).join(get_user_file_path(email)?);
-    fs::remove_file(path)?;
+    log_err!(fs::remove_file(path), warn)?;
     Ok(())
 }

backend/src/settings.rs

@@ -1,4 +1,5 @@
 use lettre::{transport::smtp::authentication::Credentials, SmtpTransport};
+use log::error;
 use once_cell::sync::Lazy;
 use sequoia_net::wkd::Variant;
 use sequoia_openpgp::policy::StandardPolicy;
@@ -6,7 +7,7 @@ use serde::{Deserialize, Serialize};
 use std::path::PathBuf;
 use url::Url;
 
-use crate::utils::read_file;
+use crate::{log_err, utils::read_file};
 
 #[derive(Serialize, Deserialize, Debug)]
 pub struct Settings {
@@ -52,7 +53,7 @@ fn get_settings() -> Settings {
             panic!("Unable to access settings file!")
         }
     };
-    let settings = match toml::from_str(&content) {
+    let settings = match log_err!(toml::from_str(&content), error) {
         Ok(settings) => settings,
         Err(_) => {
             panic!("Unable to parse settings from file!")

backend/src/utils.rs

@@ -1,5 +1,6 @@
 use crate::errors::CompatErr;
 use crate::errors::SpecialErrors;
+use crate::log_err;
 use crate::settings::ROOT_FOLDER;
 use crate::settings::SETTINGS;
 
@@ -9,9 +10,10 @@ use actix_web::{
     HttpResponse, HttpResponseBuilder,
 };
 use anyhow::Result;
-use flexi_logger::{
-    style, DeferredNow, FileSpec, FlexiLoggerError, Logger, LoggerHandle, Record,
-};
+use flexi_logger::{style, DeferredNow, FileSpec, FlexiLoggerError, Logger, LoggerHandle, Record};
+use log::debug;
+use log::trace;
+use log::warn;
 use rand::{distributions::Alphanumeric, thread_rng, Rng};
 use sequoia_net::wkd::Url;
 use sequoia_openpgp::{parse::Parse, Cert};
@@ -23,14 +25,13 @@ use std::{
 #[macro_export]
 macro_rules! validate_cert {
     ( $x:expr ) => {
-        match $x.with_policy($crate::settings::POLICY, None) {
+        match log_err!($x.with_policy($crate::settings::POLICY, None), debug) {
             Ok(validcert) => Ok(validcert),
             Err(_) => Err($crate::errors::SpecialErrors::InvalidCert),
         }
     };
 }
 
-
 pub fn pending_path() -> PathBuf {
     Path::new(&ROOT_FOLDER).join("pending")
 }
@@ -41,25 +42,25 @@ pub fn webpage_path() -> PathBuf {
 
 pub fn read_file(path: &PathBuf) -> Result<String> {
     if path.is_file() {
-        Ok(fs::read_to_string(path)?)
+        Ok(log_err!(fs::read_to_string(path), warn)?)
     } else {
+        trace!("The requested file {} does not exist", path.display());
         Err(SpecialErrors::MissingFile)?
     }
 }
 
 pub fn is_email_allowed(email: &str) -> Result<()> {
-    let allowed = match email.split('@').last() {
-        Some(domain) => SETTINGS.allowed_domains.contains(&domain.to_string()),
-        None => Err(SpecialErrors::MalformedEmail)?,
-    };
+    let domain = extract_domain(email)?;
+    let allowed = SETTINGS.allowed_domains.contains(&domain);
     if !allowed {
+        debug!("User {} was rejected: domain not whitelisted", email);
         Err(SpecialErrors::UnallowedDomain)?;
     }
     Ok(())
 }
 
 pub fn parse_pem(pemfile: &str) -> Result<Cert> {
-    let cert = match sequoia_openpgp::Cert::from_bytes(pemfile.as_bytes()) {
+    let cert = match log_err!(sequoia_openpgp::Cert::from_bytes(pemfile.as_bytes()), debug) {
         Ok(cert) => cert,
         Err(_) => Err(SpecialErrors::MalformedCert)?,
     };
@@ -74,22 +75,34 @@ pub fn gen_random_token() -> String {
 
 pub fn get_email_from_cert(cert: &Cert) -> Result<String> {
     let validcert = validate_cert!(cert)?;
-    let userid_opt = validcert.primary_userid()?;
+    let userid_opt = log_err!(validcert.primary_userid(), debug)?;
     let email_opt = userid_opt.email()?;
     match email_opt {
         Some(email) => Ok(email),
-        None => Err(SpecialErrors::EmailMissing)?,
+        None => log_err!(Err(SpecialErrors::EmailMissing), debug)?,
     }
 }
 
+pub fn extract_domain(email: &str) -> Result<String> {
+    let domain = match email.split('@').last() {
+        Some(domain) => domain.to_string(),
+        None => {
+            debug!("Unable to extract domain from {}, email malformed", email);
+            Err(SpecialErrors::MalformedEmail)?
+        }
+    };
+    Ok(domain)
+}
+
 pub fn get_user_file_path(email: &str) -> Result<PathBuf> {
-    let wkd_url = Url::from(email)?;
+    let wkd_url = log_err!(Url::from(email), debug)?;
     wkd_url.to_file_path(SETTINGS.variant)
 }
 
 pub fn key_exists(email: &str) -> Result<bool> {
     let path = get_user_file_path(email)?;
     if !Path::new(&ROOT_FOLDER).join(path).is_file() {
+        debug!("No key found for user {}", email);
         Err(SpecialErrors::InexistingUser)?
     }
     Ok(true)