diff --git a/src/mmp/metrics.rs b/src/mmp/metrics.rs index d6f41d7..7631b2a 100644 --- a/src/mmp/metrics.rs +++ b/src/mmp/metrics.rs @@ -8,7 +8,7 @@ use crate::mmp::algorithms::{DualEwma, SrttEstimator, compute_etx}; use crate::mmp::report::ReceiverReport; use std::time::Instant; -use tracing::debug; +use tracing::trace; /// Derived MMP metrics, updated from incoming ReceiverReports. /// @@ -81,7 +81,7 @@ impl MmpMetrics { if our_timestamp_ms > echo_ms + dwell_ms { let rtt_ms = our_timestamp_ms - echo_ms - dwell_ms; let rtt_us = (rtt_ms as i64) * 1000; - debug!( + trace!( our_ts = our_timestamp_ms, echo = echo_ms, dwell = dwell_ms, diff --git a/src/node/bloom.rs b/src/node/bloom.rs index 3c6e154..8fb8bec 100644 --- a/src/node/bloom.rs +++ b/src/node/bloom.rs @@ -9,7 +9,7 @@ use crate::NodeAddr; use super::{Node, NodeError}; use std::collections::HashMap; -use tracing::{debug, info}; +use tracing::{debug, trace}; impl Node { /// Collect inbound filters from all peers for outgoing filter computation. @@ -77,7 +77,7 @@ impl Node { peer.clear_filter_update_needed(); } - debug!(peer = %peer_addr, seq = announce.sequence, "Sent FilterAnnounce"); + trace!(peer = %peer_addr, seq = announce.sequence, "Sent FilterAnnounce"); Ok(()) } @@ -161,7 +161,7 @@ impl Node { peer.update_filter(announce.filter, announce.sequence, now_ms); } - info!( + debug!( from = %from, seq = announce.sequence, "Received FilterAnnounce" diff --git a/src/node/handlers/mmp.rs b/src/node/handlers/mmp.rs index 72a8e91..76279ea 100644 --- a/src/node/handlers/mmp.rs +++ b/src/node/handlers/mmp.rs @@ -13,7 +13,7 @@ use crate::protocol::{ }; use crate::NodeAddr; use std::time::Instant; -use tracing::{debug, info, warn}; +use tracing::{debug, info, trace}; /// Format bytes/sec as human-readable throughput. fn format_throughput(bps: f64) -> String { @@ -55,7 +55,7 @@ impl Node { return; } - debug!( + trace!( from = %from, cum_pkts = sr.cumulative_packets_sent, interval_bytes = sr.interval_bytes_sent, @@ -116,7 +116,7 @@ impl Node { mmp.metrics.set_delivery_ratio_reverse(reverse_ratio); } - debug!( + trace!( from = %from, rtt_ms = ?mmp.metrics.srtt_ms(), loss = format_args!("{:.1}%", mmp.metrics.loss_rate() * 100.0), @@ -168,13 +168,13 @@ impl Node { // Send collected reports for (node_addr, encoded) in sender_reports { if let Err(e) = self.send_encrypted_link_message(&node_addr, &encoded).await { - warn!(peer = %node_addr, error = %e, "Failed to send SenderReport"); + debug!(peer = %node_addr, error = %e, "Failed to send SenderReport"); } } for (node_addr, encoded) in receiver_reports { if let Err(e) = self.send_encrypted_link_message(&node_addr, &encoded).await { - warn!(peer = %node_addr, error = %e, "Failed to send ReceiverReport"); + debug!(peer = %node_addr, error = %e, "Failed to send ReceiverReport"); } } } diff --git a/src/node/handlers/session.rs b/src/node/handlers/session.rs index 95ae64e..33d58f7 100644 --- a/src/node/handlers/session.rs +++ b/src/node/handlers/session.rs @@ -22,7 +22,7 @@ use crate::protocol::{ }; use crate::NodeAddr; use secp256k1::PublicKey; -use tracing::debug; +use tracing::{debug, info, trace}; impl Node { /// Handle a locally-delivered session datagram payload. @@ -160,7 +160,7 @@ impl Node { entry.set_coords_warmup_remaining(self.config.node.session.coords_warmup_packets); entry.mark_established(Self::now_ms()); entry.init_mmp(&self.config.node.session_mmp); - debug!(src = %src_addr, "Session established (responder, on first encrypted message)"); + info!(src = %src_addr, "Session established (responder, on first encrypted message)"); } // Decrypt with AAD = the 12-byte header @@ -235,7 +235,7 @@ impl Node { debug!(error = %e, "Failed to deliver decrypted packet to TUN"); } } else { - debug!( + trace!( src = %src_addr, "DataPacket decrypted (no TUN interface, plaintext dropped)" ); @@ -434,7 +434,7 @@ impl Node { // Flush any queued outbound packets for this destination self.flush_pending_packets(src_addr).await; - debug!(src = %src_addr, "Session established (initiator)"); + info!(src = %src_addr, "Session established (initiator)"); } // === Session-layer MMP report handlers === @@ -452,7 +452,7 @@ impl Node { } }; - debug!( + trace!( src = %src_addr, cum_pkts = sr.cumulative_packets_sent, interval_bytes = sr.interval_bytes_sent, @@ -519,7 +519,7 @@ impl Node { mmp.metrics.set_delivery_ratio_reverse(reverse_ratio); } - debug!( + trace!( src = %src_addr, rtt_ms = ?mmp.metrics.srtt_ms(), loss = format_args!("{:.1}%", mmp.metrics.loss_rate() * 100.0), @@ -703,7 +703,7 @@ impl Node { let entry = SessionEntry::new(dest_addr, dest_pubkey, EndToEndState::Initiating(handshake), now_ms, true); self.sessions.insert(dest_addr, entry); - debug!(dest = %dest_addr, "Session initiation started"); + info!(dest = %dest_addr, "Session initiation started"); Ok(()) } diff --git a/src/node/lifecycle.rs b/src/node/lifecycle.rs index 44f46f7..fa7c445 100644 --- a/src/node/lifecycle.rs +++ b/src/node/lifecycle.rs @@ -166,13 +166,13 @@ impl Node { .map(|a| format!(" ({})", a)) .unwrap_or_default(); - info!("Peer connection initiated{}", alias_display); - info!(" npub: {}", peer_config.npub); - info!(" node_addr: {}", peer_node_addr); - info!(" transport: {}", addr.transport); - info!(" addr: {}", addr.addr); - info!(" link_id: {}", link_id); - info!(" our_index: {}", our_index); + debug!("Peer connection initiated{}", alias_display); + debug!(" npub: {}", peer_config.npub); + debug!(" node_addr: {}", peer_node_addr); + debug!(" transport: {}", addr.transport); + debug!(" addr: {}", addr.addr); + debug!(" link_id: {}", link_id); + debug!(" our_index: {}", our_index); // Track in pending_outbound for msg2 dispatch self.pending_outbound.insert((transport_id, our_index.as_u32()), link_id); diff --git a/src/node/retry.rs b/src/node/retry.rs index afa8e58..bc1af66 100644 --- a/src/node/retry.rs +++ b/src/node/retry.rs @@ -79,7 +79,7 @@ impl Node { } let delay = state.backoff_ms(base_interval_ms, max_backoff_ms); state.retry_after_ms = now_ms + delay; - info!( + debug!( node_addr = %node_addr, retry = state.retry_count, delay_secs = delay / 1000, @@ -102,7 +102,7 @@ impl Node { state.retry_count = 1; let delay = state.backoff_ms(base_interval_ms, max_backoff_ms); state.retry_after_ms = now_ms + delay; - info!( + debug!( node_addr = %node_addr, delay_secs = delay / 1000, "First connection attempt failed, scheduling retry" @@ -144,7 +144,7 @@ impl Node { None => continue, }; - info!( + debug!( node_addr = %node_addr, retry = state.retry_count, "Attempting connection retry" diff --git a/src/node/tree.rs b/src/node/tree.rs index f93985d..52916d6 100644 --- a/src/node/tree.rs +++ b/src/node/tree.rs @@ -7,7 +7,7 @@ use crate::protocol::TreeAnnounce; use crate::NodeAddr; use super::{Node, NodeError}; -use tracing::{debug, info, warn}; +use tracing::{debug, info, trace, warn}; impl Node { /// Build a TreeAnnounce from our current tree state. @@ -68,7 +68,7 @@ impl Node { peer.record_tree_announce_sent(now_ms); } - debug!(peer = %peer_addr, "Sent TreeAnnounce"); + trace!(peer = %peer_addr, "Sent TreeAnnounce"); Ok(()) } diff --git a/src/transport/udp.rs b/src/transport/udp.rs index 4f0db94..2668122 100644 --- a/src/transport/udp.rs +++ b/src/transport/udp.rs @@ -11,7 +11,7 @@ use std::net::SocketAddr; use std::sync::Arc; use tokio::net::UdpSocket; use tokio::task::JoinHandle; -use tracing::{debug, info, warn}; +use tracing::{debug, info, trace, warn}; /// UDP transport for FIPS. /// @@ -149,7 +149,7 @@ impl UdpTransport { self.state = TransportState::Down; - debug!( + info!( transport_id = %self.transport_id, "UDP transport stopped" ); @@ -182,7 +182,7 @@ impl UdpTransport { .await .map_err(|e| TransportError::SendFailed(format!("{}", e)))?; - debug!( + trace!( transport_id = %self.transport_id, remote_addr = %socket_addr, bytes = bytes_sent, @@ -265,7 +265,7 @@ async fn udp_receive_loop( let addr = TransportAddr::from_string(&remote_addr.to_string()); let packet = ReceivedPacket::new(transport_id, addr, data); - debug!( + trace!( transport_id = %transport_id, remote_addr = %remote_addr, bytes = len, diff --git a/src/upper/tun.rs b/src/upper/tun.rs index d7a31d6..e973601 100644 --- a/src/upper/tun.rs +++ b/src/upper/tun.rs @@ -13,7 +13,7 @@ use std::net::Ipv6Addr; use std::os::unix::io::{AsRawFd, FromRawFd}; use std::sync::mpsc; use thiserror::Error; -use tracing::{debug, error, info}; +use tracing::{debug, error, info, trace}; use tun::Layer; /// Channel sender for packets to be written to TUN. @@ -222,7 +222,7 @@ impl TunWriter { for mut packet in self.rx { // Clamp TCP MSS on inbound SYN-ACK packets if clamp_tcp_mss(&mut packet, self.max_mss) { - debug!( + trace!( name = %self.name, max_mss = self.max_mss, "Clamped TCP MSS in inbound SYN-ACK packet" @@ -237,7 +237,7 @@ impl TunWriter { } error!(name = %self.name, error = %e, "TUN write error"); } else { - debug!(name = %self.name, len = packet.len(), "TUN packet written"); + trace!(name = %self.name, len = packet.len(), "TUN packet written"); } } } @@ -301,7 +301,7 @@ pub fn run_tun_reader( if packet[24] == crate::identity::FIPS_ADDRESS_PREFIX { // Clamp TCP MSS if this is a SYN packet if clamp_tcp_mss(packet, max_mss) { - debug!( + trace!( name = %name, max_mss = max_mss, "Clamped TCP MSS in SYN packet" @@ -321,7 +321,7 @@ pub fn run_tun_reader( our_addr.to_ipv6(), ) { - debug!( + trace!( name = %name, len = response.len(), "Sending ICMPv6 Destination Unreachable (non-FIPS destination)" @@ -347,7 +347,7 @@ pub fn run_tun_reader( } } -/// Log basic information about an IPv6 packet at DEBUG level. +/// Log basic information about an IPv6 packet at TRACE level. pub fn log_ipv6_packet(packet: &[u8]) { if packet.len() < 40 { debug!(len = packet.len(), "Received undersized packet"); @@ -374,11 +374,11 @@ pub fn log_ipv6_packet(packet: &[u8]) { _ => "other", }; - debug!("TUN packet received:"); - debug!(" src: {}", src); - debug!(" dst: {}", dst); - debug!(" protocol: {} ({})", protocol, next_header); - debug!(" payload: {} bytes, hop_limit: {}", payload_len, hop_limit); + trace!("TUN packet received:"); + trace!(" src: {}", src); + trace!(" dst: {}", dst); + trace!(" protocol: {} ({})", protocol, next_header); + trace!(" payload: {} bytes, hop_limit: {}", payload_len, hop_limit); } /// Shutdown and delete a TUN interface by name.