mab122
/
radicle-heartwood-lfs
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

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!`.
This commit is contained in:
Fintan Halpenny 2026-01-19 13:46:58 +00:00 committed by Lorenz Leutgeb
parent ee1f55420a
commit b020543c4b
7 changed files with 33 additions and 33 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
crates/radicle-node/src/main.rs
View File

@ -330,7 +330,7 @@ fn execute(options: Options) -> Result<(), ExecutionError> {
#[cfg(windows)] #[cfg(windows)]
let signals = { let signals = {
let (_, signals) = chan::bounded(1); 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 signals
}; };

10
crates/radicle-node/src/reactor.rs
View File

@ -483,7 +483,7 @@ impl<H: ReactionHandler> Runtime<H> {
deregistered.push(token); deregistered.push(token);
} }
} else if !deregistered.contains(&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<H: ReactionHandler> Runtime<H> {
fn deregister_listener(&mut self, token: Token) -> Option<H::Listener> { fn deregister_listener(&mut self, token: Token) -> Option<H::Listener> {
let Some(mut source) = self.listeners.remove(&token) else { 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; return None;
}; };
if let Err(err) = self.poll.registry().deregister(&mut source) { 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) Some(source)
@ -589,12 +589,12 @@ impl<H: ReactionHandler> Runtime<H> {
fn deregister_transport(&mut self, token: Token) -> Option<H::Transport> { fn deregister_transport(&mut self, token: Token) -> Option<H::Transport> {
let Some(mut source) = self.transports.remove(&token) else { 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; return None;
}; };
if let Err(err) = self.poll.registry().deregister(&mut source) { 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) Some(source)

8
crates/radicle-node/src/reactor/transport.rs
View File

@ -148,7 +148,7 @@ impl<S: Session> Transport<S> {
fn handle_io(&mut self, interest: Interest) -> Option<SessionEvent<S>> { fn handle_io(&mut self, interest: Interest) -> Option<SessionEvent<S>> {
if self.state == TransportState::Terminated { 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; return None;
} }
@ -217,7 +217,7 @@ impl<S: Session> Transport<S> {
| io::ErrorKind::Interrupted | 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; self.write_intent = true;
None None
} }
@ -241,7 +241,7 @@ impl<S: Session> Transport<S> {
// when there's data on the socket. We leave it here in case external // when there's data on the socket. We leave it here in case external
// conditions change. // conditions change.
log::warn!(target: "transport", log::trace!(target: "transport",
"WOULD_BLOCK on resource which had read intent - probably normal thing to happen" "WOULD_BLOCK on resource which had read intent - probably normal thing to happen"
); );
None None
@ -261,7 +261,7 @@ impl<S: Session> Transport<S> {
| io::ErrorKind::OutOfMemory | io::ErrorKind::OutOfMemory
| io::ErrorKind::WriteZero | io::ErrorKind::WriteZero
| io::ErrorKind::Interrupted => { | 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) Ok(0)
}, },
_ => { _ => {

22
crates/radicle-node/src/wire.rs
View File

@ -248,7 +248,7 @@ impl Peers {
fn insert(&mut self, token: Token, peer: Peer) { fn insert(&mut self, token: Token, peer: Peer) {
if self.0.insert(token, peer).is_some() { 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 nid = task.remote;
let Some((fd, peer)) = self.peers.lookup_mut(&nid) else { 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; return;
}; };
@ -421,7 +421,7 @@ where
} else { } else {
// If the peer disconnected, we'll get here, but we still want to let the service know // 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. // 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; return;
}; };
@ -444,11 +444,11 @@ where
fn flush(&mut self, remote: NodeId, stream: StreamId) { fn flush(&mut self, remote: NodeId, stream: StreamId) {
let Some((fd, peer)) = self.peers.lookup_mut(&remote) else { 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; return;
}; };
let Peer::Connected { streams, link, .. } = peer else { 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; return;
}; };
let Some(s) = streams.get_mut(&stream) else { let Some(s) = streams.get_mut(&stream) else {
@ -582,7 +582,7 @@ where
} else if self.inbound.contains(&token) { } else if self.inbound.contains(&token) {
log::debug!(target: "wire", token=token.0; "Inbound peer resource registered"); log::debug!(target: "wire", token=token.0; "Inbound peer resource registered");
} else { } 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), (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 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); disconnect.push(close);
} }
} }
for id in &disconnect { for id in &disconnect {
log::warn!( log::info!(
target: "wire", token=token.0; "Closing conflicting session with {nid}.." target: "wire", token=token.0; "Closing conflicting session with {nid}.."
); );
// Disconnect and return the associated NID of the peer, if available. // Disconnect and return the associated NID of the peer, if available.
@ -727,7 +727,7 @@ where
ChannelsConfig::new(FETCH_TIMEOUT) ChannelsConfig::new(FETCH_TIMEOUT)
.with_reader_limit(reader_limit), .with_reader_limit(reader_limit),
) else { ) 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; continue;
}; };
@ -816,7 +816,7 @@ where
} }
} }
} else { } 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) => { SessionEvent::Terminated(err) => {
@ -1007,7 +1007,7 @@ where
self.metrics.peer(nid).disconnects += 1; self.metrics.peer(nid).disconnects += 1;
} }
} else { } 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) => { Io::Wakeup(d) => {

2
crates/radicle-node/src/worker.rs
View File

@ -240,7 +240,7 @@ impl Worker {
// N.b. ensure that `git gc` works in debug mode. // N.b. ensure that `git gc` works in debug mode.
debug_assert!(false, "`git gc` failed: {e}"); 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) Ok(result)
} }

16
crates/radicle-node/src/worker/fetch.rs
View File

@ -96,7 +96,7 @@ impl Handle {
}; };
for rejected in result.rejected() { 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 { match result {
@ -119,7 +119,7 @@ impl Handle {
validations, validations,
} => { } => {
for warn in 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 // N.b. We do not go through handle for this since the cloning handle
@ -133,7 +133,7 @@ impl Handle {
} }
} }
Err(RepositoryError::Quorum(e)) => { 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()), Err(e) => return Err(e.into()),
} }
@ -141,7 +141,7 @@ impl Handle {
let canonical = match set_canonical_refs(&repo, &applied) { let canonical = match set_canonical_refs(&repo, &applied) {
Ok(updates) => updates.unwrap_or_default(), Ok(updates) => updates.unwrap_or_default(),
Err(e) => { 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() UpdatedCanonicalRefs::default()
} }
}; };
@ -228,7 +228,7 @@ where
let (namespace, qualified) = match radicle::git::parse_ref_namespaced(name) { let (namespace, qualified) = match radicle::git::parse_ref_namespaced(name) {
Err(e) => { Err(e) => {
log::error!(target: "worker", "Git reference is invalid: {name:?}: {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; break;
} }
Ok((n, q)) => (n, q), Ok((n, q)) => (n, q),
@ -248,7 +248,7 @@ where
if let Err(e) = result { if let Err(e) = result {
log::error!(target: "worker", "Error updating git refs cache for {name:?}: {e}"); 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; break;
} }
} }
@ -380,7 +380,7 @@ fn set_canonical_refs(
let canonical = match canonical.find_objects() { let canonical = match canonical.find_objects() {
Err(err) => { 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; continue;
} }
Ok(canonical) => canonical, Ok(canonical) => canonical,
@ -390,7 +390,7 @@ fn set_canonical_refs(
Err(err) => { Err(err) => {
log::warn!( log::warn!(
target: "worker", target: "worker",
"Failed to calculate canonical reference: {err}", "Failed to calculate canonical reference `{name}`: {err}",
); );
continue; continue;
} }

6
crates/radicle-node/src/worker/upload_pack.rs
View File

@ -97,7 +97,7 @@ where
Ok(n) => { Ok(n) => {
let mut lock = reporter.lock().expect("FATAL: upload_pack poisoned lock"); let mut lock = reporter.lock().expect("FATAL: upload_pack poisoned lock");
if let Err(e) = lock.write_all(&buffer[..n]) { 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()); emitter.emit(events::UploadPack::error(header.repo, remote, e).into());
break; break;
} }
@ -119,7 +119,7 @@ where
Ok(0) => break, Ok(0) => break,
Ok(n) => { Ok(n) => {
if let Err(e) = stdin.write_all(&buffer[..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; break;
} }
} }
@ -128,7 +128,7 @@ where
break; break;
} }
Err(e) if e.kind() == io::ErrorKind::TimedOut => { 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 // N.b. if the read timed out, ensure that the sender isn't
// still sending messages. // still sending messages.
let lock = reporter.lock().expect("FATAL: upload_pack poisoned lock"); let lock = reporter.lock().expect("FATAL: upload_pack poisoned lock");