diff --git a/Cargo.lock b/Cargo.lock index dacd04454..3ad8ba616 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2211,6 +2211,15 @@ dependencies = [ "hashbrown 0.15.2", ] +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "matchit" version = "0.7.3" @@ -3014,8 +3023,17 @@ checksum = "b544ef1b4eac5dc2db33ea63606ae9ffcfac26c1416a2806ae0bf5f56b201191" dependencies = [ "aho-corasick", "memchr", - "regex-automata", - "regex-syntax", + "regex-automata 0.4.9", + "regex-syntax 0.8.5", +] + +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", ] [[package]] @@ -3026,9 +3044,15 @@ checksum = "809e8dc61f6de73b46c85f4c96486310fe304c434cfa43669d7b40f711150908" dependencies = [ "aho-corasick", "memchr", - "regex-syntax", + "regex-syntax 0.8.5", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.8.5" @@ -4012,6 +4036,7 @@ dependencies = [ "tower-http", "tracing", "tracing-subscriber", + "tracing-test", "url", "uuid", "zerocopy", @@ -4251,17 +4276,42 @@ version = "0.3.19" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" dependencies = [ + "matchers", "nu-ansi-term", + "once_cell", + "regex", "serde", "serde_json", "sharded-slab", "smallvec", "thread_local", + "tracing", "tracing-core", "tracing-log", "tracing-serde", ] +[[package]] +name = "tracing-test" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "557b891436fe0d5e0e363427fc7f217abf9ccd510d5136549847bdcbcd011d68" +dependencies = [ + "tracing-core", + "tracing-subscriber", + "tracing-test-macro", +] + +[[package]] +name = "tracing-test-macro" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "04659ddb06c87d233c566112c1c9c5b9e98256d9af50ec3bc9c8327f873a7568" +dependencies = [ + "quote", + "syn 2.0.90", +] + [[package]] name = "try-lock" version = "0.2.5" diff --git a/Cargo.toml b/Cargo.toml index 6832f17f2..1dcff27e6 100644 --- a/Cargo.toml +++ b/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" diff --git a/src/bootstrap/logging.rs b/src/bootstrap/logging.rs index 34809c1ca..c42abd4fb 100644 --- a/src/bootstrap/logging.rs +++ b/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 { diff --git a/src/core/mod.rs b/src/core/mod.rs index b5759709b..add719958 100644 --- a/src/core/mod.rs +++ b/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) -> Result { + error!("This is being logged on the error level"); + let auth_key = auth::generate_key(lifetime); self.database.add_key_to_keys(&auth_key)?; diff --git a/src/servers/apis/server.rs b/src/servers/apis/server.rs index 31220f497..116d96993 100644 --- a/src/servers/apis/server.rs +++ b/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 { form: ServiceRegistrationForm, access_tokens: Arc, ) -> Result, Error> { + debug!("Starting new API test environment ApiServer::start"); + let (tx_start, rx_start) = tokio::sync::oneshot::channel::(); let (tx_halt, rx_halt) = tokio::sync::oneshot::channel::(); let launcher = self.state.launcher; let task = tokio::spawn(async move { + debug!("Starting new API test environment ApiServer::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; diff --git a/tests/common/logging.rs b/tests/common/logging.rs index 71be2ece7..2ad13a8f4 100644 --- a/tests/common/logging.rs +++ b/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"); } diff --git a/tests/servers/api/environment.rs b/tests/servers/api/environment.rs index bffe42603..483778dc2 100644 --- a/tests/servers/api/environment.rs +++ b/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 { pub fn new(configuration: &Arc) -> Self { + debug!("Creating new API test environment: Environment::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 { } pub async fn start(self) -> Environment { + debug!("Starting new API test environment: Environment::start"); + let access_tokens = Arc::new(self.config.access_tokens.clone()); Environment { @@ -71,6 +76,8 @@ impl Environment { impl Environment { pub async fn new(configuration: &Arc) -> Self { + debug!("Creating new API test environment: Environment::new"); + Environment::::new(configuration).start().await } diff --git a/tests/servers/api/v1/contract/context/auth_key.rs b/tests/servers/api/v1/contract/context/auth_key.rs index 2792a513c..dc9f66aa8 100644 --- a/tests/servers/api/v1/contract/context/auth_key.rs +++ b/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; }