From b020543c4b5ba30567a710337a2602c75711310e Mon Sep 17 00:00:00 2001 From: Fintan Halpenny Date: Mon, 19 Jan 2026 13:46:58 +0000 Subject: [PATCH] node: downgrade `warn!` logs Evaluate the `warn!` logging in `radicle-node`. If the event is a result of something being suspicious in the running of the protocol, then it remains a `warn!`. However, if the system ends up ignoring the event and can continue without issues, the log level is reduced to `debug!`. --- crates/radicle-node/src/main.rs | 2 +- crates/radicle-node/src/reactor.rs | 10 ++++----- crates/radicle-node/src/reactor/transport.rs | 8 +++---- crates/radicle-node/src/wire.rs | 22 +++++++++---------- crates/radicle-node/src/worker.rs | 2 +- crates/radicle-node/src/worker/fetch.rs | 16 +++++++------- crates/radicle-node/src/worker/upload_pack.rs | 6 ++--- 7 files changed, 33 insertions(+), 33 deletions(-) diff --git a/crates/radicle-node/src/main.rs b/crates/radicle-node/src/main.rs index 03f221e1..ddc3edf0 100644 --- a/crates/radicle-node/src/main.rs +++ b/crates/radicle-node/src/main.rs @@ -330,7 +330,7 @@ fn execute(options: Options) -> Result<(), ExecutionError> { #[cfg(windows)] let signals = { let (_, signals) = chan::bounded(1); - log::warn!(target: "node", "Signal handlers not installed."); + log::info!(target: "node", "No signal handlers were installed, because this is not available on Windows."); signals }; diff --git a/crates/radicle-node/src/reactor.rs b/crates/radicle-node/src/reactor.rs index 467eded3..84a2bfd9 100644 --- a/crates/radicle-node/src/reactor.rs +++ b/crates/radicle-node/src/reactor.rs @@ -483,7 +483,7 @@ impl Runtime { deregistered.push(token); } } else if !deregistered.contains(&token) { - log::warn!(target: "reactor", token=token.0; "Event from unknown token {}: {:?}", token.0, event); + log::debug!(target: "reactor", token=token.0; "Event from unknown token {}: {:?}", token.0, event); } } @@ -576,12 +576,12 @@ impl Runtime { fn deregister_listener(&mut self, token: Token) -> Option { let Some(mut source) = self.listeners.remove(&token) else { - log::warn!(target: "reactor", token=token.0; "Deregistering non-registered listener with token {}", token.0); + log::debug!(target: "reactor", token=token.0; "Deregistering non-registered listener with token {}", token.0); return None; }; if let Err(err) = self.poll.registry().deregister(&mut source) { - log::warn!(target: "reactor", token=token.0; "Failed to deregister listener with token {} from mio: {err}", token.0); + log::debug!(target: "reactor", token=token.0; "Failed to deregister listener with token {} from mio: {err}", token.0); } Some(source) @@ -589,12 +589,12 @@ impl Runtime { fn deregister_transport(&mut self, token: Token) -> Option { let Some(mut source) = self.transports.remove(&token) else { - log::warn!(target: "reactor", token=token.0; "Deregistering non-registered transport with token {}", token.0); + log::debug!(target: "reactor", token=token.0; "Deregistering non-registered transport with token {}", token.0); return None; }; if let Err(err) = self.poll.registry().deregister(&mut source) { - log::warn!(target: "reactor", token=token.0; "Failed to deregister transport with token {} from mio: {err}", token.0); + log::debug!(target: "reactor", token=token.0; "Failed to deregister transport with token {} from mio: {err}", token.0); } Some(source) diff --git a/crates/radicle-node/src/reactor/transport.rs b/crates/radicle-node/src/reactor/transport.rs index 6ace822c..ef6e141a 100644 --- a/crates/radicle-node/src/reactor/transport.rs +++ b/crates/radicle-node/src/reactor/transport.rs @@ -148,7 +148,7 @@ impl Transport { fn handle_io(&mut self, interest: Interest) -> Option> { if self.state == TransportState::Terminated { - log::warn!(target: "transport", "Transport {self} is terminated, ignoring I/O event"); + log::debug!(target: "transport", "Transport {self} is terminated, ignoring I/O event"); return None; } @@ -217,7 +217,7 @@ impl Transport { | io::ErrorKind::Interrupted ) => { - log::warn!(target: "transport", "Resource {} was not able to consume any data even though it has announced its write readiness", self.display()); + log::debug!(target: "transport", "Resource {} was not able to consume any data even though it has announced its write readiness", self.display()); self.write_intent = true; None } @@ -241,7 +241,7 @@ impl Transport { // when there's data on the socket. We leave it here in case external // conditions change. - log::warn!(target: "transport", + log::trace!(target: "transport", "WOULD_BLOCK on resource which had read intent - probably normal thing to happen" ); None @@ -261,7 +261,7 @@ impl Transport { | io::ErrorKind::OutOfMemory | io::ErrorKind::WriteZero | io::ErrorKind::Interrupted => { - log::warn!(target: "transport", "Resource {} kernel buffer is full (system message is '{err}')", self.display()); + log::trace!(target: "transport", "Resource {} kernel buffer is full (system message is '{err}')", self.display()); Ok(0) }, _ => { diff --git a/crates/radicle-node/src/wire.rs b/crates/radicle-node/src/wire.rs index 5d351f93..de2f3ff4 100644 --- a/crates/radicle-node/src/wire.rs +++ b/crates/radicle-node/src/wire.rs @@ -248,7 +248,7 @@ impl Peers { fn insert(&mut self, token: Token, peer: Peer) { if self.0.insert(token, peer).is_some() { - log::warn!(target: "wire", token=token.0; "Replacing existing peer"); + log::debug!(target: "wire", token=token.0; "Replacing existing peer"); } } @@ -396,7 +396,7 @@ where let nid = task.remote; let Some((fd, peer)) = self.peers.lookup_mut(&nid) else { - log::warn!(target: "wire", "Peer {nid} not found; ignoring fetch result"); + log::debug!(target: "wire", "Peer {nid} not found; ignoring fetch result"); return; }; @@ -421,7 +421,7 @@ where } else { // If the peer disconnected, we'll get here, but we still want to let the service know // about the fetch result, so we don't return here. - log::warn!(target: "wire", "Peer {nid} is not connected; ignoring fetch result"); + log::debug!(target: "wire", "Peer {nid} is not connected; ignoring fetch result"); return; }; @@ -444,11 +444,11 @@ where fn flush(&mut self, remote: NodeId, stream: StreamId) { let Some((fd, peer)) = self.peers.lookup_mut(&remote) else { - log::warn!(target: "wire", "Peer {remote} is not known; ignoring flush"); + log::debug!(target: "wire", "Peer {remote} is not known; ignoring flush"); return; }; let Peer::Connected { streams, link, .. } = peer else { - log::warn!(target: "wire", "Peer {remote} is not connected; ignoring flush"); + log::debug!(target: "wire", "Peer {remote} is not connected; ignoring flush"); return; }; let Some(s) = streams.get_mut(&stream) else { @@ -582,7 +582,7 @@ where } else if self.inbound.contains(&token) { log::debug!(target: "wire", token=token.0; "Inbound peer resource registered"); } else { - log::warn!(target: "wire", token=token.0; "Unknown peer registered"); + log::debug!(target: "wire", token=token.0; "Unknown peer registered"); } } @@ -665,14 +665,14 @@ where (Outbound, Outbound, _) => token.max(c_token), }; - log::warn!( + log::trace!( target: "wire", "Established session with token {} conflicts with existing session with token {} for {nid}. Disconnecting session with token {}.", token.0, c_token.0, close.0 ); disconnect.push(close); } } for id in &disconnect { - log::warn!( + log::info!( target: "wire", token=token.0; "Closing conflicting session with {nid}.." ); // Disconnect and return the associated NID of the peer, if available. @@ -727,7 +727,7 @@ where ChannelsConfig::new(FETCH_TIMEOUT) .with_reader_limit(reader_limit), ) else { - log::warn!(target: "wire", "Peer attempted to open already-open stream stream {stream}"); + log::debug!(target: "wire", "Peer attempted to open already-open stream stream {stream}"); continue; }; @@ -816,7 +816,7 @@ where } } } else { - log::warn!(target: "wire", token=token.0; "Dropping message from unconnected peer"); + log::debug!(target: "wire", token=token.0; "Dropping message from unconnected peer"); } } SessionEvent::Terminated(err) => { @@ -1007,7 +1007,7 @@ where self.metrics.peer(nid).disconnects += 1; } } else { - log::warn!(target: "wire", "Peer {nid} is not connected: ignoring disconnect"); + log::debug!(target: "wire", "Peer {nid} is not connected: ignoring disconnect"); } } Io::Wakeup(d) => { diff --git a/crates/radicle-node/src/worker.rs b/crates/radicle-node/src/worker.rs index 3aae8166..0449b526 100644 --- a/crates/radicle-node/src/worker.rs +++ b/crates/radicle-node/src/worker.rs @@ -240,7 +240,7 @@ impl Worker { // N.b. ensure that `git gc` works in debug mode. debug_assert!(false, "`git gc` failed: {e}"); - log::warn!(target: "worker", "Failed to run `git gc`: {e}"); + log::debug!(target: "worker", "Failed to run `git gc`: {e}"); } Ok(result) } diff --git a/crates/radicle-node/src/worker/fetch.rs b/crates/radicle-node/src/worker/fetch.rs index da4256a3..44a80338 100644 --- a/crates/radicle-node/src/worker/fetch.rs +++ b/crates/radicle-node/src/worker/fetch.rs @@ -96,7 +96,7 @@ impl Handle { }; for rejected in result.rejected() { - log::warn!(target: "worker", "Rejected update for {}", rejected.refname()) + log::debug!(target: "worker", "Rejected update for {}", rejected.refname()) } match result { @@ -119,7 +119,7 @@ impl Handle { validations, } => { for warn in validations { - log::warn!(target: "worker", "Validation error: {warn}"); + log::debug!(target: "worker", "Validation error: {warn}"); } // N.b. We do not go through handle for this since the cloning handle @@ -133,7 +133,7 @@ impl Handle { } } Err(RepositoryError::Quorum(e)) => { - log::warn!(target: "worker", "Fetch could not set HEAD: {e}") + log::warn!(target: "worker", "Fetch could not set HEAD for {rid}: {e}") } Err(e) => return Err(e.into()), } @@ -141,7 +141,7 @@ impl Handle { let canonical = match set_canonical_refs(&repo, &applied) { Ok(updates) => updates.unwrap_or_default(), Err(e) => { - log::warn!(target: "worker", "Failed to set canonical references: {e}"); + log::warn!(target: "worker", "Failed to set canonical references for {rid}: {e}"); UpdatedCanonicalRefs::default() } }; @@ -228,7 +228,7 @@ where let (namespace, qualified) = match radicle::git::parse_ref_namespaced(name) { Err(e) => { log::error!(target: "worker", "Git reference is invalid: {name:?}: {e}"); - log::warn!(target: "worker", "Skipping refs caching for fetch of {repo}"); + log::debug!(target: "worker", "Skipping refs caching for fetch of {repo}"); break; } Ok((n, q)) => (n, q), @@ -248,7 +248,7 @@ where if let Err(e) = result { log::error!(target: "worker", "Error updating git refs cache for {name:?}: {e}"); - log::warn!(target: "worker", "Skipping refs caching for fetch of {repo}"); + log::debug!(target: "worker", "Skipping refs caching for fetch of {repo}"); break; } } @@ -380,7 +380,7 @@ fn set_canonical_refs( let canonical = match canonical.find_objects() { Err(err) => { - log::warn!(target: "worker", "Failed to find objects for canonical computation: {err}"); + log::warn!(target: "worker", "Failed to find objects for canonical computation of `{name}`: {err}"); continue; } Ok(canonical) => canonical, @@ -390,7 +390,7 @@ fn set_canonical_refs( Err(err) => { log::warn!( target: "worker", - "Failed to calculate canonical reference: {err}", + "Failed to calculate canonical reference `{name}`: {err}", ); continue; } diff --git a/crates/radicle-node/src/worker/upload_pack.rs b/crates/radicle-node/src/worker/upload_pack.rs index 9fb86701..50de14ae 100644 --- a/crates/radicle-node/src/worker/upload_pack.rs +++ b/crates/radicle-node/src/worker/upload_pack.rs @@ -97,7 +97,7 @@ where Ok(n) => { let mut lock = reporter.lock().expect("FATAL: upload_pack poisoned lock"); if let Err(e) = lock.write_all(&buffer[..n]) { - log::warn!(target: "worker", "Error reading stdout to upload-pack reporter: {e}"); + log::debug!(target: "worker", "Failed to write buffer to upload-pack reporter: {e}"); emitter.emit(events::UploadPack::error(header.repo, remote, e).into()); break; } @@ -119,7 +119,7 @@ where Ok(0) => break, Ok(n) => { if let Err(e) = stdin.write_all(&buffer[..n]) { - log::warn!(target: "worker", "Error writing to upload-pack stdin: {e}"); + log::debug!(target: "worker", "Failed to write to upload-pack stdin: {e}"); break; } } @@ -128,7 +128,7 @@ where break; } Err(e) if e.kind() == io::ErrorKind::TimedOut => { - log::warn!(target: "worker", "Read channel timed out for upload-pack {}", header.repo); + log::debug!(target: "worker", "Read channel timed out for upload-pack {}", header.repo); // N.b. if the read timed out, ensure that the sender isn't // still sending messages. let lock = reporter.lock().expect("FATAL: upload_pack poisoned lock");