Unfinished attempt to use the tracing-test crate

Cargo.toml

@@ -73,7 +73,7 @@ serde_json = { version = "1", features = ["preserve_order"] }
 serde_repr = "0"
 serde_with = { version = "3", features = ["json"] }
 thiserror = "2"
-tokio = { version = "1", features = ["macros", "net", "rt-multi-thread", "signal", "sync"] }
+tokio = { version = "1", features = ["macros", "net", "rt-multi-thread", "signal", "sync", "macros"] }
 torrust-tracker-clock = { version = "3.0.0-develop", path = "packages/clock" }
 torrust-tracker-configuration = { version = "3.0.0-develop", path = "packages/configuration" }
 torrust-tracker-contrib-bencode = { version = "3.0.0-develop", path = "contrib/bencode" }
@@ -84,6 +84,7 @@ tower = { version = "0", features = ["timeout"] }
 tower-http = { version = "0", features = ["compression-full", "cors", "propagate-header", "request-id", "trace"] }
 tracing = "0"
 tracing-subscriber = { version = "0", features = ["json"] }
+tracing-test = "0.2.5"
 url = { version = "2", features = ["serde"] }
 uuid = { version = "1", features = ["v4"] }
 zerocopy = "0.7"

src/bootstrap/logging.rs

@@ -11,6 +11,7 @@
 //! - `Trace`
 //!
 //! Refer to the [configuration crate documentation](https://docs.rs/torrust-tracker-configuration) to know how to change log settings.
+use std::env;
 use std::sync::Once;
 
 use torrust_tracker_configuration::{Configuration, Threshold};
@@ -21,6 +22,12 @@ static INIT: Once = Once::new();
 /// It redirects the log info to the standard output with the log threshold
 /// defined in the configuration.
 pub fn setup(cfg: &Configuration) {
+    // Check if we are running in test mode
+    if env::var("RUNNING_IN_TEST").unwrap_or_default() == "true" {
+        println!("Running in test mode. Skipping logging setup.");
+        return;
+    }
+
     let tracing_level = map_to_tracing_level_filter(&cfg.logging.threshold);
 
     if tracing_level == LevelFilter::OFF {

src/core/mod.rs

@@ -470,7 +470,7 @@ use torrust_tracker_primitives::torrent_metrics::TorrentsMetrics;
 use torrust_tracker_primitives::{peer, DurationSinceUnixEpoch};
 use torrust_tracker_torrent_repository::entry::EntrySync;
 use torrust_tracker_torrent_repository::repository::Repository;
-use tracing::instrument;
+use tracing::{error, instrument};
 
 use self::auth::Key;
 use self::error::Error;
@@ -480,7 +480,7 @@ use crate::CurrentClock;
 
 /// The domain layer tracker service.
 ///
-/// Its main responsibility is to handle the `announce` and `scrape` requests.
+/// Its main responsibility is to handle the `announce` and `scrape` requests.d
 /// But it's also a container for the `Tracker` configuration, persistence,
 /// authentication and other services.
 ///
@@ -966,6 +966,8 @@ impl Tracker {
     /// * `lifetime` - The duration in seconds for the new key. The key will be
     ///   no longer valid after `lifetime` seconds.
     pub async fn generate_auth_key(&self, lifetime: Option<Duration>) -> Result<auth::PeerKey, databases::error::Error> {
+        error!("This is being logged on the error level");
+
         let auth_key = auth::generate_key(lifetime);
 
         self.database.add_key_to_keys(&auth_key)?;

src/servers/apis/server.rs

@@ -34,7 +34,7 @@ use futures::future::BoxFuture;
 use thiserror::Error;
 use tokio::sync::oneshot::{Receiver, Sender};
 use torrust_tracker_configuration::AccessTokens;
-use tracing::{instrument, Level};
+use tracing::{debug, instrument, Level};
 
 use super::routes::router;
 use crate::bootstrap::jobs::Started;
@@ -129,12 +129,16 @@ impl ApiServer<Stopped> {
         form: ServiceRegistrationForm,
         access_tokens: Arc<AccessTokens>,
     ) -> Result<ApiServer<Running>, Error> {
+        debug!("Starting new API test environment ApiServer<Stopped>::start");
+
         let (tx_start, rx_start) = tokio::sync::oneshot::channel::<Started>();
         let (tx_halt, rx_halt) = tokio::sync::oneshot::channel::<Halted>();
 
         let launcher = self.state.launcher;
 
         let task = tokio::spawn(async move {
+            debug!("Starting new API test environment ApiServer<Stopped>::start spawned task");
+
             tracing::debug!(target: API_LOG_TARGET, "Starting with launcher in spawned task ...");
 
             let _task = launcher.start(tracker, access_tokens, tx_start, rx_halt).await;

tests/common/logging.rs

@@ -18,13 +18,13 @@ use tracing::level_filters::LevelFilter;
 pub static INIT: Once = Once::new();
 
 #[allow(dead_code)]
-pub fn tracing_stderr_init(filter: LevelFilter) {
-    let builder = tracing_subscriber::fmt()
+pub fn tracing_stderr_init(_filter: LevelFilter) {
+    /*let builder = tracing_subscriber::fmt()
         .with_max_level(filter)
         .with_ansi(true)
         .with_writer(std::io::stderr);
 
-    builder.pretty().with_file(true).init();
+    builder.pretty().with_file(true).init();*/
 
     tracing::info!("Logging initialized");
 }

tests/servers/api/environment.rs

@@ -10,6 +10,7 @@ use torrust_tracker::servers::apis::server::{ApiServer, Launcher, Running, Stopp
 use torrust_tracker::servers::registar::Registar;
 use torrust_tracker_configuration::{Configuration, HttpApi};
 use torrust_tracker_primitives::peer;
+use tracing::debug;
 
 use super::connection_info::ConnectionInfo;
 
@@ -35,6 +36,8 @@ where
 
 impl Environment<Stopped> {
     pub fn new(configuration: &Arc<Configuration>) -> Self {
+        debug!("Creating new API test environment: Environment<Stopped>::new");
+
         let tracker = initialize_with_configuration(configuration);
 
         let config = Arc::new(configuration.http_api.clone().expect("missing API configuration"));
@@ -54,6 +57,8 @@ impl Environment<Stopped> {
     }
 
     pub async fn start(self) -> Environment<Running> {
+        debug!("Starting new API test environment: Environment<Stopped>::start");
+
         let access_tokens = Arc::new(self.config.access_tokens.clone());
 
         Environment {
@@ -71,6 +76,8 @@ impl Environment<Stopped> {
 
 impl Environment<Running> {
     pub async fn new(configuration: &Arc<Configuration>) -> Self {
+        debug!("Creating new API test environment: Environment<Running>::new");
+
         Environment::<Stopped>::new(configuration).start().await
     }
 

tests/servers/api/v1/contract/context/auth_key.rs

@@ -2,8 +2,11 @@ use std::time::Duration;
 
 use serde::Serialize;
 use torrust_tracker::core::auth::Key;
+use torrust_tracker_configuration::Threshold;
 use torrust_tracker_test_helpers::configuration;
+use tracing::error;
 use tracing::level_filters::LevelFilter;
+use tracing_test::traced_test;
 
 use crate::common::logging::{tracing_stderr_init, INIT};
 use crate::servers::api::connection_info::{connection_with_invalid_token, connection_with_no_token};
@@ -249,12 +252,21 @@ async fn should_fail_deleting_an_auth_key_when_the_key_id_is_invalid() {
 }
 
 #[tokio::test]
+#[traced_test]
 async fn should_fail_when_the_auth_key_cannot_be_deleted() {
-    INIT.call_once(|| {
+    /*INIT.call_once(|| {
         tracing_stderr_init(LevelFilter::ERROR);
-    });
+    });*/
 
-    let env = Started::new(&configuration::ephemeral().into()).await;
+    std::env::set_var("RUNNING_IN_TEST", "true");
+
+    let mut config = configuration::ephemeral();
+
+    config.logging.threshold = Threshold::Trace;
+
+    let env = Started::new(&config.into()).await;
+
+    error!("after starting test env");
 
     let seconds_valid = 60;
     let auth_key = env
@@ -271,6 +283,15 @@ async fn should_fail_when_the_auth_key_cannot_be_deleted() {
 
     assert_failed_to_delete_key(response).await;
 
+    logs_assert(|lines: &[&str]| {
+        for line in lines {
+            println!("{line}");
+        }
+        Ok(())
+    });
+
+    assert!(logs_contain("logged on the error level"));
+
     env.stop().await;
 }