From 596f36164d131044b43cb463a367cc08a75c16d0 Mon Sep 17 00:00:00 2001 From: Volkor <me@volkor.me> Date: Sat, 8 Jul 2023 00:09:25 +1000 Subject: [PATCH] FIX: clean up logging a bunch more --- src/db.rs | 25 +++++++++++-------------- src/engine.rs | 11 ++++++----- src/engine_tests.rs | 4 +++- src/handlers/delete_file.rs | 15 +++++++-------- src/handlers/index.rs | 9 +++++---- src/handlers/list_files.rs | 10 ++++++---- src/handlers/mod.rs | 32 +++++++++++++++----------------- src/handlers/serve_file.rs | 16 +++++++++++----- src/handlers/serve_static.rs | 21 ++++++++++++--------- src/handlers/upload.rs | 15 ++++++++------- 10 files changed, 84 insertions(+), 74 deletions(-) diff --git a/src/db.rs b/src/db.rs index 7499508..f5fb28e 100644 --- a/src/db.rs +++ b/src/db.rs @@ -1,6 +1,6 @@ use sqlx::{sqlite::SqliteQueryResult, Pool, Sqlite}; use std::{collections::HashMap, time::SystemTime}; -use tracing::debug; +use tracing::{debug, error}; /// This struct represents a single file, with a few statistics about said file instance. pub struct FileMetric { @@ -88,11 +88,9 @@ pub async fn add_file( ) .execute(sqlconn) .await?; - tracing::debug!( + debug!( "[{}] Added {} ({}) to the database", - &domain, - &file, - &mimetype + &domain, &file, &mimetype ); Ok(result) // Will need to add another else if for expiry_override if added later. @@ -131,10 +129,9 @@ where _ => { // We found more than one file, so log it and say we found one. // I tried passing this up as MultipleFilesFound in the enum, but that made it hard to just "log and run" - tracing::error!( + error!( "The check_file query received multiple entries for one file: {}, count: {}", - &fname, - result.count + &fname, result.count ); Ok(FileCheckResult::Found) } @@ -174,7 +171,7 @@ pub async fn get_mimetype(sqlconn: &Pool<Sqlite>, file: &str) -> Result<String, /// This doesn't delete the file on disk, however. /// Returns the number of the number of rows affected (files deleted). pub async fn delete_file(sqlconn: &Pool<Sqlite>, filename: &String) -> Result<u64, sqlx::Error> { - tracing::debug!("delete_file(adminkey: {})", filename); + debug!("delete_file(adminkey: {})", filename); let result = sqlx::query!("UPDATE files SET isDeleted = 1 WHERE file = ?", filename) .execute(sqlconn) .await?; @@ -237,7 +234,7 @@ pub async fn get_old_files(sqlconn: &Pool<Sqlite>) -> Result<Vec<String>, sqlx:: let files: Vec<String> = result.iter().map(|r| r.file.to_owned()).collect(); // Print debug and return - tracing::debug!("get_old_files(files: {:?})", files); + debug!("get_old_files(files: {:?})", files); Ok(files) } @@ -337,7 +334,7 @@ pub async fn get_total_uploads_ip(sqlconn: &Pool<Sqlite>) -> Option<HashMap<Stri if result.is_err() { // If Error, return none and log. - tracing::error!("Problem getting total files by ip: {:?}", result); + error!("Problem getting total files by ip: {:?}", result); None } else { for row in result.unwrap() { @@ -364,7 +361,7 @@ pub async fn total_alive_filesize(sqlconn: &Pool<Sqlite>) -> Option<u128> { .await; if result.is_err() { // If Error, return none and log. - tracing::error!("Problem getting total files by ip: {:?}", result); + error!("Problem getting total files by ip: {:?}", result); None } else { for row in result.unwrap() { @@ -393,7 +390,7 @@ pub async fn total_dead_filesize(sqlconn: &Pool<Sqlite>) -> Option<u128> { .await; if result.is_err() { // If Error, return none and log. - tracing::error!("Problem getting total files by ip: {:?}", result); + error!("Problem getting total files by ip: {:?}", result); None } else { for row in result.unwrap() { @@ -420,7 +417,7 @@ pub async fn get_file_metrics(sqlconn: &Pool<Sqlite>) -> Option<Vec<FileMetric>> if result.is_err() { // If Error, return none and log. - tracing::error!("Problem getting filesizes: {:?}", result); + error!("Problem getting filesizes: {:?}", result); None } else { for row in result.unwrap() { diff --git a/src/engine.rs b/src/engine.rs index 378ed70..5bc0105 100644 --- a/src/engine.rs +++ b/src/engine.rs @@ -8,6 +8,7 @@ use std::{ path::{Path, PathBuf}, time::SystemTime, }; +use tracing::{debug, error}; /// Generate a random name for the uploaded file. /// Files with no file extension are completely randomised @@ -24,12 +25,12 @@ where // Add the extension to the new filename, if it exists. if let Some(ext) = ext { - tracing::debug!("generate_filename(File Extension ({:?}) detected)", ext); + debug!("generate_filename(File Extension ({:?}) detected)", ext); let random_filename: PathBuf = (nanoid!(length) + "." + ext.to_str().unwrap_or("")).into(); - tracing::debug!("generate_filename(New filename: {:?} )", random_filename); + debug!("generate_filename(New filename: {:?} )", random_filename); return random_filename; } - tracing::debug!("generate_filename(New filename: {:?} )", random_filename); + debug!("generate_filename(New filename: {:?} )", random_filename); random_filename } @@ -62,7 +63,7 @@ where 2 => engine_2(filesize).await, 3 => engine_3(sqlconn, filename.as_ref(), filesize).await, _ => { - tracing::error!("Unknown engine mode: {}", engine_mode); + error!("Unknown engine mode: {}", engine_mode); std::process::exit(2); } }; @@ -71,7 +72,7 @@ where // Especially since many of these are just the fn name and arguments passed. There's probably some crate that lets you just #[derive(Log)] or something // audron: for the calculate_expiry() function logging https://docs.rs/tracing/latest/tracing/attr.instrument.html might help, tho idk rn if it also logs return value on function exit // Volkor note: I tried adding instrument but it didn't return anything, so idk, I've cleaned this up a little bit more, but I'll keep wasteful logging on the mind when I do it. - tracing::debug!( + debug!( "calculate_expiry(file: {}, expiry: {}) ", filename.as_ref(), expiry diff --git a/src/engine_tests.rs b/src/engine_tests.rs index 431cfb7..70ab689 100644 --- a/src/engine_tests.rs +++ b/src/engine_tests.rs @@ -1,5 +1,7 @@ #[cfg(test)] mod tests { + use tracing::error; + use crate::{ db, db_tests, engine::{self, generate_filename, lifetime_0x0}, @@ -106,7 +108,7 @@ mod tests { let pool = match db_tests::tests::init_test_db().await { Ok(pool) => pool, Err(err) => { - tracing::error!("Error initialising database connection: {:?}", err); + error!("Error initialising database connection: {:?}", err); return; } }; diff --git a/src/handlers/delete_file.rs b/src/handlers/delete_file.rs index 2679a81..471602f 100644 --- a/src/handlers/delete_file.rs +++ b/src/handlers/delete_file.rs @@ -5,6 +5,7 @@ use salvo::{ writer::Text, Request, Response, }; +use tracing::{debug, error, info}; use crate::{ db, engine, @@ -19,7 +20,7 @@ pub async fn delete_file(req: &mut Request, res: &mut Response) { let headers = req.headers().clone(); let sqlconn = SQLITE.get().unwrap(); let adminkey: &String = &req.param("adminkey").unwrap(); - tracing::debug!("delete_file(adminkey): {:?}", adminkey); + debug!("delete_file(adminkey): {:?}", adminkey); // Returns true if the "source" field in the HTTP request's form data is "web", false otherwise or if an error occurs. // Since we don't have a 'source' field in the request, we guess from the user agent. It's not perfect, but it works. and it's not really a security problem. @@ -40,23 +41,21 @@ pub async fn delete_file(req: &mut Request, res: &mut Response) { db::delete_file(sqlconn, &fname) .await .unwrap_or_else(|err| { - tracing::error!( + error!( "Failed to delete file from the database: {} error: {:?}", - &fname, - err + &fname, err ); 0 }); engine::delete_file(&fname).await.unwrap_or_else(|err| { - tracing::error!( + error!( "Failed to delete file from the filesystem: {} error: {:?}", - &fname, - err + &fname, err ); }); - tracing::info!("File deleted: {}", &fname); + info!("File deleted: {}", &fname); // Respond to the client. if upload_by_web { diff --git a/src/handlers/index.rs b/src/handlers/index.rs index 7d86d22..2380f4d 100644 --- a/src/handlers/index.rs +++ b/src/handlers/index.rs @@ -1,5 +1,6 @@ use salvo::{handler, hyper::header::HOST, prelude::StatusCode, Request, Response}; use std::path::PathBuf; +use tracing::{debug, info}; use crate::handlers::{render_template, TemplateStruct}; @@ -8,12 +9,12 @@ use crate::handlers::{render_template, TemplateStruct}; pub async fn index(req: &mut Request, res: &mut Response) { // Get the headers (for Host header stuff thats needed later) let headers = req.headers(); - let host = headers[HOST].to_str().unwrap_or("localhost:8282"); - tracing::info!("New Request: /"); + let domain = headers[HOST].to_str().unwrap_or("localhost:8282"); + info!("[{}]New Request: /", &domain); // Renders the template based on `/templates/$host/upload.html` - let template_host_path = PathBuf::from("./templates/").join(host); - tracing::debug!("template_with_host: {:?}", template_host_path); + let template_host_path = PathBuf::from("./templates/").join(domain); + debug!("template_with_host: {:?}", template_host_path); let template = TemplateStruct { domain: String::from(headers[HOST].to_str().unwrap()), diff --git a/src/handlers/list_files.rs b/src/handlers/list_files.rs index c144d52..ae70094 100644 --- a/src/handlers/list_files.rs +++ b/src/handlers/list_files.rs @@ -1,4 +1,5 @@ use salvo::{handler, hyper::header::HOST, prelude::StatusCode, Request, Response}; +use tracing::{debug, error, info}; use crate::{ db, @@ -24,7 +25,7 @@ pub async fn list_files(req: &mut Request, res: &mut Response) { let remote_addr = &req.remote_addr().clone(); let ip = guess_ip(headers, remote_addr); - tracing::debug!("list_files(remote_addr, ip): {:?}, {:?}", remote_addr, ip); + debug!("list_files(remote_addr, ip): {:?}, {:?}", remote_addr, ip); // This returns a Vec of all the files uploaded by a specific IP Address let files = db::get_my_files(sqlconn, &ip).await; @@ -66,7 +67,7 @@ pub async fn list_files(req: &mut Request, res: &mut Response) { } Err(err) => { // Log error to console - tracing::error!("Error retrieving file metrics: {:?}", err); + error!("Error retrieving file metrics: {:?}", err); // Render a nice error page for the poor user let template_filename = "error.html"; @@ -88,8 +89,9 @@ pub async fn list_files(req: &mut Request, res: &mut Response) { html.push_str("</table>"); // Log this to the server console - tracing::info!( - "New Request: /my_files ({} Files)", + info!( + "[{}]New Request: /my_files ({} Files)", + &headers[HOST].to_str().unwrap(), count_file_metrics(&files) ); diff --git a/src/handlers/mod.rs b/src/handlers/mod.rs index fc369e8..e2ac274 100644 --- a/src/handlers/mod.rs +++ b/src/handlers/mod.rs @@ -17,6 +17,7 @@ use salvo::{ }; use sqlx::{sqlite::SqliteQueryResult, Error}; use tokio::{task, time}; +use tracing::{debug, error, info}; use crate::{ db::{self, FileMetric}, @@ -71,20 +72,18 @@ pub fn guess_ip(headers: &HeaderMap, ip: &SocketAddr) -> String { let cloudflare_ip: Option<String> = headers .get("CF-Connecting-IP") .map(|hv| hv.to_str().unwrap().to_owned()); - tracing::debug!("guess_ip(CF-Connecting-IP: {:?})", cloudflare_ip); + debug!("guess_ip(CF-Connecting-IP: {:?})", cloudflare_ip); // Define x_real_ip, or None let x_real_ip: Option<String> = headers .get("X-Real-IP") .map(|hv| hv.to_str().unwrap().to_owned()); - tracing::debug!("guess_ip(X-Real-IP: {:?})", x_real_ip); + debug!("guess_ip(X-Real-IP: {:?})", x_real_ip); if cloudflare_ip.is_none() { // Either there was a problem with the cloudflare header, or there is no cloudflare. - tracing::debug!( - "guess_ip(No cloudflare header detected!, falling back to X-Real-IP header)" - ); + debug!("guess_ip(No cloudflare header detected!, falling back to X-Real-IP header)"); if x_real_ip.is_none() { - tracing::debug!("guess_ip(No X-Real-IP detected!, falling back to remote_addr header)"); + debug!("guess_ip(No X-Real-IP detected!, falling back to remote_addr header)"); match ip { SocketAddr::IPv4(addr) => return addr.ip().to_string(), @@ -100,8 +99,8 @@ pub fn guess_ip(headers: &HeaderMap, ip: &SocketAddr) -> String { } // Unable to determine ip, use 0.0.0.0 - tracing::debug!("guess_ip(headers): {:?}", headers); - tracing::error!("guess_ip(Failed to guess ip, falling back to 0.0.0.0)"); + debug!("guess_ip(headers): {:?}", headers); + error!("guess_ip(Failed to guess ip, falling back to 0.0.0.0)"); "0.0.0.0".to_string() } @@ -169,12 +168,12 @@ where .iter() .map(|mime| { let mime_str = mime.clone().to_lowercase(); - tracing::debug!("Banned mimetype: {}", mime_str); + debug!("Banned mimetype: {}", mime_str); mime_str }) .collect(); - tracing::debug!("Provided mimetype: {}", lowercase_mimetype); + debug!("Provided mimetype: {}", lowercase_mimetype); lowercase_banned.contains(&lowercase_mimetype) } @@ -239,26 +238,25 @@ pub fn cleaner_thread(period: i32) { match old_files_result { Ok(file_list) => { - tracing::info!("Running Cleaner"); + info!("Running Cleaner"); for file in file_list { // Delete the file from the database db::delete_file(sqlconn, &file).await.unwrap_or_else(|err| { - tracing::error!( + error!( "Failed to delete file from database: {}, error: {:?}", - &file, - err + &file, err ); 0 }); // Delete the file from the filesystem engine::delete_file(&file).await.unwrap_or_else(|err| { - tracing::error!("Failed to delete file from database: {:?}", err); + error!("Failed to delete file from database: {:?}", err); }); } - tracing::info!("Cleaner finished"); + info!("Cleaner finished"); } Err(err) => { - tracing::error!("Error getting files to expire: {}", err); + error!("Error getting files to expire: {}", err); // Return a empty Vec so it doesn't delete anything return Vec::<String>::new(); } diff --git a/src/handlers/serve_file.rs b/src/handlers/serve_file.rs index 357d73e..a86c154 100644 --- a/src/handlers/serve_file.rs +++ b/src/handlers/serve_file.rs @@ -11,7 +11,7 @@ use salvo::{ Request, Response, }; use std::time::SystemTime; -use tracing::{debug, info, error}; +use tracing::{debug, error, info}; use crate::{ db::{self, FileCheckResult}, @@ -28,7 +28,11 @@ pub async fn render_file(req: &mut Request, res: &mut Response, headers: HeaderM .param("file") .expect("Failed to set the filename variable"); - info!("[{}]File View: {:?}", &headers[HOST].to_str().unwrap(), &filename.to_string()); + info!( + "[{}]File View: {:?}", + &headers[HOST].to_str().unwrap(), + &filename.to_string() + ); // Get a new sql pool thingy let sqlconn = SQLITE.get().expect("Failed to grab sqlite pool"); @@ -64,8 +68,7 @@ pub async fn render_file(req: &mut Request, res: &mut Response, headers: HeaderM .unwrap_or_else(|err| { error!( "Failed to update fileview for file: {} error: {:?}", - &filename, - err + &filename, err ); error!("soft-setting fileview to 0 for file: {}", &filename); 0 @@ -169,7 +172,10 @@ pub async fn serve_file(req: &mut Request, res: &mut Response) { match check_file_exists(&filename, "files/").await { // File does exist in the filesystem! true => { - info!("Adding previously unknown file to the database: {}", &filename); + info!( + "Adding previously unknown file to the database: {}", + &filename + ); // Add the file to the database match add_undeleted_file(&filename).await { Ok(_) => { diff --git a/src/handlers/serve_static.rs b/src/handlers/serve_static.rs index 7788144..7d5a437 100644 --- a/src/handlers/serve_static.rs +++ b/src/handlers/serve_static.rs @@ -8,6 +8,7 @@ use salvo::{ Request, Response, }; use std::path::PathBuf; +use tracing::{error, info}; use super::guess_ip; use crate::{db, handlers::TemplateStruct, SQLITE}; @@ -28,7 +29,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { // Although I'm not sure how much it would actually improve things, maybe just for readability? match req.uri().path() { "/services" => { - tracing::info!("New Request: /services"); + info!("[{}]New Request: /services", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -42,7 +43,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/about" => { - tracing::info!("New Request: /about"); + info!("[{}]New Request: /about", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -56,7 +57,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/faq" => { - tracing::info!("New Request: /faq"); + info!("[{}]New Request: /faq", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -70,7 +71,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/dmca" => { - tracing::info!("New Request: /dmca"); + info!("[{}]New Request: /dmca", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -85,7 +86,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/welcome" => { - tracing::info!("New Request: /welcome"); + info!("[{}]New Request: /welcome", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -100,7 +101,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/czb" => { - tracing::info!("New Request: /czb"); + info!("[{}]New Request: /czb", &host); let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( Ramhorns::from_folder(template_host_path_default) .expect("Couldn't find default template"), @@ -115,7 +116,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } "/qr" => { - tracing::info!("New Request: /qr"); + info!("[{}]New Request: /qr", &host); // Setup the Sqlite pool stuff for later let sqlconn = SQLITE.get().unwrap(); // Get the headers (for Host header stuff thats needed later) @@ -125,7 +126,7 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { .await .is_err() { - tracing::error!("Failed to add QR Scan to the database."); + error!("Failed to add QR Scan to the database."); } let tpls: Ramhorns = Ramhorns::from_folder(template_host_path).unwrap_or( @@ -142,7 +143,9 @@ pub async fn serve_static(req: &mut Request, res: &mut Response) { res.render(Text::Html(rendered)); } _ => { - tracing::info!("Bad Request Received"); + info!("Bad Request Received"); + // TODO: Nice Render page + res.status_code(StatusCode::BAD_REQUEST); } } } diff --git a/src/handlers/upload.rs b/src/handlers/upload.rs index a629b48..d82f124 100644 --- a/src/handlers/upload.rs +++ b/src/handlers/upload.rs @@ -6,6 +6,7 @@ use std::{ path::{Path, PathBuf}, time::SystemTime, }; +use tracing::{debug, error, info}; use super::guess_ip; use crate::{ @@ -131,24 +132,24 @@ pub async fn upload(req: &mut Request, res: &mut Response) { // file.size seems to be always 'None', so we'll ask the filesystem. let path = Path::new(file.path()); let filesize = fs::metadata(path).unwrap().len() as i32; - tracing::debug!("upload(filesize): {:?}", filesize); + debug!("upload(filesize): {:?}", filesize); let expiry = engine::calculate_expiry(sqlconn, &filename.to_str().unwrap(), filesize).await; // Convert that expiry to actual time and date (for display) let expiry_dt = Utc.timestamp_opt(expiry as i64, 0).unwrap(); - tracing::debug!("upload(expiry): {:?}", expiry); + debug!("upload(expiry): {:?}", expiry); // Determine what ip type it is. - tracing::debug!("upload(headers): {:?}", headers); + debug!("upload(headers): {:?}", headers); let ip = guess_ip(headers, remote_addr); - tracing::debug!("upload(ip): {:?}", ip); + debug!("upload(ip): {:?}", ip); // Get the current time let accessed = SystemTime::now() .duration_since(SystemTime::UNIX_EPOCH) .unwrap(); - tracing::debug!("upload(accessed): {:?}", accessed); + debug!("upload(accessed): {:?}", accessed); // Add file to the database, or print an error. if let Err(e) = db::add_file( @@ -165,10 +166,10 @@ pub async fn upload(req: &mut Request, res: &mut Response) { ) .await { - tracing::error!("File upload error: {:?}", e); + error!("File upload error: {:?}", e); } - tracing::info!("File uploaded to {:?}", dest); + info!("File uploaded to {:?}", dest); let fileurl = format!( "{}://{}/{}", -- GitLab