Merge #699: Tracker API: log request and responses

5ccdf10 fix: build errors `imported redundantly` (Jose Celano)
32727ca feat: [#696] API, log request and responses (Jose Celano)
945e91f chore: [#696] add cargo dependencies for logging (Jose Celano)

Pull request description:

  Tracker API: log request and responses. Log example:

  ```
  2024-02-19T10:26:32.338162254+00:00 [API][INFO] request; method=GET uri=/api/v1/stats?token=MyAccessToken request_id=e3d2d819-fb36-4e56-89e5-64deae95f372
  2024-02-19T10:26:32.338218836+00:00 [API][INFO] response; latency=0 status=200 OK request_id=e3d2d819-fb36-4e56-89e5-64deae95f372
  ```

ACKs for top commit:
  josecelano:
    ACK 5ccdf10

Tree-SHA512: 3b182ae2c19ce46451fc370bd05c4e5a3311526562ca396424f046d4087e7fba51ec6101019fe2a8d7fe8f18752a4fce6662871108a7c252d17c5b248b38569b

Author: josecelano

Cargo.lock

@@ -67,14 +67,16 @@ torrust-tracker-configuration = { version = "3.0.0-alpha.12-develop", path = "pa
 torrust-tracker-contrib-bencode = { version = "3.0.0-alpha.12-develop", path = "contrib/bencode" }
 torrust-tracker-located-error = { version = "3.0.0-alpha.12-develop", path = "packages/located-error" }
 torrust-tracker-primitives = { version = "3.0.0-alpha.12-develop", path = "packages/primitives" }
-tower-http = { version = "0", features = ["compression-full"] }
+tower-http = { version = "0", features = ["compression-full", "cors", "trace", "propagate-header", "request-id"] }
 uuid = { version = "1", features = ["v4"] }
 colored = "2.1.0"
 url = "2.5.0"
 tempfile = "3.9.0"
 clap = { version = "4.4.18", features = ["derive", "env"]}
 anyhow = "1.0.79"
 hex-literal = "0.4.1"
+trace = "0.1.7"
+tracing = "0.1.40"
 
 [dev-dependencies]
 criterion = { version = "0.5.1", features = ["async_tokio"] }

Cargo.toml

@@ -117,6 +117,7 @@
         "Swatinem",
         "Swiftbit",
         "taiki",
+        "tdyne",
         "tempfile",
         "thiserror",
         "tlsv",

cSpell.json

@@ -1,5 +1,3 @@
-use std::iter::Extend;
-
 use crate::access::bencode::{BRefAccess, RefKind};
 use crate::access::dict::BDictAccess;
 use crate::access::list::BListAccess;

contrib/bencode/src/mutable/encode.rs

@@ -125,8 +125,6 @@ impl<'a> BRefAccessExt<'a> for BencodeRef<'a> {
 
 #[cfg(test)]
 mod tests {
-    use std::default::Default;
-
     use crate::access::bencode::BRefAccess;
     use crate::reference::bencode_ref::BencodeRef;
     use crate::reference::decode_opt::BDecodeOpt;

contrib/bencode/src/reference/bencode_ref.rs

@@ -177,8 +177,6 @@ fn peek_byte(bytes: &[u8], pos: usize) -> BencodeParseResult<u8> {
 
 #[cfg(test)]
 mod tests {
-    use std::default::Default;
-
     use crate::access::bencode::BRefAccess;
     use crate::reference::bencode_ref::BencodeRef;
     use crate::reference::decode_opt::BDecodeOpt;

contrib/bencode/src/reference/decode.rs

@@ -1,5 +1,3 @@
-use std::default::Default;
-
 const DEFAULT_MAX_RECURSION: usize = 50;
 const DEFAULT_CHECK_KEY_SORT: bool = false;
 const DEFAULT_ENFORCE_FULL_DECODE: bool = true;

contrib/bencode/src/reference/decode_opt.rs

@@ -4,7 +4,6 @@ use std::net::SocketAddr;
 
 use reqwest::Url as ServiceUrl;
 use serde::Deserialize;
-use url;
 
 /// It parses the configuration from a JSON format.
 ///
@@ -88,7 +87,7 @@ impl TryFrom<PlainConfiguration> for Configuration {
 
 #[cfg(test)]
 mod tests {
-    use std::net::{IpAddr, Ipv4Addr, SocketAddr};
+    use std::net::{IpAddr, Ipv4Addr};
 
     use super::*;
 

src/console/clients/checker/config.rs

@@ -24,7 +24,6 @@ use std::net::{IpAddr, SocketAddr};
 use std::panic::Location;
 
 use aquatic_udp_protocol::{AnnounceEvent, NumberOfBytes};
-use serde;
 use serde::Serialize;
 use thiserror::Error;
 

src/core/peer.rs

@@ -6,11 +6,20 @@
 //! All the API routes have the `/api` prefix and the version number as the
 //! first path segment. For example: `/api/v1/torrents`.
 use std::sync::Arc;
+use std::time::Duration;
 
+use axum::http::{HeaderName, HeaderValue};
+use axum::response::Response;
 use axum::routing::get;
 use axum::{middleware, Router};
+use hyper::Request;
 use torrust_tracker_configuration::AccessTokens;
 use tower_http::compression::CompressionLayer;
+use tower_http::propagate_header::PropagateHeaderLayer;
+use tower_http::request_id::{MakeRequestId, RequestId, SetRequestIdLayer};
+use tower_http::trace::{DefaultMakeSpan, TraceLayer};
+use tracing::{Level, Span};
+use uuid::Uuid;
 
 use super::v1;
 use super::v1::context::health_check::handlers::health_check_handler;
@@ -32,4 +41,47 @@ pub fn router(tracker: Arc<Tracker>, access_tokens: Arc<AccessTokens>) -> Router
         .layer(middleware::from_fn_with_state(state, v1::middlewares::auth::auth))
         .route(&format!("{api_url_prefix}/health_check"), get(health_check_handler))
         .layer(CompressionLayer::new())
+        .layer(SetRequestIdLayer::x_request_id(RequestIdGenerator))
+        .layer(PropagateHeaderLayer::new(HeaderName::from_static("x-request-id")))
+        .layer(
+            TraceLayer::new_for_http()
+                .make_span_with(DefaultMakeSpan::new().level(Level::INFO))
+                .on_request(|request: &Request<axum::body::Body>, _span: &Span| {
+                    let method = request.method().to_string();
+                    let uri = request.uri().to_string();
+                    let request_id = request
+                        .headers()
+                        .get("x-request-id")
+                        .map(|v| v.to_str().unwrap_or_default())
+                        .unwrap_or_default();
+
+                    tracing::span!(
+                        target: "API",
+                        tracing::Level::INFO, "request", method = %method, uri = %uri, request_id = %request_id);
+                })
+                .on_response(|response: &Response, latency: Duration, _span: &Span| {
+                    let status_code = response.status();
+                    let request_id = response
+                        .headers()
+                        .get("x-request-id")
+                        .map(|v| v.to_str().unwrap_or_default())
+                        .unwrap_or_default();
+                    let latency_ms = latency.as_millis();
+
+                    tracing::span!(
+                        target: "API",
+                        tracing::Level::INFO, "response", latency = %latency_ms, status = %status_code, request_id = %request_id);
+                }),
+        )
+        .layer(SetRequestIdLayer::x_request_id(RequestIdGenerator))
+}
+
+#[derive(Clone, Default)]
+struct RequestIdGenerator;
+
+impl MakeRequestId for RequestIdGenerator {
+    fn make_request_id<B>(&mut self, _request: &Request<B>) -> Option<RequestId> {
+        let id = HeaderValue::from_str(&Uuid::new_v4().to_string()).expect("UUID is a valid HTTP header value");
+        Some(RequestId::new(id))
+    }
 }

src/servers/apis/routes.rs

@@ -1,5 +1,4 @@
 //! API resources for the [`auth_key`](crate::servers::apis::v1::context::auth_key) API context.
-use std::convert::From;
 
 use serde::{Deserialize, Serialize};
 

src/servers/apis/v1/context/auth_key/resources.rs

@@ -13,7 +13,7 @@
 //! code.
 use axum::http::StatusCode;
 use axum::response::{IntoResponse, Response};
-use serde::{self, Serialize};
+use serde::Serialize;
 
 /// `Error` response for the [`HTTP tracker`](crate::servers::http).
 #[derive(Serialize, Debug, PartialEq)]

src/servers/http/v1/responses/error.rs

@@ -1,4 +1,3 @@
-use std::convert::TryFrom;
 use std::error::Error;
 use std::fmt::{self};
 use std::str::FromStr;

src/shared/bit_torrent/tracker/http/client/requests/scrape.rs

@@ -1,6 +1,6 @@
 use std::net::{IpAddr, Ipv4Addr, SocketAddr};
 
-use serde::{self, Deserialize, Serialize};
+use serde::{Deserialize, Serialize};
 
 use crate::core::peer::Peer;
 

src/shared/bit_torrent/tracker/http/client/responses/announce.rs

@@ -1,4 +1,4 @@
-use serde::{self, Deserialize, Serialize};
+use serde::{Deserialize, Serialize};
 
 #[derive(Serialize, Deserialize, Debug, PartialEq)]
 pub struct Error {

src/shared/bit_torrent/tracker/http/client/responses/error.rs

@@ -3,7 +3,7 @@ use std::fmt::Write;
 use std::str;
 
 use serde::ser::SerializeMap;
-use serde::{self, Deserialize, Serialize, Serializer};
+use serde::{Deserialize, Serialize, Serializer};
 use serde_bencode::value::Value;
 
 use crate::shared::bit_torrent::tracker::http::{ByteArray20, InfoHash};

src/shared/bit_torrent/tracker/http/client/responses/scrape.rs

@@ -86,8 +86,6 @@ pub mod seeds {
 
         #[cfg(test)]
         mod tests {
-            use std::convert::TryInto;
-
             use crate::shared::crypto::ephemeral_instance_keys::RANDOM_SEED;
             use crate::shared::crypto::keys::seeds::detail::ZEROED_TEST_SEED;
             use crate::shared::crypto::keys::seeds::CURRENT_SEED;

src/shared/crypto/keys.rs

@@ -1,6 +1,6 @@
 use std::net::{IpAddr, Ipv4Addr, SocketAddr};
 
-use serde::{self, Deserialize, Serialize};
+use serde::{Deserialize, Serialize};
 use torrust_tracker::core::peer::Peer;
 
 #[derive(Serialize, Deserialize, Debug, PartialEq)]

tests/servers/http/responses/announce.rs

@@ -1,4 +1,4 @@
-use serde::{self, Deserialize, Serialize};
+use serde::{Deserialize, Serialize};
 
 #[derive(Serialize, Deserialize, Debug, PartialEq)]
 pub struct Error {

tests/servers/http/responses/error.rs

@@ -1,7 +1,7 @@
 use std::collections::HashMap;
 use std::str;
 
-use serde::{self, Deserialize, Serialize};
+use serde::{Deserialize, Serialize};
 use serde_bencode::value::Value;
 
 use crate::servers::http::{ByteArray20, InfoHash};