From 272219decde5e305b3a80efd46c2a2d4b9b44f08 Mon Sep 17 00:00:00 2001 From: Jose Celano Date: Mon, 13 Jul 2026 16:29:56 +0100 Subject: [PATCH 1/3] docs(1447): add issue spec for changing connection ID error log level to WARNING --- ...e-logging-threshold-connection-id-error.md | 121 ++++++++++++++++++ 1 file changed, 121 insertions(+) create mode 100644 docs/issues/open/1447-change-logging-threshold-connection-id-error.md diff --git a/docs/issues/open/1447-change-logging-threshold-connection-id-error.md b/docs/issues/open/1447-change-logging-threshold-connection-id-error.md new file mode 100644 index 000000000..3269c5ac0 --- /dev/null +++ b/docs/issues/open/1447-change-logging-threshold-connection-id-error.md @@ -0,0 +1,121 @@ +--- +doc-type: issue +issue-type: task +status: planned +priority: p3 +github-issue: 1447 +spec-path: docs/issues/open/1447-change-logging-threshold-connection-id-error.md +branch: "1447-change-logging-threshold-connection-id-error" +related-pr: null +last-updated-utc: 2026-07-13 12:00 +semantic-links: + skill-links: + - create-issue + related-artifacts: + - packages/udp-server/src/handlers/error.rs +--- + +# Issue #1447 - Change the logging threshold for connection ID error to `WARNING` + +## Goal + +Change the log level for UDP connection ID errors from `ERROR` to `WARNING` to reduce +log noise in production deployments (especially the Torrust Tracker demo). + +## Background + +The UDP tracker receives a high volume of requests with invalid connection IDs from +misconfigured or abusive peers. These produce errors like: + +- `cookie value is expired` +- `cookie value is from future` + +These are currently logged at `ERROR` level, which floods the logs and makes it hard to +identify other types of errors. + +The tracker already bans IPs that make too many such requests (tracked via the +`udp_tracker_server_connection_id_errors_total` metric and the ban service), so the +logging can safely be downgraded. A `WARNING` level is still appropriate because there +is no other monitoring/analytics tool to detect unusual patterns — the log remains the +primary observability channel for connection ID issues. + +This is not an application error — it is expected behaviour from bad client traffic. + +## Scope + +### In Scope + +- Change the `tracing::error!` call in `log_error()` in `packages/udp-server/src/handlers/error.rs` to `tracing::warn!` +- Verify that the change does not break any tests that assert on log level or output +- Run `linter all` and the full test suite + +### Out of Scope + +- Adding a configuration option for the log level (not configurable for now) +- Changing log levels for other error types +- Changing the banning behaviour (stays at `ERROR`-level events) +- Adding separate monitoring/analytics tooling + +## Implementation Plan + +Status values: `TODO`, `IN_PROGRESS`, `BLOCKED`, `DONE`. + +| ID | Status | Task | Notes / Expected Output | +| --- | ------ | --------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------- | +| T1 | TODO | Change log level in `handlers/error.rs` | Make `log_error()` inspect the error type: use `tracing::warn!` for `ConnectionCookie` errors, keep `tracing::error!` for all other error types | +| T2 | TODO | Run verification | `linter all`, `cargo test --workspace`, pre-commit checks | + +## Technical Details + +The `ServerError` type in `packages/udp-server/src/error.rs` has several variants. +Connection cookie errors flow through two paths: + +- `Error::AnnounceFailed { source: UdpAnnounceError::ConnectionCookieError { .. } }` +- `Error::ScrapeFailed { source: UdpScrapeError::ConnectionCookieError { .. } }` + +The current `log_error()` function in `packages/udp-server/src/handlers/error.rs` is called for **all** UDP error types, not just connection cookie errors: + +```rust +fn log_error( + error: &Error, + client_socket_addr: SocketAddr, + server_socket_addr: SocketAddr, + opt_transaction_id: Option, + request_id: Uuid, +) { + match opt_transaction_id { + Some(transaction_id) => { + let transaction_id = transaction_id.0.to_string(); + tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, %transaction_id, "response error"); + } + None => { + tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, "response error"); + } + } +} +``` + +The implementation should inspect the error variant and use `tracing::warn!` for +`ConnectionCookie` errors while keeping `tracing::error!` for other error types +(invalid requests, announce/scrape errors, internal errors, etc.). + +The `Error` type derives `Clone` and can be pattern-matched. Matching on +`matches!(error, Error::AnnounceFailed { source: UdpAnnounceError::ConnectionCookieError { .. } })` +or similar approach. + +Note: The `ErrorKind::ConnectionCookie` variant is specifically handled by the banning +event handler (`packages/udp-server/src/banning/event/handler.rs`) to track IP bans +separately — this behaviour is unaffected by the log level change. + +## Progress Tracking + +### Workflow Checkpoints + +- [x] Spec drafted in `docs/issues/open/` +- [ ] Spec reviewed and approved by user/maintainer +- [ ] GitHub issue exists and issue number matches spec +- [ ] Implementation completed +- [ ] Automatic verification completed (`linter all`, relevant tests, and any pre-push checks) +- [ ] Manual verification scenarios executed and recorded (status + evidence) +- [ ] Acceptance criteria reviewed after implementation and updated with evidence +- [ ] Reviewer validated acceptance criteria and updated checkboxes From 2f100ba9c2a76857cc11a899cddbdfc204f6cf6a Mon Sep 17 00:00:00 2001 From: Jose Celano Date: Mon, 13 Jul 2026 16:53:46 +0100 Subject: [PATCH 2/3] feat(udp-server): change connection ID error log level from ERROR to WARNING Connection cookie errors (expired/from-future) are caused by bad client traffic, not application errors. Logging them at ERROR level floods the logs, making it hard to identify real issues. Now inspects the error variant: - Connection cookie errors: logged at WARN - All other UDP errors: remain at ERROR Also updated the test helper log filter from ERROR to WARN so the captured test logs include WARN messages for assertions. --- packages/test-helpers/src/logging.rs | 2 +- packages/udp-server/src/handlers/error.rs | 37 ++++++++++++++++---- packages/udp-server/tests/server/contract.rs | 4 +-- 3 files changed, 34 insertions(+), 9 deletions(-) diff --git a/packages/test-helpers/src/logging.rs b/packages/test-helpers/src/logging.rs index 564074f3e..86c3294fc 100644 --- a/packages/test-helpers/src/logging.rs +++ b/packages/test-helpers/src/logging.rs @@ -18,7 +18,7 @@ pub fn captured_logs_buffer() -> &'static Mutex { pub fn setup() { INIT.call_once(|| { - tracing_init(LevelFilter::ERROR, &TraceStyle::Default); + tracing_init(LevelFilter::WARN, &TraceStyle::Default); }); } diff --git a/packages/udp-server/src/handlers/error.rs b/packages/udp-server/src/handlers/error.rs index 0c61a96b4..afc13c59e 100644 --- a/packages/udp-server/src/handlers/error.rs +++ b/packages/udp-server/src/handlers/error.rs @@ -3,6 +3,8 @@ use std::net::SocketAddr; use std::ops::Range; use torrust_net_primitives::service_binding::ServiceBinding; +use torrust_tracker_udp_core::services::announce::UdpAnnounceError; +use torrust_tracker_udp_core::services::scrape::UdpScrapeError; use torrust_tracker_udp_core::{self, UDP_TRACKER_LOG_TARGET}; use torrust_tracker_udp_protocol::{ErrorResponse, Response, TransactionId}; use tracing::{Level, instrument}; @@ -52,17 +54,40 @@ fn log_error( opt_transaction_id: Option, request_id: Uuid, ) { - match opt_transaction_id { - Some(transaction_id) => { - let transaction_id = transaction_id.0.to_string(); - tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, %transaction_id, "response error"); + if is_connection_cookie_error(error) { + match opt_transaction_id { + Some(transaction_id) => { + let transaction_id = transaction_id.0.to_string(); + tracing::warn!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, %transaction_id, "response error"); + } + None => { + tracing::warn!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, "response error"); + } } - None => { - tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, "response error"); + } else { + match opt_transaction_id { + Some(transaction_id) => { + let transaction_id = transaction_id.0.to_string(); + tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, %transaction_id, "response error"); + } + None => { + tracing::error!(target: UDP_TRACKER_LOG_TARGET, error = %error, %client_socket_addr, %server_socket_addr, %request_id, "response error"); + } } } } +fn is_connection_cookie_error(error: &Error) -> bool { + matches!( + error, + Error::AnnounceFailed { + source: UdpAnnounceError::ConnectionCookieError { .. } + } | Error::ScrapeFailed { + source: UdpScrapeError::ConnectionCookieError { .. } + } + ) +} + async fn trigger_udp_error_event( error: &Error, client_socket_addr: SocketAddr, diff --git a/packages/udp-server/tests/server/contract.rs b/packages/udp-server/tests/server/contract.rs index 402a79ff6..f9930d0b6 100644 --- a/packages/udp-server/tests/server/contract.rs +++ b/packages/udp-server/tests/server/contract.rs @@ -275,8 +275,8 @@ mod receiving_an_announce_request { let transaction_id = tx_id.0.to_string(); assert!( - logs_contains_a_line_with(&["ERROR", "UDP TRACKER", &transaction_id]), - "Expected logs to contain: ERROR ... UDP TRACKER ... transaction_id={transaction_id}" + logs_contains_a_line_with(&["WARN", "UDP TRACKER", &transaction_id]), + "Expected logs to contain: WARN ... UDP TRACKER ... transaction_id={transaction_id}" ); } From b4fa8f968750d339daedcf0bad58cb3fc13b8451 Mon Sep 17 00:00:00 2001 From: Jose Celano Date: Mon, 13 Jul 2026 19:13:43 +0100 Subject: [PATCH 3/3] fix(udp-server): address Copilot review comments - Remove unused torrust_tracker_udp_core::self import - Add missing skill-link marker to issue spec --- .../open/1447-change-logging-threshold-connection-id-error.md | 2 ++ packages/udp-server/src/handlers/error.rs | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/docs/issues/open/1447-change-logging-threshold-connection-id-error.md b/docs/issues/open/1447-change-logging-threshold-connection-id-error.md index 3269c5ac0..6d1bccf85 100644 --- a/docs/issues/open/1447-change-logging-threshold-connection-id-error.md +++ b/docs/issues/open/1447-change-logging-threshold-connection-id-error.md @@ -15,6 +15,8 @@ semantic-links: - packages/udp-server/src/handlers/error.rs --- + + # Issue #1447 - Change the logging threshold for connection ID error to `WARNING` ## Goal diff --git a/packages/udp-server/src/handlers/error.rs b/packages/udp-server/src/handlers/error.rs index afc13c59e..5f91905d7 100644 --- a/packages/udp-server/src/handlers/error.rs +++ b/packages/udp-server/src/handlers/error.rs @@ -3,9 +3,9 @@ use std::net::SocketAddr; use std::ops::Range; use torrust_net_primitives::service_binding::ServiceBinding; +use torrust_tracker_udp_core::UDP_TRACKER_LOG_TARGET; use torrust_tracker_udp_core::services::announce::UdpAnnounceError; use torrust_tracker_udp_core::services::scrape::UdpScrapeError; -use torrust_tracker_udp_core::{self, UDP_TRACKER_LOG_TARGET}; use torrust_tracker_udp_protocol::{ErrorResponse, Response, TransactionId}; use tracing::{Level, instrument}; use uuid::Uuid;