Merge pull request 'Fix #623 tracing crate' (#868) from logging into main

Reviewed-on: https://git.joinplu.me/Plume/Plume/pulls/868

I read tracing's documentation and thought that is what I need. I decided use it instead of log crate. Thank you for info, igalic.

Cargo.lock

@@ -2598,6 +2598,7 @@ dependencies = [
  "serde 1.0.118 (registry+https://github.com/rust-lang/crates.io-index)",
  "serde_json 1.0.61 (registry+https://github.com/rust-lang/crates.io-index)",
  "shrinkwraprs 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)",
  "validator 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "validator_derive 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "webfinger 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -2646,6 +2647,7 @@ dependencies = [
  "shrinkwraprs 0.3.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "syntect 4.5.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "tokio 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
 [[package]]
@@ -2704,6 +2706,7 @@ dependencies = [
  "serde_json 1.0.61 (registry+https://github.com/rust-lang/crates.io-index)",
  "shrinkwraprs 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)",
  "tantivy 0.12.0 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)",
  "url 2.2.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "walkdir 2.3.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "webfinger 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -4179,9 +4182,20 @@ dependencies = [
  "cfg-if 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "log 0.4.11 (registry+https://github.com/rust-lang/crates.io-index)",
  "pin-project-lite 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)",
+ "tracing-attributes 0.1.11 (registry+https://github.com/rust-lang/crates.io-index)",
  "tracing-core 0.1.17 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
+[[package]]
+name = "tracing-attributes"
+version = "0.1.11"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+dependencies = [
+ "proc-macro2 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)",
+ "quote 1.0.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "syn 1.0.56 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
 [[package]]
 name = "tracing-core"
 version = "0.1.17"
@@ -5071,6 +5085,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 "checksum toml 0.4.10 (registry+https://github.com/rust-lang/crates.io-index)" = "758664fc71a3a69038656bee8b6be6477d2a6c315a6b81f7081f591bffa4111f"
 "checksum tower-service 0.3.0 (registry+https://github.com/rust-lang/crates.io-index)" = "e987b6bf443f4b5b3b6f38704195592cca41c5bb7aedd3c3693c7081f8289860"
 "checksum tracing 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)" = "9f47026cdc4080c07e49b37087de021820269d996f581aac150ef9e5583eefe3"
+"checksum tracing-attributes 0.1.11 (registry+https://github.com/rust-lang/crates.io-index)" = "80e0ccfc3378da0cce270c946b676a376943f5cd16aeba64568e7939806f4ada"
 "checksum tracing-core 0.1.17 (registry+https://github.com/rust-lang/crates.io-index)" = "f50de3927f93d202783f4513cda820ab47ef17f624b03c096e86ef00c67e6b5f"
 "checksum tracing-futures 0.2.4 (registry+https://github.com/rust-lang/crates.io-index)" = "ab7bb6f14721aa00656086e9335d363c5c8747bae02ebe32ea2c7dece5689b4c"
 "checksum traitobject 0.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "efd1f82c56340fdf16f2a953d7bda4f8fdffba13d93b00844c25572110b26079"

Cargo.toml

@@ -30,6 +30,7 @@ shrinkwraprs = "0.2.1"
 validator = "0.8"
 validator_derive = "0.8"
 webfinger = "0.4.1"
+tracing = "0.1.22"
 
 [[bin]]
 name = "plume"

plume-common/Cargo.toml

@@ -23,6 +23,7 @@ shrinkwraprs = "0.3.0"
 syntect = "4.5.0"
 tokio = "0.1.22"
 regex-syntax = { version = "0.6.17", default-features = false, features = ["unicode-perl"] }
+tracing = "0.1.22"
 
 [dependencies.chrono]
 features = ["serde"]

plume-common/src/activity_pub/mod.rs

@@ -1,5 +1,6 @@
 use activitypub::{Activity, Link, Object};
 use array_tool::vec::Uniq;
+use tracing::{debug, warn};
 use reqwest::r#async::ClientBuilder;
 use rocket::{
     http::Status,
@@ -153,10 +154,10 @@ where
                 .send()
                 .and_then(|r| r.into_body().concat2())
                 .map(move |response| {
-                    println!("Successfully sent activity to inbox ({})", inbox);
+                    debug!("Successfully sent activity to inbox ({})", inbox);
-                    println!("Response: \"{:?}\"\n", response)
+                    debug!("Response: \"{:?}\"\n", response)
                 })
-                .map_err(|e| println!("Error while sending to inbox ({:?})", e)),
+                .map_err(|e| warn!("Error while sending to inbox ({:?})", e)),
         );
     }
     rt.run().unwrap();

plume-models/Cargo.toml

@@ -32,6 +32,7 @@ shrinkwraprs = "0.2.1"
 diesel-derive-newtype = "0.1.2"
 glob = "0.3.0"
 lindera-tantivy = { version = "0.1.3", optional = true }
+tracing = "0.1.22"
 
 [dependencies.chrono]
 features = ["serde"]

plume-models/src/migrations.rs

@@ -1,5 +1,6 @@
 use crate::{Connection, Error, Result};
 use diesel::connection::{Connection as Conn, SimpleConnection};
+use tracing::info;
 use migrations_internals::{setup_database, MigrationConnection};
 use std::path::Path;
 
@@ -26,7 +27,7 @@ struct ComplexMigration {
 
 impl ComplexMigration {
     fn run(&self, conn: &Connection, path: &Path) -> Result<()> {
-        println!("Running migration {}", self.name);
+        info!("Running migration {}", self.name);
         for step in self.up {
             step.run(conn, path)?
         }
@@ -34,7 +35,7 @@ impl ComplexMigration {
     }
 
     fn revert(&self, conn: &Connection, path: &Path) -> Result<()> {
-        println!("Reverting migration {}", self.name);
+        info!("Reverting migration {}", self.name);
         for step in self.down {
             step.run(conn, path)?
         }

src/inbox.rs

@@ -1,3 +1,4 @@
+use tracing::warn;
 use plume_common::activity_pub::{
     inbox::FromId,
     request::Digest,
@@ -41,7 +42,7 @@ pub fn handle_incoming(
                 }
             })
             .map_err(|_| {
-                println!(
+                warn!(
                     "Rejected invalid activity supposedly from {}, with headers {:?}",
                     actor.username, headers.0
                 );
@@ -58,7 +59,7 @@ pub fn handle_incoming(
     Ok(match inbox(&rockets, act) {
         Ok(_) => String::new(),
         Err(e) => {
-            println!("Shared inbox error: {:?}", e);
+            warn!("Shared inbox error: {:?}", e);
             format!("Error: {:?}", e)
         }
     })

src/main.rs

@@ -13,6 +13,7 @@ extern crate validator_derive;
 use chrono::Utc;
 use clap::App;
 use diesel::r2d2::ConnectionManager;
+use tracing::warn;
 use plume_models::{
     db_conn::{DbPool, PragmaForeignKey},
     instance::Instance,
@@ -50,12 +51,6 @@ compile_i18n!();
 
 /// Initializes a database pool.
 fn init_pool() -> Option<DbPool> {
-    match dotenv::dotenv() {
-        Ok(path) => println!("Configuration read from {}", path.display()),
-        Err(ref e) if e.not_found() => eprintln!("no .env was found"),
-        e => e.map(|_| ()).unwrap(),
-    }
-
     let manager = ConnectionManager::<Connection>::new(CONFIG.database_url.as_str());
     let mut builder = DbPool::builder()
         .connection_customizer(Box::new(PragmaForeignKey))
@@ -69,6 +64,12 @@ fn init_pool() -> Option<DbPool> {
 }
 
 fn main() {
+    match dotenv::dotenv() {
+        Ok(path) => eprintln!("Configuration read from {}", path.display()),
+        Err(ref e) if e.not_found() => eprintln!("no .env was found"),
+        e => e.map(|_| ()).unwrap(),
+    }
+
     App::new("Plume")
         .bin_name("plume")
         .version(env!("CARGO_PKG_VERSION"))
@@ -82,6 +83,8 @@ and https://docs.joinplu.me/installation/init for more info.
         "#,
         )
         .get_matches();
+    // Initialize Rocket early to load its internal logger
+    let rocket = rocket::custom(CONFIG.rocket.clone().unwrap());
     let dbpool = init_pool().expect("main: database pool initialization error");
     if IMPORTED_MIGRATIONS
         .is_pending(&dbpool.get().unwrap())
@@ -112,7 +115,7 @@ Then try to restart Plume.
                 .expect("main: error on backing up search index directory for recreating");
             if UnmanagedSearcher::create(&CONFIG.search_index, &CONFIG.search_tokenizers).is_ok() {
                 if fs::remove_dir_all(backup_path).is_err() {
-                    eprintln!(
+                    warn!(
                         "error on removing backup directory: {}. it remains",
                         backup_path.display()
                     );
@@ -171,11 +174,11 @@ Then try to restart Plume
 
     let mail = mail::init();
     if mail.is_none() && CONFIG.rocket.as_ref().unwrap().environment.is_prod() {
-        println!("Warning: the email server is not configured (or not completely).");
+        warn!("Warning: the email server is not configured (or not completely).");
-        println!("Please refer to the documentation to see how to configure it.");
+        warn!("Please refer to the documentation to see how to configure it.");
     }
 
-    let rocket = rocket::custom(CONFIG.rocket.clone().unwrap())
+    let rocket = rocket
         .mount(
             "/",
             routes![

src/routes/errors.rs

@@ -1,4 +1,5 @@
 use crate::template_utils::{IntoContext, Ructe};
+use tracing::warn;
 use plume_models::{Error, PlumeRocket};
 use rocket::{
     response::{self, Responder},
@@ -49,7 +50,7 @@ pub fn server_error(req: &Request<'_>) -> Ructe {
 #[post("/csrf-violation?<target>")]
 pub fn csrf_violation(target: Option<String>, rockets: PlumeRocket) -> Ructe {
     if let Some(uri) = target {
-        eprintln!("Csrf violation while acceding \"{}\"", uri)
+        warn!("Csrf violation while accessing \"{}\"", uri)
     }
     render!(errors::csrf(&rockets.to_context()))
 }

src/routes/session.rs

@@ -1,5 +1,6 @@
 use crate::routes::RespondOrRedirect;
 use lettre::Transport;
+use tracing::warn;
 use rocket::http::ext::IntoOwned;
 use rocket::{
     http::{uri::Uri, Cookie, Cookies, SameSite},
@@ -155,7 +156,7 @@ pub fn password_reset_request(
         ) {
             if let Some(ref mut mail) = *mail.lock().unwrap() {
                 mail.send(message.into())
-                    .map_err(|_| eprintln!("Couldn't send password reset email"))
+                    .map_err(|_| warn!("Couldn't send password reset email"))
                     .ok();
             }
         }

src/routes/user.rs

@@ -3,6 +3,7 @@ use activitypub::{
     collection::{OrderedCollection, OrderedCollectionPage},
 };
 use diesel::SaveChangesDsl;
+use tracing::{info, warn};
 use rocket::{
     http::{ContentType, Cookies},
     request::LenientForm,
@@ -67,9 +68,9 @@ pub fn details(
                     Ok(article) => {
                         Post::from_activity(&fetch_rockets, article)
                             .expect("Article from remote user couldn't be saved");
-                        println!("Fetched article from remote user");
+                        info!("Fetched article from remote user");
                     }
-                    Err(e) => println!("Error while fetching articles in background: {:?}", e),
+                    Err(e) => warn!("Error while fetching articles in background: {:?}", e),
                 }
             }
         });