logging: Hide too verbose logs, introduce verbose logging by env variable

The system now provides clean, minimal logging by default while preserving all critical error information about upload/download disruptions or security issues.
Debug mode (STORAGE_DEBUG=1) still shows all the verbose details when troubleshooting.

Signed-off-by: Denys Fedoryshchenko <denys.f@collabora.com>

Author: nuclearcat

src/azure.rs

@@ -23,6 +23,15 @@ use serde::Deserialize;
 use std::fs::read_to_string;
 use std::fs::File;
 use std::io::Read;
+use std::env;
+
+macro_rules! debug_log {
+    ($($arg:tt)*) => {
+        if env::var("STORAGE_DEBUG").is_ok() {
+            println!($($arg)*);
+        }
+    };
+}
 use std::io::Write;
 use std::sync::Arc;
 use tempfile::Builder;
@@ -250,7 +259,7 @@ async fn get_file_from_blob(filename: String) -> ReceivedFile {
             return received_file;
         } else {
             // delete cache file and headers
-            println!("Cache file {} is zero length, deleting", cache_filename);
+            debug_log!("Cache file {} is zero length, deleting", cache_filename);
             match std::fs::remove_file(&cache_filename) {
                 Ok(_) => {}
                 Err(e) => {
@@ -273,17 +282,12 @@ async fn get_file_from_blob(filename: String) -> ReceivedFile {
             }
         }
     }
-    /*
-    println!(
-        "Downloading blob to cache file {} from {}",
-        cache_filename, blob_url
-    );
-    */
+    debug_log!("Downloading blob to cache file {} from {}", cache_filename, blob_url);
     let client = Client::new();
     let response = client.get(blob_url).send().await;
     match response {
         Ok(response) => {
-            println!("Response: {:?}", response);
+            debug_log!("Azure response: {:?}", response);
             // is status anything else than 200?
             // TODO: Do we need to return headers as well or it is data leakage?
             if response.status() != 200 {
@@ -359,7 +363,7 @@ async fn azure_list_files(directory: String) -> Vec<String> {
             };
             listing.push(blob_name.clone());
         }
-        println!("Listing count: {}", listing.len());
+        debug_log!("Listing count: {}", listing.len());
     }
     //println!("Listing: {:?}", listing);
     listing

src/main.rs

@@ -26,8 +26,16 @@ use axum_server::tls_rustls::RustlsConfig;
 use clap::Parser;
 use headers::HeaderMap;
 use std::path;
-use std::{net::SocketAddr, path::PathBuf};
+use std::{env, net::SocketAddr, path::PathBuf};
 use tokio::io::AsyncSeekExt;
+
+macro_rules! debug_log {
+    ($($arg:tt)*) => {
+        if env::var("STORAGE_DEBUG").is_ok() {
+            println!($($arg)*);
+        }
+    };
+}
 use tokio_util::io::ReaderStream;
 use toml::Table;
 use tower::ServiceBuilder;
@@ -390,7 +398,6 @@ async fn ax_post_file(headers: HeaderMap, State(state): State<AppState>, mut mul
     if let Some(expect) = headers.get("Expect") {
         println!("Expect: {:?}", expect);
         if expect == "100-continue" {
-            println!("Expect 100-continue");
             return (StatusCode::CONTINUE, Vec::new());
         }
     }
@@ -418,18 +425,17 @@ async fn ax_post_file(headers: HeaderMap, State(state): State<AppState>, mut mul
 
         match data {
             Ok(data) => {
-                println!("Length of `{}` is {} bytes", name, data.len());
+                println!("Field {}: {} bytes", name, data.len());
                 if name == "path" {
                     path = String::from_utf8(data.to_vec()).unwrap();
-                    println!("Path: {}", path);
                 } else if name == "file0" {
                     file0 = data.to_vec();
                     match filename {
                         Some(filename) => file0_filename = filename.to_string(),
                         None => todo!(),
                     }
                 } else {
-                    println!("Unknown field: {} len: {}", name, data.len());
+                    println!("Unknown field {}: {} bytes", name, data.len());
                 }
             }
             Err(e) => {
@@ -441,12 +447,7 @@ async fn ax_post_file(headers: HeaderMap, State(state): State<AppState>, mut mul
             }
         }
     }
-    println!(
-        "File: {} bytes filename: {} path: {}",
-        file0.len(),
-        file0_filename,
-        path
-    );
+    println!("Upload: {} bytes, {}/{}", file0.len(), path, file0_filename);
     // if path ends on /, remove it
     if path.ends_with("/") {
         // TBD: Fix it!
@@ -468,15 +469,11 @@ async fn ax_post_file(headers: HeaderMap, State(state): State<AppState>, mut mul
 
     let content_type: String = match hdr_content_type {
         Some(content_type) => {
-            println!("Content-Type: {:?}", content_type);
             content_type.to_str().unwrap().to_string()
         }
         None => {
             let heuristic_ctype = heuristic_filetype(file0_filename);
-            println!(
-                "Content-Type not found, using heuristics: {}",
-                heuristic_ctype
-            );
+            debug_log!("Content-Type not found, using heuristics: {}", heuristic_ctype);
             heuristic_ctype
         }
     };
@@ -559,7 +556,6 @@ async fn ax_get_file(
     let metadata = tokio::fs::metadata(&cached_file).await.unwrap();
     let mut headers = HeaderMap::new();
     if let Some(content_type) = upstream_headers.get(CONTENT_TYPE) {
-        println!("Stored content-Type: {:?}", content_type);
         headers.insert(header::CONTENT_TYPE, content_type.clone());
     } else {
         headers.insert(
@@ -631,12 +627,10 @@ async fn ax_get_file(
             let mut end = metadata.len();
             // is Content-Range present?
             if let Some(range) = rxheaders.get("Range") {
-                println!("Range: {:?}", range);
                 (start, end) = parse_range(range.to_str().unwrap());
             }
             // if start is set to non-zero, we need to seek
             if start != 0 && (end == metadata.len() || end == 0) {
-                println!("Seeking to {}", start);
                 file.seek(std::io::SeekFrom::Start(start)).await.unwrap();
                 headers.insert(
                     header::CONTENT_RANGE,
@@ -688,7 +682,7 @@ async fn ax_get_file(
             return (StatusCode::OK, headers, axbody).into_response();
         }
         Err(_) => {
-            println!("Error opening file in ax_get_file");
+            eprintln!("Error opening file in ax_get_file");
             println!(
                 "{:?} 404 0 {} {} {} {}",
                 remote_addr, human_time, method, filepath, user_agent_str
@@ -739,7 +733,7 @@ fn verify_auth_hdr(headers: &HeaderMap) -> Result<String, Option<String>> {
         let bmap = match verif_result {
             Ok(bmap) => bmap.clone(),
             Err(_) => {
-                println!("Error verifying token");
+                eprintln!("Error verifying token");
                 return Err(None);
             }
         };
@@ -753,7 +747,7 @@ fn verify_auth_hdr(headers: &HeaderMap) -> Result<String, Option<String>> {
     let bmap = match verif_result {
         Ok(bmap) => bmap.clone(),
         Err(_) => {
-            println!("Error verifying bearer token");
+            eprintln!("Error verifying bearer token");
             return Err(None);
         }
     };

src/storcaching.rs

@@ -1,6 +1,15 @@
 use std::fs;
 use std::time::SystemTime;
 use tokio::time::Duration;
+use std::env;
+
+macro_rules! debug_log {
+    ($($arg:tt)*) => {
+        if env::var("STORAGE_DEBUG").is_ok() {
+            println!($($arg)*);
+        }
+    };
+}
 
 struct Files {
     file: String,
@@ -26,7 +35,7 @@ async fn read_filesinfo(cache_dir: String) -> Vec<Files> {
             files
         }
         Err(_) => {
-            println!("Error reading files");
+            eprintln!("Error reading cache directory files");
             Vec::new()
         }
     }
@@ -38,14 +47,14 @@ async fn freediskspace_percent(cache_dir: String) -> u64 {
     let total = match total_r {
         Ok(total) => total as f64,
         Err(_) => {
-            println!("Error getting total space");
+            eprintln!("Error getting disk total space");
             return 0;
         }
     };
     let free = match free_r {
         Ok(free) => free as f64,
         Err(_) => {
-            println!("Error getting free space");
+            eprintln!("Error getting disk free space");
             return 0;
         }
     };
@@ -58,22 +67,19 @@ fn delete_cache_file(file: String) {
     // Truncate from filename .content, and add .headers, delete both files
     let content_filename = file.clone();
     let headers_filename = file.replace(".content", ".headers");
-    println!(
-        "Deleting files: {} {}",
-        &content_filename, &headers_filename
-    );
+    debug_log!("Deleting files: {} {}", &content_filename, &headers_filename);
     let res = fs::remove_file(&content_filename);
     match res {
         Ok(_) => {}
         Err(_) => {
-            println!("Error deleting file: {}", content_filename);
+            debug_log!("Error deleting file: {}", content_filename);
         }
     }
     let res = fs::remove_file(&headers_filename);
     match res {
         Ok(_) => {}
         Err(_) => {
-            println!("Error deleting file: {}", headers_filename);
+            debug_log!("Error deleting file: {}", headers_filename);
         }
     }
 }
@@ -93,7 +99,7 @@ async fn clean_disk(cache_dir: String) {
     if oldest_file.last_update.elapsed().unwrap() > Duration::from_secs(60 * 60) {
         delete_cache_file(oldest_file.file);
     } else {
-        println!("File is less than 60 min old, skipping: {}, sleeping 60 seconds", oldest_file.file);
+        debug_log!("File is less than 60 min old, skipping: {}, sleeping 60 seconds", oldest_file.file);
         // sleep 60 seconds
         tokio::time::sleep(Duration::from_secs(60)).await;
     }
@@ -119,7 +125,7 @@ pub async fn cache_loop(cache_dir: &str) {
             // critical mode, sleep only 100ms
             tokio::time::sleep(Duration::from_millis(100)).await;
         } else {
-            println!("Free disk space: {}%", free_space);
+            debug_log!("Free disk space: {}%", free_space);
             // normal mode, sleep 10 seconds
             tokio::time::sleep(Duration::from_secs(10)).await;
         }

src/storjwt.rs

@@ -4,6 +4,15 @@ use jwt::{Header, SignWithKey, Token, VerifyWithKey};
 use sha2::Sha256;
 use std::collections::BTreeMap;
 use toml::value::Table;
+use std::env;
+
+macro_rules! debug_log {
+    ($($arg:tt)*) => {
+        if env::var("STORAGE_DEBUG").is_ok() {
+            println!($($arg)*);
+        }
+    };
+}
 pub fn verify_jwt_token(token_str: &str) -> Result<BTreeMap<String, String>, jwt::Error> {
     // config.toml, jwt_secret parameter
     let toml_cfg = get_config_content();
@@ -14,7 +23,7 @@ pub fn verify_jwt_token(token_str: &str) -> Result<BTreeMap<String, String>, jwt
     let token: Token<Header, BTreeMap<String, String>, _> = match verify_result {
         Ok(token) => token,
         Err(e) => {
-            println!("verify_result Error: {:?} token_str: {}", e, token_str);
+            eprintln!("JWT verification error: {:?}", e);
             return Err(e);
         }
     };
@@ -23,10 +32,10 @@ pub fn verify_jwt_token(token_str: &str) -> Result<BTreeMap<String, String>, jwt
     let email = claims.get("email");
     match email {
         Some(email) => {
-            println!("email: {}", email);
+            debug_log!("email: {}", email);
         }
         None => {
-            println!("email not found");
+            debug_log!("email not found");
             return Err(jwt::Error::InvalidSignature);
         }
     }
@@ -42,7 +51,7 @@ pub fn generate_jwt_secret() {
         .take(32)
         .map(char::from)
         .collect();
-    println!("jwt_secret=\"{}\"", secret);
+    debug_log!("jwt_secret=\"{}\"", secret);
 }
 
 pub fn generate_jwt_token(email: &str) -> Result<String, jwt::Error> {