log => tracing

This commit is contained in:
Jędrzej Stuczyński
2025-09-01 16:15:35 +01:00
parent d3ad14e87d
commit f1f302a71c
10 changed files with 65 additions and 63 deletions
Generated
+1 -1
View File
@@ -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",
]
@@ -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"] }
@@ -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(())
}
}
@@ -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();
}
@@ -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
@@ -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))
}
}
@@ -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<Vec<PacketHandleResult>> {
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(())
}
}
@@ -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;
@@ -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}")
}
});
}
@@ -11,7 +11,7 @@ pub(crate) struct ParsedPacket<'a> {
pub(crate) fn parse_packet(packet: &[u8]) -> Result<ParsedPacket<'_>, 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<ParsedPacket<'_>, 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<ParsedPacket<'_>, 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);
}
};