Skip to content

Commit 5a6c968

Browse files
committed
feat: [torrust#704] add latency to UDP tracker logs
Example: ``` 2024-02-23T08:24:50.137064143+00:00 [UDP TRACKER][INFO] request; server_socket_addr=0.0.0.0:6969 action=ANNOUNCE transaction_id=-888840697 request_id=c38ab102-3ad1-48d3-8f2e-e03190d6e592 connection_id=4792797915217963415 info_hash=9c38422213e30bff212b30c360d26f9a02136422 2024-02-23T08:24:50.137075433+00:00 [UDP TRACKER][INFO] response; server_socket_addr=0.0.0.0:6969 transaction_id=-888840697 request_id=c38ab102-3ad1-48d3-8f2e-e03190d6e592 latency_ms=0 ```
1 parent 5e5a9aa commit 5a6c968

File tree

2 files changed

+21
-3
lines changed

2 files changed

+21
-3
lines changed

src/servers/udp/handlers.rs

+6-1
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ use std::fmt;
33
use std::net::{IpAddr, Ipv4Addr, Ipv6Addr, SocketAddr};
44
use std::panic::Location;
55
use std::sync::Arc;
6+
use std::time::Instant;
67

78
use aquatic_udp_protocol::{
89
AnnounceInterval, AnnounceRequest, AnnounceResponse, ConnectRequest, ConnectResponse, ErrorResponse, NumberOfDownloads,
@@ -35,6 +36,8 @@ use crate::shared::bit_torrent::info_hash::InfoHash;
3536
pub(crate) async fn handle_packet(udp_request: UdpRequest, tracker: &Arc<Tracker>, socket: Arc<UdpSocket>) -> Response {
3637
debug!("Handling Packets: {udp_request:?}");
3738

39+
let start_time = Instant::now();
40+
3841
let request_id = RequestId::make(&udp_request);
3942
let server_socket_addr = socket.local_addr().expect("Could not get local_addr for socket.");
4043

@@ -58,7 +61,9 @@ pub(crate) async fn handle_packet(udp_request: UdpRequest, tracker: &Arc<Tracker
5861
Err(e) => handle_error(&e, transaction_id),
5962
};
6063

61-
log_response(&response, &transaction_id, &request_id, &server_socket_addr);
64+
let latency = start_time.elapsed();
65+
66+
log_response(&response, &transaction_id, &request_id, &server_socket_addr, latency);
6267

6368
response
6469
}

src/servers/udp/logging.rs

+15-2
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
//! Logging for UDP Tracker requests and responses.
22
33
use std::net::SocketAddr;
4+
use std::time::Duration;
45

56
use aquatic_udp_protocol::{Request, Response, TransactionId};
67

@@ -36,7 +37,13 @@ pub fn log_request(request: &Request, request_id: &RequestId, server_socket_addr
3637

3738
tracing::span!(
3839
target: "UDP TRACKER",
39-
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);
40+
tracing::Level::INFO,
41+
"request",
42+
server_socket_addr = %server_socket_addr,
43+
action = %action,
44+
transaction_id = %transaction_id_str,
45+
request_id = %request_id,
46+
connection_id = %connection_id_str);
4047
}
4148
};
4249
}
@@ -54,10 +61,16 @@ pub fn log_response(
5461
transaction_id: &TransactionId,
5562
request_id: &RequestId,
5663
server_socket_addr: &SocketAddr,
64+
latency: Duration,
5765
) {
5866
tracing::span!(
5967
target: "UDP TRACKER",
60-
tracing::Level::INFO, "response", server_socket_addr = %server_socket_addr, transaction_id = %transaction_id.0.to_string(), request_id = %request_id);
68+
tracing::Level::INFO,
69+
"response",
70+
server_socket_addr = %server_socket_addr,
71+
transaction_id = %transaction_id.0.to_string(),
72+
request_id = %request_id,
73+
latency_ms = %latency.as_millis());
6174
}
6275

6376
pub fn log_bad_request(request_id: &RequestId) {

0 commit comments

Comments
 (0)