laantungir/fips
1
0
Fork 0
mirror of https://github.com/jmcorgan/fips.git synced 2026-07-30 19:46:15 +00:00
Code Issues Packages Projects Releases Wiki Activity

Human-readable peer identifiers in log messages

Browse Source 
Replace raw NodeAddr hex strings in log output with human-readable
identifiers using a four-tier lookup: configured alias, active peer
short npub, session endpoint short npub, or truncated hex fallback.

- Add PeerIdentity::short_npub() for compact npub display (npub1xxxx...yyyy)
- Add NodeAddr::short_hex() for compact hex fallback (first 4 bytes + ...)
- Add peer_aliases map populated at startup from peer config
- Add Node::peer_display_name() with four-tier resolution
- Add SessionEntry::remote_pubkey() accessor for session-layer lookups
- Update all 120 log field occurrences across 11 handler/node files
- Pass pre-computed display names to MMP static metric/teardown methods
  to work around borrow checker constraints in iterator loops
This commit is contained in:
Johnathan Corgan
2026-02-19 05:04:19 +00:00
parent ab7a4bac29
commit 9605cbafe3
15 changed files with 215 additions and 141 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/identity/node_addr.rs
+5
View File
@@ -51,6 +51,11 @@ impl NodeAddr {
pub fn as_slice(&self) -> &[u8] {
&self.0
}
/// Return a short hex representation: first 4 bytes + "...".
pub fn short_hex(&self) -> String {
format!("{}...", hex_encode(&self.0[..4]))
}
}
impl fmt::Debug for NodeAddr {
src/identity/peer.rs
+7
View File
@@ -78,6 +78,13 @@ impl PeerIdentity {
encode_npub(&self.pubkey)
}
/// Return a shortened npub for log display (e.g., `npub1abcd...wxyz`).
pub fn short_npub(&self) -> String {
let full = self.npub();
let data = &full[5..]; // strip "npub1"
format!("npub1{}...{}", &data[..4], &data[data.len() - 4..])
}
/// Return the node ID.
pub fn node_addr(&self) -> &NodeAddr {
&self.node_addr
src/node/bloom.rs
+8 -8
View File
@@ -77,7 +77,7 @@ impl Node {
peer.clear_filter_update_needed();
}
trace!(peer = %peer_addr, seq = announce.sequence, "Sent FilterAnnounce");
trace!(peer = %self.peer_display_name(peer_addr), seq = announce.sequence, "Sent FilterAnnounce");
Ok(())
}
@@ -98,7 +98,7 @@ impl Node {
for peer_addr in ready {
if let Err(e) = self.send_filter_announce_to_peer(&peer_addr).await {
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(&peer_addr),
error = %e,
"Failed to send pending FilterAnnounce"
);
@@ -116,18 +116,18 @@ impl Node {
let announce = match FilterAnnounce::decode(payload) {
Ok(a) => a,
Err(e) => {
debug!(from = %from, error = %e, "Malformed FilterAnnounce");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed FilterAnnounce");
return;
}
};
// Validate
if !announce.is_valid() {
debug!(from = %from, "FilterAnnounce filter/size_class mismatch");
debug!(from = %self.peer_display_name(from), "FilterAnnounce filter/size_class mismatch");
return;
}
if !announce.is_v1_compliant() {
debug!(from = %from, size_class = announce.size_class, "Non-v1 FilterAnnounce rejected");
debug!(from = %self.peer_display_name(from), size_class = announce.size_class, "Non-v1 FilterAnnounce rejected");
return;
}
@@ -135,7 +135,7 @@ impl Node {
let current_seq = match self.peers.get(from) {
Some(peer) => peer.filter_sequence(),
None => {
debug!(from = %from, "FilterAnnounce from unknown peer");
debug!(from = %self.peer_display_name(from), "FilterAnnounce from unknown peer");
return;
}
};
@@ -143,7 +143,7 @@ impl Node {
// Reject stale/replay
if announce.sequence <= current_seq {
debug!(
from = %from,
from = %self.peer_display_name(from),
received_seq = announce.sequence,
current_seq = current_seq,
"Stale FilterAnnounce rejected"
@@ -162,7 +162,7 @@ impl Node {
}
debug!(
from = %from,
from = %self.peer_display_name(from),
seq = announce.sequence,
"Received FilterAnnounce"
);
src/node/handlers/discovery.rs
+19 -19
View File
@@ -28,7 +28,7 @@ impl Node {
let request = match LookupRequest::decode(payload) {
Ok(req) => req,
Err(e) => {
debug!(from = %from, error = %e, "Malformed LookupRequest");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed LookupRequest");
return;
}
};
@@ -39,7 +39,7 @@ impl Node {
if self.recent_requests.contains_key(&request.request_id) {
trace!(
request_id = request.request_id,
from = %from,
from = %self.peer_display_name(from),
"Duplicate LookupRequest, dropping"
);
return;
@@ -58,7 +58,7 @@ impl Node {
if request.was_visited(self.node_addr()) {
trace!(
request_id = request.request_id,
target = %request.target,
target = %self.peer_display_name(&request.target),
"Already visited, dropping LookupRequest"
);
return;
@@ -68,7 +68,7 @@ impl Node {
if request.target == *self.node_addr() {
debug!(
request_id = request.request_id,
origin = %request.origin,
origin = %self.peer_display_name(&request.origin),
"We are the lookup target, generating response"
);
self.send_lookup_response(&request).await;
@@ -81,7 +81,7 @@ impl Node {
} else {
trace!(
request_id = request.request_id,
target = %request.target,
target = %self.peer_display_name(&request.target),
"LookupRequest TTL exhausted, not forwarding"
);
}
@@ -102,7 +102,7 @@ impl Node {
let response = match LookupResponse::decode(payload) {
Ok(resp) => resp,
Err(e) => {
debug!(from = %from, error = %e, "Malformed LookupResponse");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed LookupResponse");
return;
}
};
@@ -116,15 +116,15 @@ impl Node {
debug!(
request_id = response.request_id,
target = %response.target,
next_hop = %from_peer,
target = %self.peer_display_name(&response.target),
next_hop = %self.peer_display_name(&from_peer),
"Reverse-path forwarding LookupResponse"
);
let encoded = response.encode();
if let Err(e) = self.send_encrypted_link_message(&from_peer, &encoded).await {
debug!(
next_hop = %from_peer,
next_hop = %self.peer_display_name(&from_peer),
error = %e,
"Failed to forward LookupResponse"
);
@@ -133,7 +133,7 @@ impl Node {
// We originated this request — cache the discovered coordinates
debug!(
request_id = response.request_id,
target = %response.target,
target = %self.peer_display_name(&response.target),
depth = response.target_coords.depth(),
"Received LookupResponse, caching route"
);
@@ -158,7 +158,7 @@ impl Node {
let n = self.config.node.session.coords_warmup_packets;
entry.set_coords_warmup_remaining(n);
debug!(
dest = %target,
dest = %self.peer_display_name(&target),
warmup_packets = n,
"Reset coords warmup after discovery for existing session"
);
@@ -202,7 +202,7 @@ impl Node {
recent.from_peer
} else {
debug!(
origin = %request.origin,
origin = %self.peer_display_name(&request.origin),
"Cannot route LookupResponse: no path to origin"
);
return;
@@ -212,15 +212,15 @@ impl Node {
debug!(
request_id = request.request_id,
origin = %request.origin,
next_hop = %next_hop_addr,
origin = %self.peer_display_name(&request.origin),
next_hop = %self.peer_display_name(&next_hop_addr),
"Sending LookupResponse"
);
let encoded = response.encode();
if let Err(e) = self.send_encrypted_link_message(&next_hop_addr, &encoded).await {
debug!(
next_hop = %next_hop_addr,
next_hop = %self.peer_display_name(&next_hop_addr),
error = %e,
"Failed to send LookupResponse"
);
@@ -253,7 +253,7 @@ impl Node {
debug!(
request_id = request.request_id,
target = %request.target,
target = %self.peer_display_name(&request.target),
ttl = request.ttl,
peer_count = forward_to.len(),
"Forwarding LookupRequest"
@@ -264,7 +264,7 @@ impl Node {
for peer_addr in forward_to {
if let Err(e) = self.send_encrypted_link_message(&peer_addr, &encoded).await {
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(&peer_addr),
error = %e,
"Failed to forward LookupRequest to peer"
);
@@ -289,7 +289,7 @@ impl Node {
debug!(
request_id = request.request_id,
target = %target,
target = %self.peer_display_name(target),
ttl = ttl,
"Initiating LookupRequest"
);
@@ -301,7 +301,7 @@ impl Node {
for peer_addr in peer_addrs {
if let Err(e) = self.send_encrypted_link_message(&peer_addr, &encoded).await {
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(&peer_addr),
error = %e,
"Failed to send LookupRequest to peer"
);
src/node/handlers/dispatch.rs
+8 -5
View File
@@ -63,13 +63,13 @@ impl Node {
let disconnect = match crate::protocol::Disconnect::decode(payload) {
Ok(msg) => msg,
Err(e) => {
debug!(from = %from, error = %e, "Malformed disconnect message");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed disconnect message");
return;
}
};
info!(
node_addr = %from,
peer = %self.peer_display_name(from),
reason = %disconnect.reason,
"Peer sent disconnect notification"
);
@@ -89,14 +89,17 @@ impl Node {
let peer = match self.peers.remove(node_addr) {
Some(p) => p,
None => {
debug!(node_addr = %node_addr, "Peer already removed");
debug!(peer = %self.peer_display_name(node_addr), "Peer already removed");
return;
}
};
// MMP teardown log (before we drop the peer)
if let Some(mmp) = peer.mmp() {
Self::log_mmp_teardown(node_addr, mmp);
let name = self.peer_aliases.get(node_addr)
.cloned()
.unwrap_or_else(|| peer.identity().short_npub());
Self::log_mmp_teardown(&name, mmp);
}
let link_id = peer.link_id();
@@ -126,7 +129,7 @@ impl Node {
self.bloom_state.mark_all_updates_needed(remaining_peers);
info!(
node_addr = %node_addr,
peer = %self.peer_display_name(node_addr),
link_id = %link_id,
tree_changed = tree_changed,
"Peer removed and state cleaned up"
src/node/handlers/encrypted.rs
+3 -3
View File
@@ -47,7 +47,7 @@ impl Node {
Some(s) => s,
None => {
warn!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
"Peer in index map has no session"
);
return;
@@ -64,7 +64,7 @@ impl Node {
Ok(p) => p,
Err(e) => {
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
counter = header.counter,
error = %e,
"Decryption failed"
@@ -80,7 +80,7 @@ impl Node {
Some(parts) => parts,
None => {
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
len = plaintext.len(),
"Decrypted payload too short for inner header"
);
src/node/handlers/handshake.rs
+17 -17
View File
@@ -165,14 +165,14 @@ impl Node {
match result {
PromotionResult::Promoted(node_addr) => {
info!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
link_id = %link_id,
our_index = %our_index,
"Inbound peer promoted to active"
);
// Send initial tree announce to new peer
if let Err(e) = self.send_tree_announce_to_peer(&node_addr).await {
debug!(peer = %node_addr, error = %e, "Failed to send initial TreeAnnounce");
debug!(peer = %self.peer_display_name(&node_addr), error = %e, "Failed to send initial TreeAnnounce");
}
// Schedule filter announce (sent on next tick via debounce)
self.bloom_state.mark_update_needed(node_addr);
@@ -181,13 +181,13 @@ impl Node {
// Clean up the losing connection's link
self.remove_link(&loser_link_id);
info!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
loser_link_id = %loser_link_id,
"Inbound cross-connection won, loser link cleaned up"
);
// Send initial tree announce to peer (new or reconnected)
if let Err(e) = self.send_tree_announce_to_peer(&node_addr).await {
debug!(peer = %node_addr, error = %e, "Failed to send initial TreeAnnounce");
debug!(peer = %self.peer_display_name(&node_addr), error = %e, "Failed to send initial TreeAnnounce");
}
// Schedule filter announce (sent on next tick via debounce)
self.bloom_state.mark_update_needed(node_addr);
@@ -285,7 +285,7 @@ impl Node {
let peer_node_addr = *peer_identity.node_addr();
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
link_id = %link_id,
their_index = %header.sender_idx,
"Outbound handshake completed"
@@ -327,7 +327,7 @@ impl Node {
match (outbound_session, outbound_our_index) {
(Some(s), Some(idx)) => (s, idx),
_ => {
warn!(node_addr = %peer_node_addr, "Incomplete outbound connection");
warn!(peer = %self.peer_display_name(&peer_node_addr), "Incomplete outbound connection");
self.pending_outbound.remove(&key);
return;
}
@@ -352,7 +352,7 @@ impl Node {
);
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
new_our_index = %outbound_our_index,
new_their_index = %header.sender_idx,
"Cross-connection: swapped to outbound session (our outbound wins)"
@@ -372,7 +372,7 @@ impl Node {
if let Some(peer) = self.peers.get(&peer_node_addr) {
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
kept_their_index = ?peer.their_index(),
"Cross-connection: keeping inbound session and original their_index (peer outbound wins)"
);
@@ -390,7 +390,7 @@ impl Node {
// Send TreeAnnounce now that sessions are aligned
if let Err(e) = self.send_tree_announce_to_peer(&peer_node_addr).await {
debug!(peer = %peer_node_addr, error = %e, "Failed to send TreeAnnounce after cross-connection resolution");
debug!(peer = %self.peer_display_name(&peer_node_addr), error = %e, "Failed to send TreeAnnounce after cross-connection resolution");
}
// Schedule filter announce (sent on next tick via debounce)
self.bloom_state.mark_update_needed(peer_node_addr);
@@ -406,12 +406,12 @@ impl Node {
match result {
PromotionResult::Promoted(node_addr) => {
info!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
"Peer promoted to active"
);
// Send initial tree announce to new peer
if let Err(e) = self.send_tree_announce_to_peer(&node_addr).await {
debug!(peer = %node_addr, error = %e, "Failed to send initial TreeAnnounce");
debug!(peer = %self.peer_display_name(&node_addr), error = %e, "Failed to send initial TreeAnnounce");
}
// Schedule filter announce (sent on next tick via debounce)
self.bloom_state.mark_update_needed(node_addr);
@@ -425,13 +425,13 @@ impl Node {
link_id,
);
info!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
loser_link_id = %loser_link_id,
"Outbound cross-connection won, loser link cleaned up"
);
// Send initial tree announce to peer (new or reconnected)
if let Err(e) = self.send_tree_announce_to_peer(&node_addr).await {
debug!(peer = %node_addr, error = %e, "Failed to send initial TreeAnnounce");
debug!(peer = %self.peer_display_name(&node_addr), error = %e, "Failed to send initial TreeAnnounce");
}
// Schedule filter announce (sent on next tick via debounce)
self.bloom_state.mark_update_needed(node_addr);
@@ -561,7 +561,7 @@ impl Node {
self.register_identity(peer_node_addr, verified_identity.pubkey_full());
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
winner_link = %link_id,
loser_link = %loser_link_id,
"Cross-connection resolved: this connection won"
@@ -577,7 +577,7 @@ impl Node {
let _ = self.index_allocator.free(our_index);
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
winner_link = %existing_link_id,
loser_link = %link_id,
"Cross-connection resolved: this connection lost"
@@ -608,7 +608,7 @@ impl Node {
for pending_link_id in &pending_to_same_peer {
debug!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
pending_link_id = %pending_link_id,
promoted_link_id = %link_id,
"Deferring cleanup of pending outbound (awaiting msg2 for index update)"
@@ -643,7 +643,7 @@ impl Node {
self.register_identity(peer_node_addr, verified_identity.pubkey_full());
info!(
node_addr = %peer_node_addr,
peer = %self.peer_display_name(&peer_node_addr),
link_id = %link_id,
our_index = %our_index,
their_index = %their_index,
src/node/handlers/mmp.rs
+36 -21
View File
@@ -38,7 +38,7 @@ impl Node {
let sr = match SenderReport::decode(payload) {
Ok(sr) => sr,
Err(e) => {
debug!(from = %from, error = %e, "Malformed SenderReport");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed SenderReport");
return;
}
};
@@ -46,7 +46,7 @@ impl Node {
let peer = match self.peers.get_mut(from) {
Some(p) => p,
None => {
debug!(from = %from, "SenderReport from unknown peer");
debug!(from = %self.peer_display_name(from), "SenderReport from unknown peer");
return;
}
};
@@ -56,7 +56,7 @@ impl Node {
}
trace!(
from = %from,
from = %self.peer_display_name(from),
cum_pkts = sr.cumulative_packets_sent,
interval_bytes = sr.interval_bytes_sent,
"Received SenderReport"
@@ -75,15 +75,17 @@ impl Node {
let rr = match ReceiverReport::decode(payload) {
Ok(rr) => rr,
Err(e) => {
debug!(from = %from, error = %e, "Malformed ReceiverReport");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed ReceiverReport");
return;
}
};
let peer_name = self.peer_display_name(from);
let peer = match self.peers.get_mut(from) {
Some(p) => p,
None => {
debug!(from = %from, "ReceiverReport from unknown peer");
debug!(from = %peer_name, "ReceiverReport from unknown peer");
return;
}
};
@@ -117,7 +119,7 @@ impl Node {
}
trace!(
from = %from,
from = %peer_name,
rtt_ms = ?mmp.metrics.srtt_ms(),
loss = format_args!("{:.1}%", mmp.metrics.loss_rate() * 100.0),
etx = format_args!("{:.2}", mmp.metrics.etx),
@@ -136,6 +138,11 @@ impl Node {
let mut receiver_reports: Vec<(NodeAddr, Vec<u8>)> = Vec::new();
for (node_addr, peer) in self.peers.iter_mut() {
// Compute display name before taking mutable MMP borrow
let peer_name = self.peer_aliases.get(node_addr)
.cloned()
.unwrap_or_else(|| peer.identity().short_npub());
let Some(mmp) = peer.mmp_mut() else {
continue;
};
@@ -160,7 +167,7 @@ impl Node {
// Periodic operator logging
if mmp.should_log(now) {
Self::log_mmp_metrics(node_addr, mmp);
Self::log_mmp_metrics(&peer_name, mmp);
mmp.mark_logged(now);
}
}
@@ -168,19 +175,19 @@ 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 {
debug!(peer = %node_addr, error = %e, "Failed to send SenderReport");
debug!(peer = %self.peer_display_name(&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 {
debug!(peer = %node_addr, error = %e, "Failed to send ReceiverReport");
debug!(peer = %self.peer_display_name(&node_addr), error = %e, "Failed to send ReceiverReport");
}
}
}
/// Emit periodic MMP metrics for a peer at info and debug levels.
fn log_mmp_metrics(node_addr: &NodeAddr, mmp: &crate::mmp::MmpPeerState) {
fn log_mmp_metrics(peer_name: &str, mmp: &crate::mmp::MmpPeerState) {
let m = &mmp.metrics;
let rtt_str = match m.srtt_ms() {
@@ -196,7 +203,7 @@ impl Node {
// Info-level: concise summary
info!(
peer = %node_addr,
peer = %peer_name,
rtt = %rtt_str,
loss = format_args!("{:.1}%", loss_pct),
goodput = %goodput_str,
@@ -207,7 +214,7 @@ impl Node {
// Debug-level: extended details
debug!(
peer = %node_addr,
peer = %peer_name,
jitter_us = mmp.receiver.jitter_us(),
reorder = mmp.receiver.cumulative_packets_recv(),
rtt_trend = format_args!("{}", if m.rtt_trend.initialized() {
@@ -228,7 +235,7 @@ impl Node {
}
/// Emit a teardown log summarizing lifetime MMP metrics for a removed peer.
pub(in crate::node) fn log_mmp_teardown(node_addr: &NodeAddr, mmp: &crate::mmp::MmpPeerState) {
pub(in crate::node) fn log_mmp_teardown(peer_name: &str, mmp: &crate::mmp::MmpPeerState) {
let m = &mmp.metrics;
let rtt_str = match m.srtt_ms() {
@@ -237,7 +244,7 @@ impl Node {
};
info!(
peer = %node_addr,
peer = %peer_name,
rtt = %rtt_str,
loss = format_args!("{:.1}%", m.loss_rate() * 100.0),
etx = format_args!("{:.2}", m.etx),
@@ -263,6 +270,14 @@ impl Node {
let mut reports: Vec<(NodeAddr, u8, Vec<u8>)> = Vec::new();
for (dest_addr, entry) in self.sessions.iter_mut() {
// Compute display name before taking mutable MMP borrow
let session_name = self.peer_aliases.get(dest_addr)
.cloned()
.unwrap_or_else(|| {
let (xonly, _) = entry.remote_pubkey().x_only_public_key();
crate::PeerIdentity::from_pubkey(xonly).short_npub()
});
let Some(mmp) = entry.mmp_mut() else {
continue;
};
@@ -309,7 +324,7 @@ impl Node {
// Periodic operator logging
if mmp.should_log(now) {
Self::log_session_mmp_metrics(dest_addr, mmp);
Self::log_session_mmp_metrics(&session_name, mmp);
mmp.mark_logged(now);
}
}
@@ -318,7 +333,7 @@ impl Node {
for (dest_addr, msg_type, body) in reports {
if let Err(e) = self.send_session_msg(&dest_addr, msg_type, &body).await {
debug!(
dest = %dest_addr,
dest = %self.peer_display_name(&dest_addr),
msg_type,
error = %e,
"Failed to send session MMP report"
@@ -328,7 +343,7 @@ impl Node {
}
/// Emit periodic session MMP metrics at info and debug levels.
fn log_session_mmp_metrics(dest_addr: &NodeAddr, mmp: &MmpSessionState) {
fn log_session_mmp_metrics(session_name: &str, mmp: &MmpSessionState) {
let m = &mmp.metrics;
let rtt_str = match m.srtt_ms() {
@@ -343,7 +358,7 @@ impl Node {
let observed_mtu = mmp.path_mtu.last_observed_mtu();
info!(
session = %dest_addr,
session = %session_name,
rtt = %rtt_str,
loss = format_args!("{:.1}%", loss_pct),
goodput = %goodput_str,
@@ -355,7 +370,7 @@ impl Node {
);
debug!(
session = %dest_addr,
session = %session_name,
jitter_us = mmp.receiver.jitter_us(),
rtt_trend = format_args!("{}", if m.rtt_trend.initialized() {
format!("short={:.1} long={:.1}", m.rtt_trend.short(), m.rtt_trend.long())
@@ -375,7 +390,7 @@ impl Node {
}
/// Emit a teardown log summarizing lifetime session MMP metrics.
pub(in crate::node) fn log_session_mmp_teardown(dest_addr: &NodeAddr, mmp: &MmpSessionState) {
pub(in crate::node) fn log_session_mmp_teardown(session_name: &str, mmp: &MmpSessionState) {
let m = &mmp.metrics;
let rtt_str = match m.srtt_ms() {
@@ -384,7 +399,7 @@ impl Node {
};
info!(
session = %dest_addr,
session = %session_name,
rtt = %rtt_str,
loss = format_args!("{:.1}%", m.loss_rate() * 100.0),
etx = format_args!("{:.2}", m.etx),
src/node/handlers/session.rs
+34 -32
View File
@@ -135,7 +135,7 @@ impl Node {
let mut entry = match self.sessions.remove(src_addr) {
Some(e) => e,
None => {
debug!(src = %src_addr, "Encrypted session message for unknown session");
debug!(src = %self.peer_display_name(src_addr), "Encrypted session message for unknown session");
return;
}
};
@@ -145,7 +145,7 @@ impl Node {
let handshake = match old_state {
Some(EndToEndState::Responding(hs)) => hs,
_ => {
debug!(src = %src_addr, "Unexpected state during Responding transition");
debug!(src = %self.peer_display_name(src_addr), "Unexpected state during Responding transition");
return;
}
};
@@ -160,14 +160,14 @@ 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);
info!(src = %src_addr, "Session established (responder, on first encrypted message)");
info!(src = %self.peer_display_name(src_addr), "Session established (responder, on first encrypted message)");
}
// Decrypt with AAD = the 12-byte header
let session = match entry.state_mut() {
EndToEndState::Established(s) => s,
_ => {
debug!(src = %src_addr, "Encrypted message but session not established");
debug!(src = %self.peer_display_name(src_addr), "Encrypted message but session not established");
self.sessions.insert(*src_addr, entry);
return;
}
@@ -181,7 +181,7 @@ impl Node {
Ok(pt) => pt,
Err(e) => {
debug!(
error = %e, src = %src_addr, counter = header.counter,
error = %e, src = %self.peer_display_name(src_addr), counter = header.counter,
"Session AEAD decryption failed"
);
self.sessions.insert(*src_addr, entry);
@@ -195,7 +195,7 @@ impl Node {
let (timestamp, msg_type, inner_flags_byte, rest) = match fsp_strip_inner_header(&plaintext) {
Some(parts) => parts,
None => {
debug!(src = %src_addr, "Decrypted payload too short for FSP inner header");
debug!(src = %self.peer_display_name(src_addr), "Decrypted payload too short for FSP inner header");
return;
}
};
@@ -236,7 +236,7 @@ impl Node {
}
} else {
trace!(
src = %src_addr,
src = %self.peer_display_name(src_addr),
"DataPacket decrypted (no TUN interface, plaintext dropped)"
);
}
@@ -251,7 +251,7 @@ impl Node {
self.handle_session_path_mtu_notification(src_addr, rest);
}
_ => {
debug!(src = %src_addr, msg_type, "Unknown session message type, dropping");
debug!(src = %self.peer_display_name(src_addr), msg_type, "Unknown session message type, dropping");
}
}
@@ -298,25 +298,25 @@ impl Node {
if self.identity.node_addr() < src_addr {
// We win — drop their setup, they'll process ours
debug!(
src = %src_addr,
src = %self.peer_display_name(src_addr),
"Simultaneous session initiation: we win (smaller addr), dropping their setup"
);
return;
}
// We lose — discard our pending handshake, become responder below
debug!(
src = %src_addr,
src = %self.peer_display_name(src_addr),
"Simultaneous session initiation: we lose, becoming responder"
);
}
EndToEndState::Responding(_) => {
// Duplicate setup while we already responded — drop
debug!(src = %src_addr, "Duplicate SessionSetup, already responding");
debug!(src = %self.peer_display_name(src_addr), "Duplicate SessionSetup, already responding");
return;
}
EndToEndState::Established(_) => {
// Re-establishment: replace existing session below
debug!(src = %src_addr, "Session re-establishment from peer");
debug!(src = %self.peer_display_name(src_addr), "Session re-establishment from peer");
}
}
}
@@ -360,7 +360,7 @@ impl Node {
// Route the ack back to the initiator
if let Err(e) = self.send_session_datagram(&mut datagram).await {
debug!(error = %e, dest = %src_addr, "Failed to send SessionAck");
debug!(error = %e, dest = %self.peer_display_name(src_addr), "Failed to send SessionAck");
return;
}
@@ -369,7 +369,7 @@ impl Node {
let entry = SessionEntry::new(*src_addr, remote_pubkey, EndToEndState::Responding(handshake), now_ms, false);
self.sessions.insert(*src_addr, entry);
debug!(src = %src_addr, "SessionSetup processed, SessionAck sent");
debug!(src = %self.peer_display_name(src_addr), "SessionSetup processed, SessionAck sent");
}
/// Handle an incoming SessionAck (Noise IK msg2).
@@ -397,7 +397,7 @@ impl Node {
let mut entry = match self.sessions.remove(src_addr) {
Some(e) => e,
None => {
debug!(src = %src_addr, "SessionAck for unknown session");
debug!(src = %self.peer_display_name(src_addr), "SessionAck for unknown session");
return;
}
};
@@ -406,7 +406,7 @@ impl Node {
let handshake = match entry.take_state() {
Some(EndToEndState::Initiating(hs)) => hs,
_ => {
debug!(src = %src_addr, "SessionAck but session not in Initiating state");
debug!(src = %self.peer_display_name(src_addr), "SessionAck but session not in Initiating state");
// Put it back
self.sessions.insert(*src_addr, entry);
return;
@@ -434,7 +434,7 @@ impl Node {
// Flush any queued outbound packets for this destination
self.flush_pending_packets(src_addr).await;
info!(src = %src_addr, "Session established (initiator)");
info!(src = %self.peer_display_name(src_addr), "Session established (initiator)");
}
// === Session-layer MMP report handlers ===
@@ -447,13 +447,13 @@ impl Node {
let sr = match SessionSenderReport::decode(body) {
Ok(sr) => sr,
Err(e) => {
debug!(src = %src_addr, error = %e, "Malformed SessionSenderReport");
debug!(src = %self.peer_display_name(src_addr), error = %e, "Malformed SessionSenderReport");
return;
}
};
trace!(
src = %src_addr,
src = %self.peer_display_name(src_addr),
cum_pkts = sr.cumulative_packets_sent,
interval_bytes = sr.interval_bytes_sent,
"Received SessionSenderReport"
@@ -468,7 +468,7 @@ impl Node {
let session_rr = match SessionReceiverReport::decode(body) {
Ok(rr) => rr,
Err(e) => {
debug!(src = %src_addr, error = %e, "Malformed SessionReceiverReport");
debug!(src = %self.peer_display_name(src_addr), error = %e, "Malformed SessionReceiverReport");
return;
}
};
@@ -477,10 +477,11 @@ impl Node {
let rr: ReceiverReport = ReceiverReport::from(&session_rr);
let now_ms = Self::now_ms();
let peer_name = self.peer_display_name(src_addr);
let entry = match self.sessions.get_mut(src_addr) {
Some(e) => e,
None => {
debug!(src = %src_addr, "SessionReceiverReport for unknown session");
debug!(src = %peer_name, "SessionReceiverReport for unknown session");
return;
}
};
@@ -520,7 +521,7 @@ impl Node {
}
trace!(
src = %src_addr,
src = %peer_name,
rtt_ms = ?mmp.metrics.srtt_ms(),
loss = format_args!("{:.1}%", mmp.metrics.loss_rate() * 100.0),
"Processed SessionReceiverReport"
@@ -535,15 +536,16 @@ impl Node {
let notif = match PathMtuNotification::decode(body) {
Ok(n) => n,
Err(e) => {
debug!(src = %src_addr, error = %e, "Malformed PathMtuNotification");
debug!(src = %self.peer_display_name(src_addr), error = %e, "Malformed PathMtuNotification");
return;
}
};
let peer_name = self.peer_display_name(src_addr);
let entry = match self.sessions.get_mut(src_addr) {
Some(e) => e,
None => {
debug!(src = %src_addr, "PathMtuNotification for unknown session");
debug!(src = %peer_name, "PathMtuNotification for unknown session");
return;
}
};
@@ -559,7 +561,7 @@ impl Node {
if new_mtu != old_mtu {
debug!(
src = %src_addr,
src = %peer_name,
old_mtu,
new_mtu,
"Path MTU changed via notification"
@@ -703,7 +705,7 @@ impl Node {
let entry = SessionEntry::new(dest_addr, dest_pubkey, EndToEndState::Initiating(handshake), now_ms, true);
self.sessions.insert(dest_addr, entry);
info!(dest = %dest_addr, "Session initiation started");
info!(dest = %self.peer_display_name(&dest_addr), "Session initiation started");
Ok(())
}
@@ -977,7 +979,7 @@ impl Node {
if let Some(entry) = self.sessions.get(&dest_addr) {
if entry.is_established() {
if let Err(e) = self.send_session_data(&dest_addr, &ipv6_packet).await {
debug!(dest = %dest_addr, error = %e, "Failed to send TUN packet via session");
debug!(dest = %self.peer_display_name(&dest_addr), error = %e, "Failed to send TUN packet via session");
}
return;
}
@@ -990,7 +992,7 @@ impl Node {
// If session initiation fails (no route), trigger discovery and
// queue the packet for retry when discovery completes.
if let Err(e) = self.initiate_session(dest_addr, dest_pubkey).await {
debug!(dest = %dest_addr, error = %e, "Failed to initiate session, trying discovery");
debug!(dest = %self.peer_display_name(&dest_addr), error = %e, "Failed to initiate session, trying discovery");
self.maybe_initiate_lookup(&dest_addr).await;
self.queue_pending_packet(dest_addr, ipv6_packet);
return;
@@ -1086,7 +1088,7 @@ impl Node {
};
for packet in packets {
if let Err(e) = self.send_session_data(dest_addr, &packet).await {
debug!(dest = %dest_addr, error = %e, "Failed to send queued TUN packet");
debug!(dest = %self.peer_display_name(dest_addr), error = %e, "Failed to send queued TUN packet");
break;
}
}
@@ -1104,7 +1106,7 @@ impl Node {
let dest_pubkey = match self.lookup_by_fips_prefix(&prefix) {
Some((_, pk)) => pk,
None => {
debug!(dest = %dest_addr, "Discovery complete but no identity for session retry");
debug!(dest = %self.peer_display_name(&dest_addr), "Discovery complete but no identity for session retry");
return;
}
};
@@ -1118,10 +1120,10 @@ impl Node {
match self.initiate_session(dest_addr, dest_pubkey).await {
Ok(()) => {
debug!(dest = %dest_addr, "Session initiated after discovery");
debug!(dest = %self.peer_display_name(&dest_addr), "Session initiated after discovery");
}
Err(e) => {
debug!(dest = %dest_addr, error = %e, "Session retry after discovery failed");
debug!(dest = %self.peer_display_name(&dest_addr), error = %e, "Session retry after discovery failed");
}
}
}
src/node/handlers/timeout.rs
+5 -2
View File
@@ -98,16 +98,19 @@ impl Node {
.collect();
for addr in idle {
// Compute display name before removing the session
let name = self.peer_display_name(&addr);
// Log MMP teardown metrics before removing the session
if let Some(entry) = self.sessions.get(&addr)
&& let Some(mmp) = entry.mmp()
{
Self::log_session_mmp_teardown(&addr, mmp);
Self::log_session_mmp_teardown(&name, mmp);
}
self.sessions.remove(&addr);
self.pending_tun_packets.remove(&addr);
debug!(
dest = %addr,
dest = %name,
idle_secs = timeout_ms / 1000,
"Idle session removed (no application data)"
);
src/node/lifecycle.rs
+20 -14
View File
@@ -17,6 +17,17 @@ impl Node {
/// For each peer configured with AutoConnect policy, creates a link and
/// peer entry, then starts the Noise handshake by sending the first message.
pub(super) async fn initiate_peer_connections(&mut self) {
// Build display name map from all configured peers (alias or short npub)
for peer_config in self.config.peers() {
if let Ok(identity) = PeerIdentity::from_npub(&peer_config.npub) {
let name = peer_config
.alias
.clone()
.unwrap_or_else(|| identity.short_npub());
self.peer_aliases.insert(*identity.node_addr(), name);
}
}
// Collect peer configs to avoid borrow conflicts
let peer_configs: Vec<_> = self.config.auto_connect_peers().cloned().collect();
@@ -160,19 +171,14 @@ impl Node {
// Build wire format msg1: [0x01][sender_idx:4 LE][noise_msg1:82]
let wire_msg1 = build_msg1(our_index, &noise_msg1);
let alias_display = peer_config
.alias
.as_deref()
.map(|a| format!(" ({})", a))
.unwrap_or_default();
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);
debug!(
peer = %self.peer_display_name(&peer_node_addr),
transport = %addr.transport,
addr = %addr.addr,
link_id = %link_id,
our_index = %our_index,
"Peer connection initiated"
);
// Track in pending_outbound for msg2 dispatch
self.pending_outbound.insert((transport_id, our_index.as_u32()), link_id);
@@ -447,7 +453,7 @@ impl Node {
Ok(()) => sent += 1,
Err(e) => {
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(node_addr),
error = %e,
"Failed to send disconnect (transport may be down)"
);
src/node/mod.rs
+29 -1
View File
@@ -32,7 +32,7 @@ use crate::tree::TreeState;
use crate::upper::icmp_rate_limit::IcmpRateLimiter;
use crate::upper::tun::{TunError, TunOutboundRx, TunState, TunTx};
use self::wire::{build_encrypted, build_established_header, prepend_inner_header, FLAG_SP};
use crate::{Config, ConfigError, Identity, IdentityError, NodeAddr};
use crate::{Config, ConfigError, Identity, IdentityError, NodeAddr, PeerIdentity};
use std::collections::{HashMap, VecDeque};
use std::fmt;
use std::thread::JoinHandle;
@@ -326,6 +326,11 @@ pub struct Node {
/// or fails, and removed on successful promotion or when max retries
/// are exhausted.
retry_pending: HashMap<NodeAddr, retry::RetryState>,
// === Display Names ===
/// Human-readable names for configured peers (alias or short npub).
/// Populated at startup from peer config.
peer_aliases: HashMap<NodeAddr, String>,
}
impl Node {
@@ -409,6 +414,7 @@ impl Node {
icmp_rate_limiter: IcmpRateLimiter::new(),
routing_error_rate_limiter: RoutingErrorRateLimiter::new(),
retry_pending: HashMap::new(),
peer_aliases: HashMap::new(),
})
}
@@ -485,6 +491,7 @@ impl Node {
icmp_rate_limiter: IcmpRateLimiter::new(),
routing_error_rate_limiter: RoutingErrorRateLimiter::new(),
retry_pending: HashMap::new(),
peer_aliases: HashMap::new(),
}
}
@@ -551,6 +558,27 @@ impl Node {
self.identity.npub()
}
/// Return a human-readable display name for a NodeAddr.
///
/// Lookup order:
/// 1. Configured peer alias or short npub (from startup map)
/// 2. Active peer's short npub (e.g., inbound peer not in config)
/// 3. Session endpoint's short npub (end-to-end, may not be direct peer)
/// 4. Truncated NodeAddr hex (unknown address)
pub(crate) fn peer_display_name(&self, addr: &NodeAddr) -> String {
if let Some(name) = self.peer_aliases.get(addr) {
return name.clone();
}
if let Some(peer) = self.peers.get(addr) {
return peer.identity().short_npub();
}
if let Some(entry) = self.sessions.get(addr) {
let (xonly, _) = entry.remote_pubkey().x_only_public_key();
return PeerIdentity::from_pubkey(xonly).short_npub();
}
addr.short_hex()
}
// === Configuration ===
/// Get the configuration.
src/node/retry.rs
+7 -6
View File
@@ -64,13 +64,14 @@ impl Node {
let base_interval_ms = retry_cfg.base_interval_secs * 1000;
let max_backoff_ms = retry_cfg.max_backoff_secs * 1000;
let peer_name = self.peer_display_name(&node_addr);
if let Some(state) = self.retry_pending.get_mut(&node_addr) {
// Already tracking — increment
state.retry_count += 1;
if state.retry_count > max_retries {
info!(
node_addr = %node_addr,
peer = %peer_name,
attempts = state.retry_count,
"Max retries exhausted, giving up on peer"
);
@@ -80,7 +81,7 @@ impl Node {
let delay = state.backoff_ms(base_interval_ms, max_backoff_ms);
state.retry_after_ms = now_ms + delay;
debug!(
node_addr = %node_addr,
peer = %peer_name,
retry = state.retry_count,
delay_secs = delay / 1000,
"Scheduling connection retry"
@@ -103,7 +104,7 @@ impl Node {
let delay = state.backoff_ms(base_interval_ms, max_backoff_ms);
state.retry_after_ms = now_ms + delay;
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
delay_secs = delay / 1000,
"First connection attempt failed, scheduling retry"
);
@@ -145,7 +146,7 @@ impl Node {
};
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
retry = state.retry_count,
"Attempting connection retry"
);
@@ -155,7 +156,7 @@ impl Node {
match self.initiate_peer_connection(&peer_config).await {
Ok(()) => {
debug!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
"Retry connection initiated"
);
// Don't remove from retry_pending — wait for promotion
@@ -163,7 +164,7 @@ impl Node {
}
Err(e) => {
warn!(
node_addr = %node_addr,
peer = %self.peer_display_name(&node_addr),
error = %e,
"Retry connection initiation failed"
);
src/node/session.rs
+5 -1
View File
@@ -47,7 +47,6 @@ pub(crate) struct SessionEntry {
#[allow(dead_code)]
remote_addr: NodeAddr,
/// Remote node's static public key (for Noise IK).
#[allow(dead_code)]
remote_pubkey: PublicKey,
/// Current session state. `None` only during state transitions.
state: Option<EndToEndState>,
@@ -95,6 +94,11 @@ impl SessionEntry {
}
}
/// Get the remote node's public key.
pub(crate) fn remote_pubkey(&self) -> &PublicKey {
&self.remote_pubkey
}
/// Get the current session state.
pub(crate) fn state(&self) -> &EndToEndState {
self.state.as_ref().expect("session state taken but not restored")
src/node/tree.rs
+12 -12
View File
@@ -47,7 +47,7 @@ impl Node {
if !peer.can_send_tree_announce(now_ms) {
peer.mark_tree_announce_pending();
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(peer_addr),
"TreeAnnounce rate-limited, marking pending"
);
return Ok(());
@@ -68,7 +68,7 @@ impl Node {
peer.record_tree_announce_sent(now_ms);
}
trace!(peer = %peer_addr, "Sent TreeAnnounce");
trace!(peer = %self.peer_display_name(peer_addr), "Sent TreeAnnounce");
Ok(())
}
@@ -79,7 +79,7 @@ impl Node {
for peer_addr in peer_addrs {
if let Err(e) = self.send_tree_announce_to_peer(&peer_addr).await {
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(&peer_addr),
error = %e,
"Failed to send TreeAnnounce"
);
@@ -104,7 +104,7 @@ impl Node {
for peer_addr in ready {
if let Err(e) = self.send_tree_announce_to_peer(&peer_addr).await {
debug!(
peer = %peer_addr,
peer = %self.peer_display_name(&peer_addr),
error = %e,
"Failed to send pending TreeAnnounce"
);
@@ -123,7 +123,7 @@ impl Node {
let announce = match TreeAnnounce::decode(payload) {
Ok(a) => a,
Err(e) => {
debug!(from = %from, error = %e, "Malformed TreeAnnounce");
debug!(from = %self.peer_display_name(from), error = %e, "Malformed TreeAnnounce");
return;
}
};
@@ -132,7 +132,7 @@ impl Node {
let pubkey = match self.peers.get(from) {
Some(peer) => peer.pubkey(),
None => {
debug!(from = %from, "TreeAnnounce from unknown peer");
debug!(from = %self.peer_display_name(from), "TreeAnnounce from unknown peer");
return;
}
};
@@ -140,7 +140,7 @@ impl Node {
// The declaring node_addr in the announce should match the sender
if announce.declaration.node_addr() != from {
debug!(
from = %from,
from = %self.peer_display_name(from),
declared = %announce.declaration.node_addr(),
"TreeAnnounce node_addr mismatch"
);
@@ -149,7 +149,7 @@ impl Node {
if let Err(e) = announce.declaration.verify(&pubkey) {
warn!(
from = %from,
from = %self.peer_display_name(from),
error = %e,
"TreeAnnounce signature verification failed"
);
@@ -177,12 +177,12 @@ impl Node {
);
if !updated {
debug!(from = %from, "TreeAnnounce not fresher than existing, ignored");
debug!(from = %self.peer_display_name(from), "TreeAnnounce not fresher than existing, ignored");
return;
}
info!(
from = %from,
from = %self.peer_display_name(from),
seq = announce.declaration.sequence(),
depth = announce.ancestry.depth(),
root = %announce.ancestry.root_id(),
@@ -206,7 +206,7 @@ impl Node {
self.coord_cache.clear();
info!(
new_parent = %new_parent,
new_parent = %self.peer_display_name(&new_parent),
new_seq = new_seq,
new_root = %self.tree_state.root(),
depth = self.tree_state.my_coords().depth(),
@@ -242,7 +242,7 @@ impl Node {
if new_root != old_root || new_depth != old_depth {
info!(
parent = %from,
parent = %self.peer_display_name(from),
old_root = %old_root,
new_root = %new_root,
new_depth = new_depth,