From b239730b1c3b0aff76660660ba760dfc389bb15d Mon Sep 17 00:00:00 2001 From: Cameron Garnham Date: Wed, 20 Nov 2024 05:13:14 +0800 Subject: [PATCH] udp: improve logging --- cSpell.json | 1 + src/core/mod.rs | 2 + src/core/services/statistics/mod.rs | 2 + src/core/statistics.rs | 24 ++ .../apis/v1/context/stats/resources.rs | 22 +- src/servers/udp/connection_cookie.rs | 27 +- src/servers/udp/error.rs | 24 +- src/servers/udp/handlers.rs | 397 +++++++++--------- src/servers/udp/logging.rs | 87 ---- src/servers/udp/mod.rs | 1 - src/servers/udp/server/launcher.rs | 9 +- .../servers/api/v1/contract/context/stats.rs | 2 + 12 files changed, 283 insertions(+), 315 deletions(-) delete mode 100644 src/servers/udp/logging.rs diff --git a/cSpell.json b/cSpell.json index e2ecd1bc3..090a2b0e3 100644 --- a/cSpell.json +++ b/cSpell.json @@ -164,6 +164,7 @@ "typenum", "Unamed", "underflows", + "Unsendable", "untuple", "uroot", "Vagaa", diff --git a/src/core/mod.rs b/src/core/mod.rs index a41ef2eba..835776e30 100644 --- a/src/core/mod.rs +++ b/src/core/mod.rs @@ -470,6 +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 self::auth::Key; use self::error::Error; @@ -1092,6 +1093,7 @@ impl Tracker { /// /// Will return an error if the tracker is running in `listed` mode /// and the infohash is not whitelisted. + #[instrument(skip(self, info_hash), err)] pub async fn authorize(&self, info_hash: &InfoHash) -> Result<(), Error> { if !self.is_listed() { return Ok(()); diff --git a/src/core/services/statistics/mod.rs b/src/core/services/statistics/mod.rs index ee1c0c4fa..0e7735be2 100644 --- a/src/core/services/statistics/mod.rs +++ b/src/core/services/statistics/mod.rs @@ -76,9 +76,11 @@ pub async fn get_metrics(tracker: Arc) -> TrackerMetrics { udp4_connections_handled: stats.udp4_connections_handled, udp4_announces_handled: stats.udp4_announces_handled, udp4_scrapes_handled: stats.udp4_scrapes_handled, + udp4_errors_handled: stats.udp4_errors_handled, udp6_connections_handled: stats.udp6_connections_handled, udp6_announces_handled: stats.udp6_announces_handled, udp6_scrapes_handled: stats.udp6_scrapes_handled, + udp6_errors_handled: stats.udp6_errors_handled, }, } } diff --git a/src/core/statistics.rs b/src/core/statistics.rs index c9681d23c..b106b2691 100644 --- a/src/core/statistics.rs +++ b/src/core/statistics.rs @@ -47,9 +47,11 @@ pub enum Event { Udp4Connect, Udp4Announce, Udp4Scrape, + Udp4Error, Udp6Connect, Udp6Announce, Udp6Scrape, + Udp6Error, } /// Metrics collected by the tracker. @@ -82,12 +84,16 @@ pub struct Metrics { pub udp4_announces_handled: u64, /// Total number of UDP (UDP tracker) `scrape` requests from IPv4 peers. pub udp4_scrapes_handled: u64, + /// Total number of UDP (UDP tracker) `error` requests from IPv4 peers. + pub udp4_errors_handled: u64, /// Total number of UDP (UDP tracker) `connection` requests from IPv6 peers. pub udp6_connections_handled: u64, /// Total number of UDP (UDP tracker) `announce` requests from IPv6 peers. pub udp6_announces_handled: u64, /// Total number of UDP (UDP tracker) `scrape` requests from IPv6 peers. pub udp6_scrapes_handled: u64, + /// Total number of UDP (UDP tracker) `error` requests from IPv6 peers. + pub udp6_errors_handled: u64, } /// The service responsible for keeping tracker metrics (listening to statistics events and handle them). @@ -168,6 +174,9 @@ async fn event_handler(event: Event, stats_repository: &Repo) { Event::Udp4Scrape => { stats_repository.increase_udp4_scrapes().await; } + Event::Udp4Error => { + stats_repository.increase_udp4_errors().await; + } // UDP6 Event::Udp6Connect => { @@ -179,6 +188,9 @@ async fn event_handler(event: Event, stats_repository: &Repo) { Event::Udp6Scrape => { stats_repository.increase_udp6_scrapes().await; } + Event::Udp6Error => { + stats_repository.increase_udp6_errors().await; + } } tracing::debug!("stats: {:?}", stats_repository.get_stats().await); @@ -282,6 +294,12 @@ impl Repo { drop(stats_lock); } + pub async fn increase_udp4_errors(&self) { + let mut stats_lock = self.stats.write().await; + stats_lock.udp4_errors_handled += 1; + drop(stats_lock); + } + pub async fn increase_udp6_connections(&self) { let mut stats_lock = self.stats.write().await; stats_lock.udp6_connections_handled += 1; @@ -299,6 +317,12 @@ impl Repo { stats_lock.udp6_scrapes_handled += 1; drop(stats_lock); } + + pub async fn increase_udp6_errors(&self) { + let mut stats_lock = self.stats.write().await; + stats_lock.udp6_errors_handled += 1; + drop(stats_lock); + } } #[cfg(test)] diff --git a/src/servers/apis/v1/context/stats/resources.rs b/src/servers/apis/v1/context/stats/resources.rs index 9e8ab6bab..de6f6ca89 100644 --- a/src/servers/apis/v1/context/stats/resources.rs +++ b/src/servers/apis/v1/context/stats/resources.rs @@ -38,12 +38,16 @@ pub struct Stats { pub udp4_announces_handled: u64, /// Total number of UDP (UDP tracker) `scrape` requests from IPv4 peers. pub udp4_scrapes_handled: u64, + /// Total number of UDP (UDP tracker) `scrape` requests from IPv4 peers. + pub udp4_errors_handled: u64, /// Total number of UDP (UDP tracker) `connection` requests from IPv6 peers. pub udp6_connections_handled: u64, /// Total number of UDP (UDP tracker) `announce` requests from IPv6 peers. pub udp6_announces_handled: u64, /// Total number of UDP (UDP tracker) `scrape` requests from IPv6 peers. pub udp6_scrapes_handled: u64, + /// Total number of UDP (UDP tracker) `scrape` requests from IPv6 peers. + pub udp6_errors_handled: u64, } impl From for Stats { @@ -62,9 +66,11 @@ impl From for Stats { udp4_connections_handled: metrics.protocol_metrics.udp4_connections_handled, udp4_announces_handled: metrics.protocol_metrics.udp4_announces_handled, udp4_scrapes_handled: metrics.protocol_metrics.udp4_scrapes_handled, + udp4_errors_handled: metrics.protocol_metrics.udp4_errors_handled, udp6_connections_handled: metrics.protocol_metrics.udp6_connections_handled, udp6_announces_handled: metrics.protocol_metrics.udp6_announces_handled, udp6_scrapes_handled: metrics.protocol_metrics.udp6_scrapes_handled, + udp6_errors_handled: metrics.protocol_metrics.udp6_errors_handled, } } } @@ -97,9 +103,11 @@ mod tests { udp4_connections_handled: 11, udp4_announces_handled: 12, udp4_scrapes_handled: 13, - udp6_connections_handled: 14, - udp6_announces_handled: 15, - udp6_scrapes_handled: 16 + udp4_errors_handled: 14, + udp6_connections_handled: 15, + udp6_announces_handled: 16, + udp6_scrapes_handled: 17, + udp6_errors_handled: 18 } }), Stats { @@ -116,9 +124,11 @@ mod tests { udp4_connections_handled: 11, udp4_announces_handled: 12, udp4_scrapes_handled: 13, - udp6_connections_handled: 14, - udp6_announces_handled: 15, - udp6_scrapes_handled: 16 + udp4_errors_handled: 14, + udp6_connections_handled: 15, + udp6_announces_handled: 16, + udp6_scrapes_handled: 17, + udp6_errors_handled: 18 } ); } diff --git a/src/servers/udp/connection_cookie.rs b/src/servers/udp/connection_cookie.rs index 9ed1bcdc8..50359033c 100644 --- a/src/servers/udp/connection_cookie.rs +++ b/src/servers/udp/connection_cookie.rs @@ -79,6 +79,7 @@ use aquatic_udp_protocol::ConnectionId as Cookie; use cookie_builder::{assemble, decode, disassemble, encode}; +use tracing::instrument; use zerocopy::AsBytes; use super::error::Error; @@ -94,9 +95,12 @@ use crate::shared::crypto::keys::CipherArrayBlowfish; /// /// It would panic if the cookie is not exactly 8 bytes is size. /// +#[instrument(err)] pub fn make(fingerprint: u64, issue_at: f64) -> Result { if !issue_at.is_normal() { - return Err(Error::InvalidCookieIssueTime { invalid_value: issue_at }); + return Err(Error::CookieValueNotNormal { + not_normal_value: issue_at, + }); } let cookie = assemble(fingerprint, issue_at); @@ -117,6 +121,7 @@ use std::ops::Range; /// # Panics /// /// It would panic if the range start is not smaller than it's end. +#[instrument(err)] pub fn check(cookie: &Cookie, fingerprint: u64, valid_range: Range) -> Result { assert!(valid_range.start <= valid_range.end, "range start is larger than range end"); @@ -126,20 +131,20 @@ pub fn check(cookie: &Cookie, fingerprint: u64, valid_range: Range) -> Resu let issue_time = disassemble(fingerprint, cookie_bytes); if !issue_time.is_normal() { - return Err(Error::ConnectionIdNotNormal { + return Err(Error::CookieValueNotNormal { not_normal_value: issue_time, }); } if issue_time < valid_range.start { - return Err(Error::ConnectionIdExpired { + return Err(Error::CookieValueExpired { expired_value: issue_time, min_value: valid_range.start, }); } if issue_time > valid_range.end { - return Err(Error::ConnectionIdFromFuture { + return Err(Error::CookieValueFromFuture { future_value: issue_time, max_value: valid_range.end, }); @@ -150,7 +155,7 @@ pub fn check(cookie: &Cookie, fingerprint: u64, valid_range: Range) -> Resu mod cookie_builder { use cipher::{BlockDecrypt, BlockEncrypt}; - use tracing::{instrument, Level}; + use tracing::instrument; use zerocopy::{byteorder, AsBytes as _, NativeEndian}; pub type CookiePlainText = CipherArrayBlowfish; @@ -158,7 +163,7 @@ mod cookie_builder { use crate::shared::crypto::keys::{CipherArrayBlowfish, Current, Keeper}; - #[instrument(ret(level = Level::TRACE))] + #[instrument()] pub(super) fn assemble(fingerprint: u64, issue_at: f64) -> CookiePlainText { let issue_at: byteorder::I64 = *zerocopy::FromBytes::ref_from(&issue_at.to_ne_bytes()).expect("it should be aligned"); @@ -172,7 +177,7 @@ mod cookie_builder { *CipherArrayBlowfish::from_slice(cookie.as_bytes()) } - #[instrument(ret(level = Level::TRACE))] + #[instrument()] pub(super) fn disassemble(fingerprint: u64, cookie: CookiePlainText) -> f64 { let fingerprint: byteorder::I64 = *zerocopy::FromBytes::ref_from(&fingerprint.to_ne_bytes()).expect("it should be aligned"); @@ -189,7 +194,7 @@ mod cookie_builder { issue_time.get() } - #[instrument(ret(level = Level::TRACE))] + #[instrument()] pub(super) fn encode(mut cookie: CookiePlainText) -> CookieCipherText { let cipher = Current::get_cipher_blowfish(); @@ -198,7 +203,7 @@ mod cookie_builder { cookie } - #[instrument(ret(level = Level::TRACE))] + #[instrument()] pub(super) fn decode(mut cookie: CookieCipherText) -> CookiePlainText { let cipher = Current::get_cipher_blowfish(); @@ -282,7 +287,7 @@ mod tests { let result = check(&cookie, fingerprint, min..max).unwrap_err(); match result { - Error::ConnectionIdExpired { .. } => {} // Expected error + Error::CookieValueExpired { .. } => {} // Expected error _ => panic!("Expected ConnectionIdExpired error"), } } @@ -300,7 +305,7 @@ mod tests { let result = check(&cookie, fingerprint, min..max).unwrap_err(); match result { - Error::ConnectionIdFromFuture { .. } => {} // Expected error + Error::CookieValueFromFuture { .. } => {} // Expected error _ => panic!("Expected ConnectionIdFromFuture error"), } } diff --git a/src/servers/udp/error.rs b/src/servers/udp/error.rs index 5996cae73..cda562aed 100644 --- a/src/servers/udp/error.rs +++ b/src/servers/udp/error.rs @@ -1,7 +1,7 @@ //! Error types for the UDP server. use std::panic::Location; -use aquatic_udp_protocol::ConnectionId; +use aquatic_udp_protocol::{ConnectionId, RequestParseError}; use derive_more::derive::Display; use thiserror::Error; use torrust_tracker_located_error::LocatedError; @@ -13,17 +13,17 @@ pub struct ConnectionCookie(pub ConnectionId); /// Error returned by the UDP server. #[derive(Error, Debug)] pub enum Error { - #[error("the issue time should be a normal floating point number")] - InvalidCookieIssueTime { invalid_value: f64 }, + #[error("cookie value is not normal: {not_normal_value}")] + CookieValueNotNormal { not_normal_value: f64 }, - #[error("connection id did not produce a normal value")] - ConnectionIdNotNormal { not_normal_value: f64 }, + #[error("cookie value is expired: {expired_value}, expected > {min_value}")] + CookieValueExpired { expired_value: f64, min_value: f64 }, - #[error("connection id produced an expired value")] - ConnectionIdExpired { expired_value: f64, min_value: f64 }, + #[error("cookie value is from future: {future_value}, expected < {max_value}")] + CookieValueFromFuture { future_value: f64, max_value: f64 }, - #[error("connection id produces a future value")] - ConnectionIdFromFuture { future_value: f64, max_value: f64 }, + #[error("error when phrasing request: {request_parse_error:?}")] + RequestParseError { request_parse_error: RequestParseError }, /// Error returned when the domain tracker returns an error. #[error("tracker server error: {source}")] @@ -48,3 +48,9 @@ pub enum Error { #[error("domain tracker requires authentication but is not supported in current UDP implementation. Location: {location}")] TrackerAuthenticationRequired { location: &'static Location<'static> }, } + +impl From for Error { + fn from(request_parse_error: RequestParseError) -> Self { + Self::RequestParseError { request_parse_error } + } +} diff --git a/src/servers/udp/handlers.rs b/src/servers/udp/handlers.rs index 814ee5e9e..af22b263d 100644 --- a/src/servers/udp/handlers.rs +++ b/src/servers/udp/handlers.rs @@ -1,34 +1,30 @@ //! Handlers for the UDP server. -use std::fmt; use std::hash::{DefaultHasher, Hash, Hasher as _}; use std::net::{IpAddr, SocketAddr}; use std::ops::Range; -use std::panic::Location; use std::sync::Arc; use std::time::Instant; use aquatic_udp_protocol::{ AnnounceInterval, AnnounceRequest, AnnounceResponse, AnnounceResponseFixedData, ConnectRequest, ConnectResponse, - ErrorResponse, Ipv4AddrBytes, Ipv6AddrBytes, NumberOfDownloads, NumberOfPeers, Port, Request, Response, ResponsePeer, - ScrapeRequest, ScrapeResponse, TorrentScrapeStatistics, TransactionId, + ErrorResponse, Ipv4AddrBytes, Ipv6AddrBytes, NumberOfDownloads, NumberOfPeers, Port, Request, RequestParseError, Response, + ResponsePeer, ScrapeRequest, ScrapeResponse, TorrentScrapeStatistics, TransactionId, }; use bittorrent_primitives::info_hash::InfoHash; use torrust_tracker_clock::clock::Time as _; -use torrust_tracker_located_error::DynError; use tracing::{instrument, Level}; use uuid::Uuid; use zerocopy::network_endian::I32; use super::connection_cookie::{check, make}; use super::RawRequest; -use crate::core::{statistics, PeersWanted, ScrapeData, Tracker}; +use crate::core::{statistics, PeersWanted, Tracker}; use crate::servers::udp::error::Error; -use crate::servers::udp::logging::{log_bad_request, log_error_response, log_request, log_response}; use crate::servers::udp::peer_builder; use crate::shared::bit_torrent::common::MAX_SCRAPE_TORRENTS; use crate::CurrentClock; -#[derive(Debug)] +#[derive(Debug, Clone, PartialEq)] pub(super) struct CookieTimeValues { pub(super) issue_time: f64, pub(super) valid_range: Range, @@ -55,60 +51,40 @@ impl CookieTimeValues { /// - Delegating the request to the correct handler depending on the request type. /// /// It will return an `Error` response if the request is invalid. -#[instrument(skip(udp_request, tracker, local_addr), ret(level = Level::TRACE))] +#[instrument(fields(request_id), skip(udp_request, tracker, cookie_time_values), ret(level = Level::TRACE))] pub(crate) async fn handle_packet( udp_request: RawRequest, tracker: &Tracker, local_addr: SocketAddr, cookie_time_values: CookieTimeValues, ) -> Response { + tracing::Span::current().record("request_id", Uuid::new_v4().to_string()); tracing::debug!("Handling Packets: {udp_request:?}"); let start_time = Instant::now(); - let request_id = RequestId::make(&udp_request); - - match Request::parse_bytes(&udp_request.payload[..udp_request.payload.len()], MAX_SCRAPE_TORRENTS).map_err(|e| { - Error::InternalServer { - message: format!("{e:?}"), - location: Location::caller(), - } - }) { - Ok(request) => { - log_request(&request, &request_id, &local_addr); - - let transaction_id = match &request { - Request::Connect(connect_request) => connect_request.transaction_id, - Request::Announce(announce_request) => announce_request.transaction_id, - Request::Scrape(scrape_request) => scrape_request.transaction_id, - }; - - let response = match handle_request(request, udp_request.from, tracker, cookie_time_values).await { - Ok(response) => response, - Err(e) => handle_error(&e, transaction_id), - }; - - let latency = start_time.elapsed(); - - log_response(&response, &transaction_id, &request_id, &local_addr, latency); - - response - } - Err(e) => { - log_bad_request(&request_id); - - let response = handle_error( - &Error::BadRequest { - source: (Arc::new(e) as DynError).into(), - }, - TransactionId(I32::new(0)), - ); + let response = + match Request::parse_bytes(&udp_request.payload[..udp_request.payload.len()], MAX_SCRAPE_TORRENTS).map_err(Error::from) { + Ok(request) => match handle_request(request, udp_request.from, tracker, cookie_time_values.clone()).await { + Ok(response) => return response, + Err((e, transaction_id)) => { + handle_error( + udp_request.from, + tracker, + cookie_time_values.valid_range.clone(), + &e, + Some(transaction_id), + ) + .await + } + }, + Err(e) => handle_error(udp_request.from, tracker, cookie_time_values.valid_range.clone(), &e, None).await, + }; - log_error_response(&request_id); + let latency = start_time.elapsed(); + tracing::trace!(?latency, "responded"); - response - } - } + response } /// It dispatches the request to the correct handler. @@ -116,23 +92,25 @@ pub(crate) async fn handle_packet( /// # Errors /// /// If a error happens in the `handle_request` function, it will just return the `ServerError`. -#[instrument(skip(request, remote_addr, tracker))] +#[instrument(skip(request, remote_addr, tracker, cookie_time_values))] pub async fn handle_request( request: Request, remote_addr: SocketAddr, tracker: &Tracker, cookie_time_values: CookieTimeValues, -) -> Result { +) -> Result { tracing::trace!("handle request"); match request { Request::Connect(connect_request) => { - handle_connect(remote_addr, &connect_request, tracker, cookie_time_values.issue_time).await + Ok(handle_connect(remote_addr, &connect_request, tracker, cookie_time_values.issue_time).await) } Request::Announce(announce_request) => { handle_announce(remote_addr, &announce_request, tracker, cookie_time_values.valid_range).await } - Request::Scrape(scrape_request) => handle_scrape(remote_addr, &scrape_request, tracker).await, + Request::Scrape(scrape_request) => { + handle_scrape(remote_addr, &scrape_request, tracker, cookie_time_values.valid_range).await + } } } @@ -142,16 +120,18 @@ pub async fn handle_request( /// # Errors /// /// This function does not ever return an error. -#[instrument(skip(tracker), err, ret(level = Level::TRACE))] +#[instrument(fields(transaction_id), skip(tracker), ret(level = Level::TRACE))] pub async fn handle_connect( remote_addr: SocketAddr, request: &ConnectRequest, tracker: &Tracker, cookie_issue_time: f64, -) -> Result { +) -> Response { + tracing::Span::current().record("transaction_id", request.transaction_id.0.to_string()); + tracing::trace!("handle connect"); - let connection_id = make(make_remote_fingerprint(&remote_addr), cookie_issue_time)?; + let connection_id = make(gen_remote_fingerprint(&remote_addr), cookie_issue_time).expect("it should be a normal value"); let response = ConnectResponse { transaction_id: request.transaction_id, @@ -168,7 +148,7 @@ pub async fn handle_connect( } } - Ok(Response::from(response)) + Response::from(response) } /// It handles the `Announce` request. Refer to [`Announce`](crate::servers::udp#announce) @@ -177,38 +157,41 @@ pub async fn handle_connect( /// # Errors /// /// If a error happens in the `handle_announce` function, it will just return the `ServerError`. -#[instrument(skip(tracker), err, ret(level = Level::TRACE))] +#[instrument(fields(transaction_id, connection_id, info_hash), skip(tracker), ret(level = Level::TRACE))] pub async fn handle_announce( remote_addr: SocketAddr, - announce_request: &AnnounceRequest, + request: &AnnounceRequest, tracker: &Tracker, cookie_valid_range: Range, -) -> Result { - tracing::trace!("handle announce"); +) -> Result { + tracing::Span::current() + .record("transaction_id", request.transaction_id.0.to_string()) + .record("connection_id", request.connection_id.0.to_string()) + .record("info_hash", InfoHash::from_bytes(&request.info_hash.0).to_hex_string()); - // Authentication - if tracker.requires_authentication() { - return Err(Error::TrackerAuthenticationRequired { - location: Location::caller(), - }); - } + tracing::trace!("handle announce"); check( - &announce_request.connection_id, - make_remote_fingerprint(&remote_addr), + &request.connection_id, + gen_remote_fingerprint(&remote_addr), cookie_valid_range, - )?; + ) + .map_err(|e| (e, request.transaction_id))?; - let info_hash = announce_request.info_hash.into(); + let info_hash = request.info_hash.into(); let remote_client_ip = remote_addr.ip(); // Authorization - tracker.authorize(&info_hash).await.map_err(|e| Error::TrackerError { - source: (Arc::new(e) as Arc).into(), - })?; + tracker + .authorize(&info_hash) + .await + .map_err(|e| Error::TrackerError { + source: (Arc::new(e) as Arc).into(), + }) + .map_err(|e| (e, request.transaction_id))?; - let mut peer = peer_builder::from_request(announce_request, &remote_client_ip); - let peers_wanted: PeersWanted = i32::from(announce_request.peers_wanted.0).into(); + let mut peer = peer_builder::from_request(request, &remote_client_ip); + let peers_wanted: PeersWanted = i32::from(request.peers_wanted.0).into(); let response = tracker.announce(&info_hash, &mut peer, &remote_client_ip, &peers_wanted); @@ -225,7 +208,7 @@ pub async fn handle_announce( if remote_addr.is_ipv4() { let announce_response = AnnounceResponse { fixed: AnnounceResponseFixedData { - transaction_id: announce_request.transaction_id, + transaction_id: request.transaction_id, announce_interval: AnnounceInterval(I32::new(i64::from(tracker.get_announce_policy().interval) as i32)), leechers: NumberOfPeers(I32::new(i64::from(response.stats.incomplete) as i32)), seeders: NumberOfPeers(I32::new(i64::from(response.stats.complete) as i32)), @@ -250,7 +233,7 @@ pub async fn handle_announce( } else { let announce_response = AnnounceResponse { fixed: AnnounceResponseFixedData { - transaction_id: announce_request.transaction_id, + transaction_id: request.transaction_id, announce_interval: AnnounceInterval(I32::new(i64::from(tracker.get_announce_policy().interval) as i32)), leechers: NumberOfPeers(I32::new(i64::from(response.stats.incomplete) as i32)), seeders: NumberOfPeers(I32::new(i64::from(response.stats.complete) as i32)), @@ -281,21 +264,33 @@ pub async fn handle_announce( /// # Errors /// /// This function does not ever return an error. -#[instrument(skip(tracker), err, ret(level = Level::TRACE))] -pub async fn handle_scrape(remote_addr: SocketAddr, request: &ScrapeRequest, tracker: &Tracker) -> Result { +#[instrument(fields(transaction_id, connection_id), skip(tracker), ret(level = Level::TRACE))] +pub async fn handle_scrape( + remote_addr: SocketAddr, + request: &ScrapeRequest, + tracker: &Tracker, + cookie_valid_range: Range, +) -> Result { + tracing::Span::current() + .record("transaction_id", request.transaction_id.0.to_string()) + .record("connection_id", request.connection_id.0.to_string()); + tracing::trace!("handle scrape"); + check( + &request.connection_id, + gen_remote_fingerprint(&remote_addr), + cookie_valid_range, + ) + .map_err(|e| (e, request.transaction_id))?; + // Convert from aquatic infohashes let mut info_hashes: Vec = vec![]; for info_hash in &request.info_hashes { info_hashes.push((*info_hash).into()); } - let scrape_data = if tracker.requires_authentication() { - ScrapeData::zeroed(&info_hashes) - } else { - tracker.scrape(&info_hashes).await - }; + let scrape_data = tracker.scrape(&info_hashes).await; let mut torrent_stats: Vec = Vec::new(); @@ -332,36 +327,59 @@ pub async fn handle_scrape(remote_addr: SocketAddr, request: &ScrapeRequest, tra Ok(Response::from(response)) } -fn handle_error(e: &Error, transaction_id: TransactionId) -> Response { - let message = e.to_string(); +#[instrument(fields(transaction_id), skip(tracker), ret(level = Level::TRACE))] +async fn handle_error( + remote_addr: SocketAddr, + tracker: &Tracker, + cookie_valid_range: Range, + e: &Error, + transaction_id: Option, +) -> Response { + tracing::trace!("handle error"); + + let e = if let Error::RequestParseError { request_parse_error } = e { + match request_parse_error { + RequestParseError::Sendable { + connection_id, + transaction_id, + err, + } => { + if let Err(e) = check(connection_id, gen_remote_fingerprint(&remote_addr), cookie_valid_range) { + (e.to_string(), Some(*transaction_id)) + } else { + ((*err).to_string(), Some(*transaction_id)) + } + } + RequestParseError::Unsendable { err } => (err.to_string(), transaction_id), + } + } else { + (e.to_string(), transaction_id) + }; + + if e.1.is_some() { + // send stats event + match remote_addr { + SocketAddr::V4(_) => { + tracker.send_stats_event(statistics::Event::Udp4Error).await; + } + SocketAddr::V6(_) => { + tracker.send_stats_event(statistics::Event::Udp6Error).await; + } + } + } + Response::from(ErrorResponse { - transaction_id, - message: message.into(), + transaction_id: e.1.unwrap_or(TransactionId(I32::new(0))), + message: e.0.into(), }) } -fn make_remote_fingerprint(remote_addr: &SocketAddr) -> u64 { +fn gen_remote_fingerprint(remote_addr: &SocketAddr) -> u64 { let mut state = DefaultHasher::new(); remote_addr.hash(&mut state); state.finish() } -/// An identifier for a request. -#[derive(Debug, Clone)] -pub struct RequestId(Uuid); - -impl RequestId { - fn make(_request: &RawRequest) -> RequestId { - RequestId(Uuid::new_v4()) - } -} - -impl fmt::Display for RequestId { - fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - write!(f, "{}", self.0) - } -} - #[cfg(test)] mod tests { @@ -375,7 +393,7 @@ mod tests { use torrust_tracker_primitives::peer; use torrust_tracker_test_helpers::configuration; - use super::make_remote_fingerprint; + use super::gen_remote_fingerprint; use crate::core::services::tracker_factory; use crate::core::Tracker; use crate::CurrentClock; @@ -392,10 +410,6 @@ mod tests { initialized_tracker(&configuration::ephemeral_public()) } - fn private_tracker() -> Arc { - initialized_tracker(&configuration::ephemeral_private()) - } - fn whitelisted_tracker() -> Arc { initialized_tracker(&configuration::ephemeral_listed()) } @@ -409,7 +423,7 @@ mod tests { } fn sample_ipv4_remote_addr_fingerprint() -> u64 { - make_remote_fingerprint(&sample_ipv4_socket_address()) + gen_remote_fingerprint(&sample_ipv4_socket_address()) } fn sample_ipv6_remote_addr() -> SocketAddr { @@ -417,7 +431,7 @@ mod tests { } fn sample_ipv6_remote_addr_fingerprint() -> u64 { - make_remote_fingerprint(&sample_ipv6_socket_address()) + gen_remote_fingerprint(&sample_ipv6_socket_address()) } fn sample_ipv4_socket_address() -> SocketAddr { @@ -527,9 +541,7 @@ mod tests { transaction_id: TransactionId(0i32.into()), }; - let response = handle_connect(sample_ipv4_remote_addr(), &request, &public_tracker(), sample_issue_time()) - .await - .unwrap(); + let response = handle_connect(sample_ipv4_remote_addr(), &request, &public_tracker(), sample_issue_time()).await; assert_eq!( response, @@ -546,9 +558,7 @@ mod tests { transaction_id: TransactionId(0i32.into()), }; - let response = handle_connect(sample_ipv4_remote_addr(), &request, &public_tracker(), sample_issue_time()) - .await - .unwrap(); + let response = handle_connect(sample_ipv4_remote_addr(), &request, &public_tracker(), sample_issue_time()).await; assert_eq!( response, @@ -565,9 +575,7 @@ mod tests { transaction_id: TransactionId(0i32.into()), }; - let response = handle_connect(sample_ipv6_remote_addr(), &request, &public_tracker(), sample_issue_time()) - .await - .unwrap(); + let response = handle_connect(sample_ipv6_remote_addr(), &request, &public_tracker(), sample_issue_time()).await; assert_eq!( response, @@ -604,8 +612,7 @@ mod tests { &torrent_tracker, sample_issue_time(), ) - .await - .unwrap(); + .await; } #[tokio::test] @@ -632,8 +639,7 @@ mod tests { &torrent_tracker, sample_issue_time(), ) - .await - .unwrap(); + .await; } } @@ -726,8 +732,8 @@ mod tests { use crate::servers::udp::connection_cookie::make; use crate::servers::udp::handlers::tests::announce_request::AnnounceRequestBuilder; use crate::servers::udp::handlers::tests::{ - make_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_ipv4_socket_address, - sample_issue_time, tracker_configuration, TorrentPeerBuilder, + gen_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_ipv4_socket_address, sample_issue_time, + tracker_configuration, TorrentPeerBuilder, }; use crate::servers::udp::handlers::{handle_announce, AnnounceResponseFixedData}; @@ -743,7 +749,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V4(client_ip), client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(client_ip) @@ -769,7 +775,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V4(Ipv4Addr::new(126, 0, 0, 1)), 8080); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .into(); let response = handle_announce(remote_addr, &request, &public_tracker(), sample_cookie_valid_range()) @@ -810,7 +816,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V4(remote_client_ip), remote_client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(peer_address) @@ -845,7 +851,7 @@ mod tests { async fn announce_a_new_peer_using_ipv4(tracker: Arc) -> Response { let remote_addr = SocketAddr::new(IpAddr::V4(Ipv4Addr::new(126, 0, 0, 1)), 8080); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .into(); handle_announce(remote_addr, &request, &tracker, sample_cookie_valid_range()) @@ -909,7 +915,7 @@ mod tests { use crate::servers::udp::handlers::handle_announce; use crate::servers::udp::handlers::tests::announce_request::AnnounceRequestBuilder; use crate::servers::udp::handlers::tests::{ - make_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_issue_time, TorrentPeerBuilder, + gen_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_issue_time, TorrentPeerBuilder, }; #[tokio::test] @@ -924,7 +930,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V4(client_ip), client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(client_ip) @@ -965,7 +971,7 @@ mod tests { use crate::servers::udp::connection_cookie::make; use crate::servers::udp::handlers::tests::announce_request::AnnounceRequestBuilder; use crate::servers::udp::handlers::tests::{ - make_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_ipv6_remote_addr, sample_issue_time, + gen_remote_fingerprint, public_tracker, sample_cookie_valid_range, sample_ipv6_remote_addr, sample_issue_time, tracker_configuration, TorrentPeerBuilder, }; use crate::servers::udp::handlers::{handle_announce, AnnounceResponseFixedData}; @@ -983,7 +989,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V6(client_ip_v6), client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(client_ip_v4) @@ -1012,7 +1018,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V6(client_ip_v6), 8080); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .into(); let response = handle_announce(remote_addr, &request, &public_tracker(), sample_cookie_valid_range()) @@ -1053,7 +1059,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V6(remote_client_ip), remote_client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(peer_address) @@ -1091,7 +1097,7 @@ mod tests { let client_port = 8080; let remote_addr = SocketAddr::new(IpAddr::V6(client_ip_v6), client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .into(); handle_announce(remote_addr, &request, &tracker, sample_cookie_valid_range()) @@ -1138,7 +1144,7 @@ mod tests { let remote_addr = sample_ipv6_remote_addr(); let announce_request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .into(); handle_announce(remote_addr, &announce_request, &tracker, sample_cookie_valid_range()) @@ -1158,7 +1164,7 @@ mod tests { use crate::servers::udp::handlers::handle_announce; use crate::servers::udp::handlers::tests::announce_request::AnnounceRequestBuilder; use crate::servers::udp::handlers::tests::{ - make_remote_fingerprint, sample_cookie_valid_range, sample_issue_time, TrackerConfigurationBuilder, + gen_remote_fingerprint, sample_cookie_valid_range, sample_issue_time, TrackerConfigurationBuilder, }; #[tokio::test] @@ -1181,7 +1187,7 @@ mod tests { let remote_addr = SocketAddr::new(IpAddr::V6(client_ip_v6), client_port); let request = AnnounceRequestBuilder::default() - .with_connection_id(make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) + .with_connection_id(make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap()) .with_info_hash(info_hash) .with_peer_id(peer_id) .with_ip_address(client_ip_v4) @@ -1218,11 +1224,13 @@ mod tests { TransactionId, }; - use super::{make_remote_fingerprint, TorrentPeerBuilder}; + use super::{gen_remote_fingerprint, TorrentPeerBuilder}; use crate::core::{self}; use crate::servers::udp::connection_cookie::make; use crate::servers::udp::handlers::handle_scrape; - use crate::servers::udp::handlers::tests::{public_tracker, sample_ipv4_remote_addr, sample_issue_time}; + use crate::servers::udp::handlers::tests::{ + public_tracker, sample_cookie_valid_range, sample_ipv4_remote_addr, sample_issue_time, + }; fn zeroed_torrent_statistics() -> TorrentScrapeStatistics { TorrentScrapeStatistics { @@ -1240,12 +1248,14 @@ mod tests { let info_hashes = vec![info_hash]; let request = ScrapeRequest { - connection_id: make(make_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap(), + connection_id: make(gen_remote_fingerprint(&remote_addr), sample_issue_time()).unwrap(), transaction_id: TransactionId(0i32.into()), info_hashes, }; - let response = handle_scrape(remote_addr, &request, &public_tracker()).await.unwrap(); + let response = handle_scrape(remote_addr, &request, &public_tracker(), sample_cookie_valid_range()) + .await + .unwrap(); let expected_torrent_stats = vec![zeroed_torrent_statistics()]; @@ -1274,7 +1284,7 @@ mod tests { let info_hashes = vec![*info_hash]; ScrapeRequest { - connection_id: make(make_remote_fingerprint(remote_addr), sample_issue_time()).unwrap(), + connection_id: make(gen_remote_fingerprint(remote_addr), sample_issue_time()).unwrap(), transaction_id: TransactionId::new(0i32), info_hashes, } @@ -1288,7 +1298,9 @@ mod tests { let request = build_scrape_request(&remote_addr, &info_hash); - handle_scrape(remote_addr, &request, &tracker).await.unwrap() + handle_scrape(remote_addr, &request, &tracker, sample_cookie_valid_range()) + .await + .unwrap() } fn match_scrape_response(response: Response) -> Option { @@ -1320,45 +1332,6 @@ mod tests { } } - mod with_a_private_tracker { - - use aquatic_udp_protocol::InfoHash; - - use crate::servers::udp::handlers::handle_scrape; - use crate::servers::udp::handlers::tests::scrape_request::{ - add_a_sample_seeder_and_scrape, build_scrape_request, match_scrape_response, zeroed_torrent_statistics, - }; - use crate::servers::udp::handlers::tests::{private_tracker, sample_ipv4_remote_addr}; - - #[tokio::test] - async fn should_return_zeroed_statistics_when_the_tracker_does_not_have_the_requested_torrent() { - let tracker = private_tracker(); - - let remote_addr = sample_ipv4_remote_addr(); - let non_existing_info_hash = InfoHash([0u8; 20]); - - let request = build_scrape_request(&remote_addr, &non_existing_info_hash); - - let torrent_stats = match_scrape_response(handle_scrape(remote_addr, &request, &tracker).await.unwrap()).unwrap(); - - let expected_torrent_stats = vec![zeroed_torrent_statistics()]; - - assert_eq!(torrent_stats.torrent_stats, expected_torrent_stats); - } - - #[tokio::test] - async fn should_return_zeroed_statistics_when_the_tracker_has_the_requested_torrent_because_authenticated_requests_are_not_supported_in_udp_tracker( - ) { - let tracker = private_tracker(); - - let torrent_stats = match_scrape_response(add_a_sample_seeder_and_scrape(tracker.clone()).await).unwrap(); - - let expected_torrent_stats = vec![zeroed_torrent_statistics()]; - - assert_eq!(torrent_stats.torrent_stats, expected_torrent_stats); - } - } - mod with_a_whitelisted_tracker { use aquatic_udp_protocol::{InfoHash, NumberOfDownloads, NumberOfPeers, TorrentScrapeStatistics}; @@ -1366,7 +1339,7 @@ mod tests { use crate::servers::udp::handlers::tests::scrape_request::{ add_a_seeder, build_scrape_request, match_scrape_response, zeroed_torrent_statistics, }; - use crate::servers::udp::handlers::tests::{sample_ipv4_remote_addr, whitelisted_tracker}; + use crate::servers::udp::handlers::tests::{sample_cookie_valid_range, sample_ipv4_remote_addr, whitelisted_tracker}; #[tokio::test] async fn should_return_the_torrent_statistics_when_the_requested_torrent_is_whitelisted() { @@ -1381,7 +1354,12 @@ mod tests { let request = build_scrape_request(&remote_addr, &info_hash); - let torrent_stats = match_scrape_response(handle_scrape(remote_addr, &request, &tracker).await.unwrap()).unwrap(); + let torrent_stats = match_scrape_response( + handle_scrape(remote_addr, &request, &tracker, sample_cookie_valid_range()) + .await + .unwrap(), + ) + .unwrap(); let expected_torrent_stats = vec![TorrentScrapeStatistics { seeders: NumberOfPeers(1.into()), @@ -1403,7 +1381,12 @@ mod tests { let request = build_scrape_request(&remote_addr, &info_hash); - let torrent_stats = match_scrape_response(handle_scrape(remote_addr, &request, &tracker).await.unwrap()).unwrap(); + let torrent_stats = match_scrape_response( + handle_scrape(remote_addr, &request, &tracker, sample_cookie_valid_range()) + .await + .unwrap(), + ) + .unwrap(); let expected_torrent_stats = vec![zeroed_torrent_statistics()]; @@ -1416,7 +1399,7 @@ mod tests { let info_hashes = vec![info_hash]; ScrapeRequest { - connection_id: make(make_remote_fingerprint(remote_addr), sample_issue_time()).unwrap(), + connection_id: make(gen_remote_fingerprint(remote_addr), sample_issue_time()).unwrap(), transaction_id: TransactionId(0i32.into()), info_hashes, } @@ -1431,7 +1414,9 @@ mod tests { use super::sample_scrape_request; use crate::core::{self, statistics}; use crate::servers::udp::handlers::handle_scrape; - use crate::servers::udp::handlers::tests::{sample_ipv4_remote_addr, tracker_configuration}; + use crate::servers::udp::handlers::tests::{ + sample_cookie_valid_range, sample_ipv4_remote_addr, tracker_configuration, + }; #[tokio::test] async fn should_send_the_upd4_scrape_event() { @@ -1453,9 +1438,14 @@ mod tests { .unwrap(), ); - handle_scrape(remote_addr, &sample_scrape_request(&remote_addr), &tracker) - .await - .unwrap(); + handle_scrape( + remote_addr, + &sample_scrape_request(&remote_addr), + &tracker, + sample_cookie_valid_range(), + ) + .await + .unwrap(); } } @@ -1468,7 +1458,9 @@ mod tests { use super::sample_scrape_request; use crate::core::{self, statistics}; use crate::servers::udp::handlers::handle_scrape; - use crate::servers::udp::handlers::tests::{sample_ipv6_remote_addr, tracker_configuration}; + use crate::servers::udp::handlers::tests::{ + sample_cookie_valid_range, sample_ipv6_remote_addr, tracker_configuration, + }; #[tokio::test] async fn should_send_the_upd6_scrape_event() { @@ -1490,9 +1482,14 @@ mod tests { .unwrap(), ); - handle_scrape(remote_addr, &sample_scrape_request(&remote_addr), &tracker) - .await - .unwrap(); + handle_scrape( + remote_addr, + &sample_scrape_request(&remote_addr), + &tracker, + sample_cookie_valid_range(), + ) + .await + .unwrap(); } } } diff --git a/src/servers/udp/logging.rs b/src/servers/udp/logging.rs deleted file mode 100644 index a61668e83..000000000 --- a/src/servers/udp/logging.rs +++ /dev/null @@ -1,87 +0,0 @@ -//! Logging for UDP Tracker requests and responses. - -use std::net::SocketAddr; -use std::time::Duration; - -use aquatic_udp_protocol::{Request, Response, TransactionId}; -use bittorrent_primitives::info_hash::InfoHash; - -use super::handlers::RequestId; -use crate::servers::udp::UDP_TRACKER_LOG_TARGET; - -pub fn log_request(request: &Request, request_id: &RequestId, server_socket_addr: &SocketAddr) { - let action = map_action_name(request); - - match &request { - Request::Connect(connect_request) => { - let transaction_id = connect_request.transaction_id; - let transaction_id_str = transaction_id.0.to_string(); - - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, "request", server_socket_addr = %server_socket_addr, action = %action, transaction_id = %transaction_id_str, request_id = %request_id); - } - Request::Announce(announce_request) => { - let transaction_id = announce_request.transaction_id; - let transaction_id_str = transaction_id.0.to_string(); - let connection_id_str = announce_request.connection_id.0.to_string(); - let info_hash_str = InfoHash::from_bytes(&announce_request.info_hash.0).to_hex_string(); - - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, "request", server_socket_addr = %server_socket_addr, action = %action, transaction_id = %transaction_id_str, request_id = %request_id, connection_id = %connection_id_str, info_hash = %info_hash_str); - } - Request::Scrape(scrape_request) => { - let transaction_id = scrape_request.transaction_id; - let transaction_id_str = transaction_id.0.to_string(); - let connection_id_str = scrape_request.connection_id.0.to_string(); - - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, - "request", - server_socket_addr = %server_socket_addr, - action = %action, - transaction_id = %transaction_id_str, - request_id = %request_id, - connection_id = %connection_id_str); - } - }; -} - -fn map_action_name(udp_request: &Request) -> String { - match udp_request { - Request::Connect(_connect_request) => "CONNECT".to_owned(), - Request::Announce(_announce_request) => "ANNOUNCE".to_owned(), - Request::Scrape(_scrape_request) => "SCRAPE".to_owned(), - } -} - -pub fn log_response( - _response: &Response, - transaction_id: &TransactionId, - request_id: &RequestId, - server_socket_addr: &SocketAddr, - latency: Duration, -) { - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, - "response", - server_socket_addr = %server_socket_addr, - transaction_id = %transaction_id.0.to_string(), - request_id = %request_id, - latency_ms = %latency.as_millis()); -} - -pub fn log_bad_request(request_id: &RequestId) { - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, "bad request", request_id = %request_id); -} - -pub fn log_error_response(request_id: &RequestId) { - tracing::span!( - target: UDP_TRACKER_LOG_TARGET, - tracing::Level::INFO, "response", request_id = %request_id); -} diff --git a/src/servers/udp/mod.rs b/src/servers/udp/mod.rs index d41bc8b3f..9b4d90c89 100644 --- a/src/servers/udp/mod.rs +++ b/src/servers/udp/mod.rs @@ -641,7 +641,6 @@ use std::net::SocketAddr; pub mod connection_cookie; pub mod error; pub mod handlers; -pub mod logging; pub mod peer_builder; pub mod server; diff --git a/src/servers/udp/server/launcher.rs b/src/servers/udp/server/launcher.rs index 348446876..c8bac8098 100644 --- a/src/servers/udp/server/launcher.rs +++ b/src/servers/udp/server/launcher.rs @@ -30,7 +30,9 @@ impl Launcher { /// # Panics /// /// It panics if unable to bind to udp socket, and get the address from the udp socket. - /// It also panics if unable to send address of socket. + /// It panics if unable to send address of socket. + /// It panics if the udp server is loaded when the tracker is private. + /// #[instrument(skip(tracker, bind_to, tx_start, rx_halt))] pub async fn run_with_graceful_shutdown( tracker: Arc, @@ -41,6 +43,11 @@ impl Launcher { ) { tracing::info!(target: UDP_TRACKER_LOG_TARGET, "Starting on: {bind_to}"); + if tracker.requires_authentication() { + tracing::error!("udp services cannot be used for private trackers"); + panic!("it should not use udp if using authentication"); + } + let socket = tokio::time::timeout(Duration::from_millis(5000), BoundSocket::new(bind_to)) .await .expect("it should bind to the socket within five seconds"); diff --git a/tests/servers/api/v1/contract/context/stats.rs b/tests/servers/api/v1/contract/context/stats.rs index 2c8e8d6a5..463dc563e 100644 --- a/tests/servers/api/v1/contract/context/stats.rs +++ b/tests/servers/api/v1/contract/context/stats.rs @@ -43,9 +43,11 @@ async fn should_allow_getting_tracker_statistics() { udp4_connections_handled: 0, udp4_announces_handled: 0, udp4_scrapes_handled: 0, + udp4_errors_handled: 0, udp6_connections_handled: 0, udp6_announces_handled: 0, udp6_scrapes_handled: 0, + udp6_errors_handled: 0, }, ) .await;