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

Demote 35 info-level log messages to debug for cleaner production output

Browse Source 
Reduce info-level noise by moving intermediate steps, periodic
telemetry, cross-connection resolution details, and redundant messages
to debug. Info output now focuses on operator-relevant state changes:
lifecycle events, peer promotions, session establishment, parent
switches, and transport start/stop.

Key categories demoted:
- Handshake cross-connection resolution mechanics (10 messages)
- Periodic MMP link/session metric reports (4 messages)
- TUN cleanup messages redundant with lifecycle shutdown (4 messages)
- Transport "packet channel closed" shutdown messages (4 messages)
- Retry scheduling, discovery lookup initiation, other intermediate steps

Change default RUST_LOG from debug to info in systemd unit files.
This commit is contained in:
Johnathan Corgan
2026-03-23 04:09:55 +00:00
parent 0ff3f029ed
commit b8fbecc575
19 changed files with 45 additions and 45 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
packaging/debian/fips.service
View File

@@ -10,7 +10,7 @@ Restart=on-failure
RestartSec=5
# Logging: RUST_LOG controls verbosity.
Environment=RUST_LOG=debug
Environment=RUST_LOG=info
# Control socket directory (/run/fips/).
# Group-accessible so 'fips' group members can use fipsctl/fipstop.

2
packaging/systemd/fips.service
View File

@@ -10,7 +10,7 @@ Restart=on-failure
RestartSec=5
# Logging: RUST_LOG controls verbosity.
Environment=RUST_LOG=debug
Environment=RUST_LOG=info
# Control socket directory (/run/fips/).
# Group-accessible so 'fips' group members can use fipsctl/fipstop.

6
src/bin/fips.rs
View File

@@ -7,7 +7,7 @@ use fips::config::{resolve_identity, IdentitySource};
use fips::version;
use fips::{Config, Node};
use std::path::PathBuf;
use tracing::{error, info, warn, Level};
use tracing::{debug, error, info, warn, Level};
use tracing_subscriber::{fmt, EnvFilter};
/// FIPS mesh network daemon
@@ -41,7 +41,7 @@ async fn main() {
info!("FIPS {} starting", version::short_version());
// Load configuration
info!("Loading configuration");
debug!("Loading configuration");
let (config, loaded_paths) = if let Some(config_path) = &args.config {
// Explicit config file specified - load only that file
match Config::load_file(config_path) {
@@ -88,7 +88,7 @@ async fn main() {
// Create node with resolved identity
let mut config = config;
config.node.identity.nsec = Some(resolved.nsec);
info!("Creating node");
debug!("Creating node");
let mut node = match Node::new(config) {
Ok(node) => node,
Err(e) => {

6
src/control/commands.rs
View File

@@ -6,7 +6,7 @@
use super::protocol::Response;
use crate::node::Node;
use serde_json::Value;
use tracing::info;
use tracing::debug;
/// Dispatch a mutating command to the appropriate handler.
pub async fn dispatch(node: &mut Node, command: &str, params: Option<&Value>) -> Response {
@@ -38,7 +38,7 @@ async fn connect(node: &mut Node, params: Option<&Value>) -> Response {
None => return Response::error("missing 'transport' parameter"),
};
info!(npub = %npub, address = %address, transport = %transport, "API connect requested");
debug!(npub = %npub, address = %address, transport = %transport, "API connect requested");
match node.api_connect(npub, address, transport).await {
Ok(data) => Response::ok(data),
@@ -59,7 +59,7 @@ fn disconnect(node: &mut Node, params: Option<&Value>) -> Response {
None => return Response::error("missing 'npub' parameter"),
};
info!(npub = %npub, "API disconnect requested");
debug!(npub = %npub, "API disconnect requested");
match node.api_disconnect(npub) {
Ok(data) => Response::ok(data),

2
src/node/handlers/discovery.rs
View File

@@ -410,7 +410,7 @@ impl Node {
let peer_count = peer_addrs.len();
info!(
debug!(
request_id = request.request_id,
target = %self.peer_display_name(target),
ttl = ttl,

20
src/node/handlers/handshake.rs
View File

@@ -420,7 +420,7 @@ impl Node {
if let Some(peer) = self.peers.get_mut(&node_addr) {
peer.set_handshake_msg2(wire_msg2.clone());
}
info!(
debug!(
peer = %self.peer_display_name(&node_addr),
link_id = %link_id,
our_index = %our_index,
@@ -449,7 +449,7 @@ impl Node {
}
// Clean up the losing connection's link
self.remove_link(&loser_link_id);
info!(
debug!(
peer = %self.peer_display_name(&node_addr),
loser_link_id = %loser_link_id,
"Inbound cross-connection won, loser link cleaned up"
@@ -474,7 +474,7 @@ impl Node {
(packet.transport_id, packet.remote_addr.clone()),
winner_link_id,
);
info!(
debug!(
winner_link_id = %winner_link_id,
"Inbound cross-connection lost, keeping existing"
);
@@ -640,7 +640,7 @@ impl Node {
let peer_node_addr = *peer_identity.node_addr();
info!(
debug!(
peer = %self.peer_display_name(&peer_node_addr),
link_id = %link_id,
their_index = %header.sender_idx,
@@ -716,7 +716,7 @@ impl Node {
);
}
info!(
debug!(
peer = %self.peer_display_name(&peer_node_addr),
new_our_index = %outbound_our_index,
new_their_index = %header.sender_idx,
@@ -736,7 +736,7 @@ impl Node {
let outbound_our_index = conn.our_index();
if let Some(peer) = self.peers.get(&peer_node_addr) {
info!(
debug!(
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)"
@@ -807,7 +807,7 @@ impl Node {
(packet.transport_id, packet.remote_addr.clone()),
link_id,
);
info!(
debug!(
peer = %self.peer_display_name(&node_addr),
loser_link_id = %loser_link_id,
"Outbound cross-connection won, loser link cleaned up"
@@ -832,7 +832,7 @@ impl Node {
(packet.transport_id, packet.remote_addr.clone()),
winner_link_id,
);
info!(
debug!(
winner_link_id = %winner_link_id,
"Outbound cross-connection lost, keeping existing"
);
@@ -950,7 +950,7 @@ impl Node {
self.retry_pending.remove(&peer_node_addr);
self.register_identity(peer_node_addr, verified_identity.pubkey_full());
info!(
debug!(
peer = %self.peer_display_name(&peer_node_addr),
winner_link = %link_id,
loser_link = %loser_link_id,
@@ -966,7 +966,7 @@ impl Node {
// Free the index we allocated
let _ = self.index_allocator.free(our_index);
info!(
debug!(
peer = %self.peer_display_name(&peer_node_addr),
winner_link = %existing_link_id,
loser_link = %link_id,

8
src/node/handlers/mmp.rs
View File

@@ -242,7 +242,7 @@ impl Node {
};
let jitter_ms = mmp.receiver.jitter_us() as f64 / 1000.0;
info!(
debug!(
peer = %peer_name,
rtt = %rtt_str,
loss = %loss_str,
@@ -265,7 +265,7 @@ impl Node {
};
let loss_str = format!("{:.1}%", m.loss_rate() * 100.0);
info!(
debug!(
peer = %peer_name,
rtt = %rtt_str,
loss = %loss_str,
@@ -434,7 +434,7 @@ impl Node {
};
let jitter_ms = mmp.receiver.jitter_us() as f64 / 1000.0;
info!(
debug!(
session = %session_name,
rtt = %rtt_str,
loss = %loss_str,
@@ -458,7 +458,7 @@ impl Node {
};
let loss_str = format!("{:.1}%", m.loss_rate() * 100.0);
info!(
debug!(
session = %session_name,
rtt = %rtt_str,
loss = %loss_str,

6
src/node/handlers/rekey.rs
View File

@@ -10,7 +10,7 @@ use crate::node::wire::build_msg1;
use crate::noise::HandshakeState;
use crate::protocol::{SessionDatagram, SessionSetup};
use crate::NodeAddr;
use tracing::{debug, info, trace, warn};
use tracing::{debug, trace, warn};
/// Keep previous session alive for this long after cutover.
const DRAIN_WINDOW_SECS: u64 = 10;
@@ -93,7 +93,7 @@ impl Node {
),
"peers_by_index should contain pre-registered new index after cutover"
);
info!(
debug!(
peer = %self.peer_display_name(&node_addr),
"Rekey cutover complete (initiator), K-bit flipped"
);
@@ -329,7 +329,7 @@ impl Node {
if let Some(entry) = self.sessions.get_mut(&node_addr)
&& entry.cutover_to_new_session(now_ms)
{
info!(
debug!(
peer = %self.peer_display_name(&node_addr),
"FSP rekey cutover complete (initiator), K-bit flipped"
);

2
src/node/handlers/session.rs
View File

@@ -1169,7 +1169,7 @@ impl Node {
entry.set_handshake_payload(setup_payload, now_ms + resend_interval);
self.sessions.insert(dest_addr, entry);
info!(dest = %self.peer_display_name(&dest_addr), "Session initiation started");
debug!(dest = %self.peer_display_name(&dest_addr), "Session initiation started");
Ok(())
}

4
src/node/handlers/timeout.rs
View File

@@ -33,13 +33,13 @@ impl Node {
let direction = conn.direction();
let idle_ms = conn.idle_time(now_ms);
if conn.is_failed() {
info!(
debug!(
link_id = %link_id,
direction = %direction,
"Failed handshake connection cleaned up"
);
} else {
info!(
debug!(
link_id = %link_id,
direction = %direction,
idle_secs = idle_ms / 1000,

4
src/node/lifecycle.rs
View File

@@ -50,7 +50,7 @@ impl Node {
return;
}
info!(count = peer_configs.len(), "Initiating static peer connections");
debug!(count = peer_configs.len(), "Initiating static peer connections");
for peer_config in peer_configs {
if let Err(e) = self.initiate_peer_connection(&peer_config).await {
@@ -561,7 +561,7 @@ impl Node {
let max_mss = effective_mtu.saturating_sub(40).saturating_sub(20); // IPv6 + TCP headers
info!("effective MTU: {} bytes", effective_mtu);
info!(" max TCP MSS: {} bytes", max_mss);
debug!(" max TCP MSS: {} bytes", max_mss);
// Create writer (dups the fd for independent write access)
let (writer, tun_tx) = device.create_writer(max_mss)?;

2
src/node/mod.rs
View File

@@ -990,7 +990,7 @@ impl Node {
),
};
if should_log {
tracing::info!(
tracing::debug!(
estimated_mesh_size = size,
peers = self.peers.len(),
children = child_count,

4
src/node/retry.rs
View File

@@ -171,7 +171,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!(
peer = %peer_name,
retry = state.retry_count,
delay_secs = delay / 1000,
@@ -185,7 +185,7 @@ impl Node {
let delay = state.backoff_ms(base_interval_ms, max_backoff_ms);
state.retry_after_ms = now_ms + delay;
info!(
debug!(
peer = %peer_name,
delay_secs = delay / 1000,
"Scheduling auto-reconnect after link-dead removal"

2
src/node/tree.rs
View File

@@ -198,7 +198,7 @@ impl Node {
self.stats_mut().tree.accepted += 1;
info!(
debug!(
from = %self.peer_display_name(from),
seq = announce.declaration.sequence(),
depth = announce.ancestry.depth(),

2
src/transport/ethernet/mod.rs
View File

@@ -421,7 +421,7 @@ async fn ethernet_receive_loop(
);
if packet_tx.send(packet).await.is_err() {
info!(
debug!(
transport_id = %transport_id,
"Packet channel closed, stopping receive loop"
);

2
src/transport/tcp/mod.rs
View File

@@ -893,7 +893,7 @@ async fn tcp_receive_loop(
);
if packet_tx.send(packet).await.is_err() {
info!(
debug!(
transport_id = %transport_id,
"Packet channel closed, stopping TCP receive loop"
);

4
src/transport/tor/mod.rs
View File

@@ -716,7 +716,7 @@ impl TorTransport {
let proxy_addr = self.config.socks5_addr();
let timeout_ms = self.config.connect_timeout_ms();
info!(
debug!(
transport_id = %self.transport_id,
remote_addr = %addr,
proxy = %proxy_addr,
@@ -1154,7 +1154,7 @@ async fn tor_receive_loop(
let packet = ReceivedPacket::new(transport_id, remote_addr.clone(), data);
if packet_tx.send(packet).await.is_err() {
info!(
debug!(
transport_id = %transport_id,
"Packet channel closed, stopping Tor receive loop"
);

2
src/transport/udp/mod.rs
View File

@@ -337,7 +337,7 @@ async fn udp_receive_loop(
if packet_tx.send(packet).await.is_err() {
// Receiver dropped, exit loop
info!(
debug!(
transport_id = %transport_id,
"Packet channel closed, stopping receive loop"
);

10
src/upper/tun.rs
View File

@@ -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, trace};
use tracing::{debug, error, trace};
use tun::Layer;
/// Channel sender for packets to be written to TUN.
@@ -96,7 +96,7 @@ impl TunDevice {
// Delete existing interface if present (TUN devices are exclusive)
if interface_exists(name).await {
info!(name, "Deleting existing TUN interface");
debug!(name, "Deleting existing TUN interface");
if let Err(e) = delete_interface(name).await {
debug!(name, error = %e, "Failed to delete existing interface");
}
@@ -158,7 +158,7 @@ impl TunDevice {
///
/// This deletes the interface entirely.
pub async fn shutdown(&self) -> Result<(), TunError> {
info!(name = %self.name, "Deleting TUN device");
debug!(name = %self.name, "Deleting TUN device");
delete_interface(&self.name).await
}
@@ -387,9 +387,9 @@ pub fn log_ipv6_packet(packet: &[u8]) {
/// to return an error. Use this for graceful shutdown when the TUN device
/// has been moved to another thread.
pub async fn shutdown_tun_interface(name: &str) -> Result<(), TunError> {
info!("Shutting down TUN interface {}", name);
debug!("Shutting down TUN interface {}", name);
delete_interface(name).await?;
info!("TUN interface {} stopped", name);
debug!("TUN interface {} stopped", name);
Ok(())
}