From f1f302a71c19a4867f226648015307a469e192ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?J=C4=99drzej=20Stuczy=C5=84ski?= Date: Mon, 1 Sep 2025 16:15:35 +0100 Subject: [PATCH] log => tracing --- Cargo.lock | 2 +- service-providers/ip-packet-router/Cargo.toml | 2 +- .../src/clients/connected_client_handler.rs | 18 +++---- .../src/clients/connected_clients.rs | 14 ++--- .../ip-packet-router/src/ip_packet_router.rs | 8 +-- .../ip-packet-router/src/messages/request.rs | 2 +- .../ip-packet-router/src/mixnet_listener.rs | 52 +++++++++---------- .../src/request_filter/mod.rs | 2 +- .../ip-packet-router/src/tun_listener.rs | 22 ++++---- .../ip-packet-router/src/util/parse_ip.rs | 6 +-- 10 files changed, 65 insertions(+), 63 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index db286286d4..75cdc8d8fa 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6023,7 +6023,6 @@ dependencies = [ "bytes", "etherparse", "futures", - "log", "nym-bin-common", "nym-client-core", "nym-exit-policy", @@ -6046,6 +6045,7 @@ dependencies = [ "tokio", "tokio-tun", "tokio-util", + "tracing", "url", ] diff --git a/service-providers/ip-packet-router/Cargo.toml b/service-providers/ip-packet-router/Cargo.toml index ab651b198b..d6c1036607 100644 --- a/service-providers/ip-packet-router/Cargo.toml +++ b/service-providers/ip-packet-router/Cargo.toml @@ -13,7 +13,7 @@ bincode = { workspace = true } bytes = { workspace = true } etherparse = { workspace = true } futures = { workspace = true } -log = { workspace = true } +tracing = { workspace = true } nym-bin-common = { path = "../../common/bin-common" } nym-client-core = { path = "../../common/client-core" } nym-exit-policy = { path = "../../common/exit-policy", features = ["client"] } diff --git a/service-providers/ip-packet-router/src/clients/connected_client_handler.rs b/service-providers/ip-packet-router/src/clients/connected_client_handler.rs index 551518a062..c3250252c8 100644 --- a/service-providers/ip-packet-router/src/clients/connected_client_handler.rs +++ b/service-providers/ip-packet-router/src/clients/connected_client_handler.rs @@ -69,8 +69,8 @@ impl ConnectedClientHandler { oneshot::Sender<()>, tokio::task::JoinHandle<()>, ) { - log::debug!("Starting connected client handler for: {client_id}"); - log::debug!("client version: {client_version:?}"); + tracing::debug!("Starting connected client handler for: {client_id}"); + tracing::debug!("client version: {client_version:?}"); let (close_tx, close_rx) = oneshot::channel(); let (forward_from_tun_tx, forward_from_tun_rx) = mpsc::unbounded_channel(); @@ -101,7 +101,7 @@ impl ConnectedClientHandler { let handle = tokio::spawn(async move { if let Err(err) = connected_client_handler.run().await { - log::error!("connected client handler has failed: {err}") + tracing::error!("connected client handler has failed: {err}") } }); @@ -149,33 +149,33 @@ impl ConnectedClientHandler { loop { tokio::select! { _ = &mut self.close_rx => { - log::info!("client handler stopping: received close: {}", self.sent_by); + tracing::info!("client handler stopping: received close: {}", self.sent_by); break; }, _ = self.activity_timeout.tick() => { - log::info!("client handler stopping: activity timeout: {}", self.sent_by); + tracing::info!("client handler stopping: activity timeout: {}", self.sent_by); break; }, _ = self.payload_topup_interval.tick() => { if let Err(err) = self.handle_packet(IprPacket::Flush).await { - log::error!("client handler: failed to handle packet: {err}"); + tracing::error!("client handler: failed to handle packet: {err}"); } }, packet = self.forward_from_tun_rx.recv() => match packet { Some(packet) => { if let Err(err) = self.handle_packet(IprPacket::from(packet)).await { - log::error!("client handler: failed to handle packet: {err}"); + tracing::error!("client handler: failed to handle packet: {err}"); } }, None => { - log::info!("client handler stopping: tun channel closed"); + tracing::info!("client handler stopping: tun channel closed"); break; } }, } } - log::debug!("ConnectedClientHandler: exiting"); + tracing::debug!("ConnectedClientHandler: exiting"); Ok(()) } } diff --git a/service-providers/ip-packet-router/src/clients/connected_clients.rs b/service-providers/ip-packet-router/src/clients/connected_clients.rs index 7100048dd8..c38f8a6b3e 100644 --- a/service-providers/ip-packet-router/src/clients/connected_clients.rs +++ b/service-providers/ip-packet-router/src/clients/connected_clients.rs @@ -61,7 +61,7 @@ impl ConnectedClients { pub(crate) fn disconnect_client(&mut self, client_id: &ConnectedClientId) { if let Some(ips) = self.lookup_ip_from_client_id(client_id) { - log::debug!("Disconnect client that requested to do so: {ips}"); + tracing::debug!("Disconnect client that requested to do so: {ips}"); self.disconnect_client_handle(ips); } } @@ -72,7 +72,7 @@ impl ConnectedClients { self.tun_listener_connected_client_tx .send(ConnectedClientEvent::Disconnect(DisconnectEvent(ips))) .inspect_err(|err| { - log::error!("Failed to send disconnect event: {err}"); + tracing::error!("Failed to send disconnect event: {err}"); }) .ok(); } @@ -117,7 +117,7 @@ impl ConnectedClients { handle: Arc::new(handle), }; - log::info!("Inserting {} and {}", ips.ipv4, ips.ipv6); + tracing::info!("Inserting {} and {}", ips.ipv4, ips.ipv6); self.clients_ipv4_mapping.insert(ips.ipv4, client.clone()); self.clients_ipv6_mapping.insert(ips.ipv6, client); @@ -129,7 +129,7 @@ impl ConnectedClients { forward_from_tun_tx, }))) .inspect_err(|err| { - log::error!("Failed to send connected client event: {err}"); + tracing::error!("Failed to send connected client event: {err}"); }) .ok(); } @@ -181,7 +181,7 @@ impl ConnectedClients { stopped_clients: Vec<(IpPair, ConnectedClientId)>, ) { for (ips, _) in &stopped_clients { - log::info!("Disconnect stopped client: {ips}"); + tracing::info!("Disconnect stopped client: {ips}"); self.disconnect_client_handle(*ips); } } @@ -191,7 +191,7 @@ impl ConnectedClients { inactive_clients: Vec<(IpPair, ConnectedClientId)>, ) { for (ips, _) in &inactive_clients { - log::info!("Disconnect inactive client: {ips}"); + tracing::info!("Disconnect inactive client: {ips}"); self.disconnect_client_handle(*ips); } } @@ -242,7 +242,7 @@ impl ConnectedClient { impl Drop for CloseTx { fn drop(&mut self) { - log::debug!("signal to close client: {}", self.client_id); + tracing::debug!("signal to close client: {}", self.client_id); if let Some(close_tx) = self.inner.take() { close_tx.send(()).ok(); } diff --git a/service-providers/ip-packet-router/src/ip_packet_router.rs b/service-providers/ip-packet-router/src/ip_packet_router.rs index 4e976e96f9..b76cd0992b 100644 --- a/service-providers/ip-packet-router/src/ip_packet_router.rs +++ b/service-providers/ip-packet-router/src/ip_packet_router.rs @@ -115,7 +115,9 @@ impl IpPacketRouter { pub async fn run_service_provider(self) -> Result<(), IpPacketRouterError> { // for debugging purposes, don't crash in debug builds on non-linux platforms if cfg!(debug_assertions) { - log::error!("ip packet router service provider is not yet supported on this platform"); + tracing::error!( + "ip packet router service provider is not yet supported on this platform" + ); Ok(()) } else { todo!("service provider is not yet supported on this platform") @@ -180,8 +182,8 @@ impl IpPacketRouter { connected_clients, }; - log::info!("The address of this client is: {self_address}"); - log::info!("All systems go. Press CTRL-C to stop the server."); + tracing::info!("The address of this client is: {self_address}"); + tracing::info!("All systems go. Press CTRL-C to stop the server."); if let Some(on_start) = self.on_start { if on_start diff --git a/service-providers/ip-packet-router/src/messages/request.rs b/service-providers/ip-packet-router/src/messages/request.rs index 665abe024a..48600e8626 100644 --- a/service-providers/ip-packet-router/src/messages/request.rs +++ b/service-providers/ip-packet-router/src/messages/request.rs @@ -130,7 +130,7 @@ impl TryFrom<&ReconstructedMessage> for IpPacketRequest { Ok(IpPacketRequest::from((request_v8, sender_tag))) } _ => { - log::info!("Received packet with invalid version: v{request_version}"); + tracing::info!("Received packet with invalid version: v{request_version}"); Err(IpPacketRouterError::InvalidPacketVersion(request_version)) } } diff --git a/service-providers/ip-packet-router/src/mixnet_listener.rs b/service-providers/ip-packet-router/src/mixnet_listener.rs index fe622f8aa0..d350d14106 100644 --- a/service-providers/ip-packet-router/src/mixnet_listener.rs +++ b/service-providers/ip-packet-router/src/mixnet_listener.rs @@ -66,7 +66,7 @@ impl MixnetListener { ip_packet: &[u8], version: ClientVersion, ) -> PacketHandleResult { - log::trace!("Received data request"); + tracing::trace!("Received data request"); // We don't forward packets that we are not able to parse. BUT, there might be a good // reason to still forward them. @@ -80,7 +80,7 @@ impl MixnetListener { } = crate::util::parse_ip::parse_packet(ip_packet)?; let dst_str = dst.map_or(dst_addr.to_string(), |dst| dst.to_string()); - log::debug!("Received packet: {packet_type}: {src_addr} -> {dst_str}"); + tracing::debug!("Received packet: {packet_type}: {src_addr} -> {dst_str}"); if let Some(connected_client) = self.connected_clients.get_client_from_ip_mut(&src_addr) { // Keep track of activity so we can disconnect inactive clients @@ -98,7 +98,7 @@ impl MixnetListener { .map_err(|_| IpPacketRouterError::FailedToWritePacketToTun)?; Ok(None) } else { - log::debug!("Denied filter check: {dst}"); + tracing::debug!("Denied filter check: {dst}"); Ok(Some(VersionedResponse { version, reply_to: connected_client.client_id.clone(), @@ -115,7 +115,7 @@ impl MixnetListener { } } else { // If the client is not connected, just drop the packet silently - log::debug!("dropping packet from mixnet: no registered client for packet with source: {src_addr}"); + tracing::debug!("dropping packet from mixnet: no registered client for packet with source: {src_addr}"); Ok(None) } } @@ -144,7 +144,7 @@ impl MixnetListener { &mut self, connect_request: StaticConnectRequest, ) -> PacketHandleResult { - log::info!( + tracing::info!( "Received static connect request from {}", connect_request.sent_by ); @@ -166,14 +166,14 @@ impl MixnetListener { let response = match (is_ip_taken, is_client_id_taken) { (true, true) => { - log::info!("Connecting an already connected client"); + tracing::info!("Connecting an already connected client"); if self .connected_clients .update_activity(&requested_ips) .await .is_err() { - log::error!("Failed to update activity for client"); + tracing::error!("Failed to update activity for client"); }; Response::StaticConnect { request_id, @@ -181,7 +181,7 @@ impl MixnetListener { } } (false, false) => { - log::info!("Connecting a new client"); + tracing::info!("Connecting a new client"); // Spawn the ConnectedClientHandler for the new client let (forward_from_tun_tx, close_tx, handle) = ConnectedClientHandler::start( @@ -205,14 +205,14 @@ impl MixnetListener { } } (true, false) => { - log::info!("Requested IP is not available"); + tracing::info!("Requested IP is not available"); Response::StaticConnect { request_id, reply: StaticConnectFailureReason::RequestedIpAlreadyInUse.into(), } } (false, true) => { - log::info!("Nym address is already registered"); + tracing::info!("Nym address is already registered"); Response::StaticConnect { request_id, reply: StaticConnectFailureReason::ClientAlreadyConnected.into(), @@ -231,7 +231,7 @@ impl MixnetListener { &mut self, connect_request: DynamicConnectRequest, ) -> PacketHandleResult { - log::info!( + tracing::info!( "Received dynamic connect request from {}", connect_request.sent_by ); @@ -245,7 +245,7 @@ impl MixnetListener { .unwrap_or(nym_ip_packet_requests::codec::BUFFER_TIMEOUT); if let Some(ips) = self.connected_clients.lookup_ip_from_client_id(&reply_to) { - log::debug!("Reconnecting to the previous session"); + tracing::debug!("Reconnecting to the previous session"); return Ok(Some(VersionedResponse { version, reply_to, @@ -257,7 +257,7 @@ impl MixnetListener { } let Some(new_ips) = self.connected_clients.find_new_ip() else { - log::info!("No available IP address"); + tracing::info!("No available IP address"); return Ok(Some(VersionedResponse { version, reply_to, @@ -299,7 +299,7 @@ impl MixnetListener { &mut self, disconnect_request: DisconnectRequest, ) -> PacketHandleResult { - log::info!( + tracing::info!( "Received disconnect request from {}", disconnect_request.sent_by ); @@ -310,7 +310,7 @@ impl MixnetListener { // Check if the client is connected if !self.connected_clients.is_client_connected(&client_id) { - log::info!("Client {client_id} is not connected, cannot disconnect"); + tracing::info!("Client {client_id} is not connected, cannot disconnect"); return Ok(Some(VersionedResponse { version, reply_to: client_id, @@ -322,7 +322,7 @@ impl MixnetListener { } // Disconnect the client - log::info!("Disconnecting client {client_id}"); + tracing::info!("Disconnecting client {client_id}"); self.connected_clients.disconnect_client(&client_id); Ok(Some(VersionedResponse { @@ -384,7 +384,7 @@ impl MixnetListener { &mut self, reconstructed: ReconstructedMessage, ) -> Result> { - log::debug!( + tracing::debug!( "Received message with sender_tag: {}", reconstructed .sender_tag @@ -395,13 +395,13 @@ impl MixnetListener { // First deserialize the request let request = match IpPacketRequest::try_from(&reconstructed) { Err(IpPacketRouterError::InvalidPacketVersion(version)) => { - log::debug!("Received packet with invalid version: v{version}"); + tracing::debug!("Received packet with invalid version: v{version}"); return Ok(vec![self.on_version_mismatch(version, &reconstructed)]); } req => req, }?; - log::debug!("Received request: {request}"); + tracing::debug!("Received request: {request}"); match request { IpPacketRequest::Data(request) => self.on_data_request(request).await, @@ -417,7 +417,7 @@ impl MixnetListener { //for (ip, nym_address) in stopped_clients.iter().chain(disconnected_clients.iter()) { // let response = IpPacketResponse::new_unrequested_disconnect(...) // if let Err(err) = self.handle_response(response).await { - // log::error!("Failed to send disconnect response: {err}"); + // tracing::error!("Failed to send disconnect response: {err}"); // } //} @@ -449,14 +449,14 @@ impl MixnetListener { match response { Ok(Some(response)) => { if let Err(err) = self.handle_response(response).await { - log::error!("Mixnet listener failed to handle response: {err}"); + tracing::error!("Mixnet listener failed to handle response: {err}"); } } Ok(None) => { continue; } Err(err) => { - log::error!("Error handling mixnet message: {err}"); + tracing::error!("Error handling mixnet message: {err}"); } } } @@ -469,7 +469,7 @@ impl MixnetListener { while !task_client.is_shutdown() { tokio::select! { _ = task_client.recv() => { - log::debug!("IpPacketRouter [main loop]: received shutdown"); + tracing::debug!("IpPacketRouter [main loop]: received shutdown"); }, _ = disconnect_timer.tick() => { self.handle_disconnect_timer().await; @@ -479,19 +479,19 @@ impl MixnetListener { match self.on_reconstructed_message(msg).await { Ok(responses) => self.handle_responses(responses).await, Err(err) => { - log::error!("Error handling reconstructed mixnet message: {err}"); + tracing::error!("Error handling reconstructed mixnet message: {err}"); } }; } else { - log::trace!("IpPacketRouter [main loop]: stopping since channel closed"); + tracing::trace!("IpPacketRouter [main loop]: stopping since channel closed"); break; }; }, } } - log::debug!("IpPacketRouter: stopping"); + tracing::debug!("IpPacketRouter: stopping"); Ok(()) } } diff --git a/service-providers/ip-packet-router/src/request_filter/mod.rs b/service-providers/ip-packet-router/src/request_filter/mod.rs index 5e2f359570..f484bf8d0d 100644 --- a/service-providers/ip-packet-router/src/request_filter/mod.rs +++ b/service-providers/ip-packet-router/src/request_filter/mod.rs @@ -4,8 +4,8 @@ use crate::config::Config; use crate::error::IpPacketRouterError; use crate::request_filter::exit_policy::ExitPolicyRequestFilter; -use log::{info, warn}; use std::{net::SocketAddr, sync::Arc}; +use tracing::{info, warn}; pub mod exit_policy; diff --git a/service-providers/ip-packet-router/src/tun_listener.rs b/service-providers/ip-packet-router/src/tun_listener.rs index 072ade7ab0..9f087963aa 100644 --- a/service-providers/ip-packet-router/src/tun_listener.rs +++ b/service-providers/ip-packet-router/src/tun_listener.rs @@ -50,7 +50,7 @@ impl ConnectedClientsListener { ips, forward_from_tun_tx, } = *connected_event; - log::trace!("Connect client: {ips}"); + tracing::trace!("Connect client: {ips}"); self.clients_ipv4.insert( ips.ipv4, ConnectedClientMirror { @@ -67,7 +67,7 @@ impl ConnectedClientsListener { ); } ConnectedClientEvent::Disconnect(DisconnectEvent(ips)) => { - log::trace!("Disconnect client: {ips}"); + tracing::trace!("Disconnect client: {ips}"); self.clients_ipv4.remove(&ips.ipv4); self.clients_ipv6.remove(&ips.ipv6); } @@ -87,7 +87,7 @@ pub(crate) struct TunListener { impl TunListener { async fn handle_packet(&mut self, buf: &[u8], len: usize) -> Result<()> { let Some(dst_addr) = parse_dst_addr(&buf[..len]) else { - log::warn!("Failed to parse packet"); + tracing::warn!("Failed to parse packet"); return Ok(()); }; @@ -98,12 +98,12 @@ impl TunListener { { let packet = buf[..len].to_vec(); if forward_from_tun_tx.send(packet).is_err() { - log::warn!("Failed to forward packet to connected client {dst_addr}: disconnecting it from tun listener"); + tracing::warn!("Failed to forward packet to connected client {dst_addr}: disconnecting it from tun listener"); self.connected_clients .update(ConnectedClientEvent::Disconnect(DisconnectEvent(*ips))); } } else { - log::debug!( + tracing::debug!( "dropping packet from network: no registered client for destination: {dst_addr}" ); } @@ -116,37 +116,37 @@ impl TunListener { while !self.task_client.is_shutdown() { tokio::select! { _ = self.task_client.recv() => { - log::trace!("TunListener: received shutdown"); + tracing::trace!("TunListener: received shutdown"); }, // TODO: ConnectedClientsListener::update should poll the channel instead event = self.connected_clients.connected_client_rx.recv() => match event { Some(event) => self.connected_clients.update(event), None => { - log::error!("TunListener: connected client channel closed"); + tracing::error!("TunListener: connected client channel closed"); break; }, }, len = self.tun_reader.read(&mut buf) => match len { Ok(len) => { if let Err(err) = self.handle_packet(&buf, len).await { - log::error!("tun: failed to handle packet: {err}"); + tracing::error!("tun: failed to handle packet: {err}"); } }, Err(err) => { - log::warn!("iface: read error: {err}"); + tracing::warn!("iface: read error: {err}"); // break; } } } } - log::debug!("TunListener: stopping"); + tracing::debug!("TunListener: stopping"); Ok(()) } pub(crate) fn start(self) { tokio::spawn(async move { if let Err(err) = self.run().await { - log::error!("tun listener router has failed: {err}") + tracing::error!("tun listener router has failed: {err}") } }); } diff --git a/service-providers/ip-packet-router/src/util/parse_ip.rs b/service-providers/ip-packet-router/src/util/parse_ip.rs index 0b9972b3f2..b31691e996 100644 --- a/service-providers/ip-packet-router/src/util/parse_ip.rs +++ b/service-providers/ip-packet-router/src/util/parse_ip.rs @@ -11,7 +11,7 @@ pub(crate) struct ParsedPacket<'a> { pub(crate) fn parse_packet(packet: &[u8]) -> Result, IpPacketRouterError> { let headers = etherparse::SlicedPacket::from_ip(packet).map_err(|err| { - log::warn!("Unable to parse incoming data as IP packet: {err}"); + tracing::warn!("Unable to parse incoming data as IP packet: {err}"); IpPacketRouterError::PacketParseFailed { source: err } })?; @@ -22,7 +22,7 @@ pub(crate) fn parse_packet(packet: &[u8]) -> Result, IpPacketRo Some(etherparse::TransportSlice::Icmpv6(_)) => ("icmpv6", None), Some(etherparse::TransportSlice::Unknown(_)) => ("unknown", None), None => { - log::warn!("Received packet missing transport header"); + tracing::warn!("Received packet missing transport header"); return Err(IpPacketRouterError::PacketMissingTransportHeader); } }; @@ -41,7 +41,7 @@ pub(crate) fn parse_packet(packet: &[u8]) -> Result, IpPacketRo (src_addr, dst_addr, dst) } None => { - log::warn!("Received packet missing IP header"); + tracing::warn!("Received packet missing IP header"); return Err(IpPacketRouterError::PacketMissingIpHeader); } };