From ce7531cc1d1a82819f32dd51d03f7e451dae7c01 Mon Sep 17 00:00:00 2001 From: Divma <26765164+divagant-martian@users.noreply.github.com> Date: Mon, 11 Dec 2023 17:04:34 -0500 Subject: [PATCH] Adjust some logs (#225) * remove log for timed out query. This is always informed in the callback * expand common logs, unify info on startup * adjust auth header log * Update src/service.rs * Appease clippy * Realised I was wrong. Don't need this log, my bad * fmt --------- Co-authored-by: Age Manning --- src/handler/mod.rs | 4 ++-- src/service.rs | 27 ++++++++++++--------------- 2 files changed, 14 insertions(+), 17 deletions(-) diff --git a/src/handler/mod.rs b/src/handler/mod.rs index 4547078e8..c2eb51577 100644 --- a/src/handler/mod.rs +++ b/src/handler/mod.rs @@ -908,8 +908,8 @@ impl Handler { } } else { warn!( - "Received an authenticated header without a matching WHOAREYOU request. {}", - node_address + node_id = %node_address.node_id, addr = %node_address.socket_addr, + "Received an authenticated header without a matching WHOAREYOU request", ); } } diff --git a/src/service.rs b/src/service.rs index 1c99e2903..0f67e6807 100644 --- a/src/service.rs +++ b/src/service.rs @@ -324,7 +324,7 @@ impl Service { ip_mode, }; - info!("Discv5 Service started"); + info!(mode = ?service.ip_mode, "Discv5 Service started"); service.start().await; })); @@ -333,7 +333,6 @@ impl Service { /// The main execution loop of the discv5 serviced. async fn start(&mut self) { - info!("{:?}", self.ip_mode); loop { tokio::select! { _ = &mut self.exit => { @@ -722,10 +721,9 @@ impl Service { if nodes.len() < before_len { // Peer sent invalid ENRs. Blacklist the Node - warn!( - "Peer sent invalid ENR. Blacklisting {}", - active_request.contact - ); + let node_id = active_request.contact.node_id(); + let addr = active_request.contact.socket_addr(); + warn!(%node_id, %addr, "ENRs received of unsolicited distances. Blacklisting"); let ban_timeout = self.config.ban_duration.map(|v| Instant::now() + v); PERMIT_BAN_LIST.write().ban(node_address, ban_timeout); } @@ -1449,13 +1447,14 @@ impl Service { match active_request.request_body { // if a failed FindNodes request, ensure we haven't partially received packets. If // so, process the partially found nodes - RequestBody::FindNode { .. } => { + RequestBody::FindNode { ref distances } => { if let Some(nodes_response) = self.active_nodes_responses.remove(&id) { if !nodes_response.received_nodes.is_empty() { - warn!( - "NODES Response failed, but was partially processed from: {}", - active_request.contact - ); + let node_id = active_request.contact.node_id(); + let addr = active_request.contact.socket_addr(); + let received = nodes_response.received_nodes.len(); + let expected = distances.len(); + warn!(%node_id, %addr, %error, %received, %expected, "FINDNODE request failed with partial results"); // if it's a query mark it as success, to process the partial // collection of peers self.discovered( @@ -1529,10 +1528,8 @@ impl Service { let request_body = query.target().rpc_request(return_peer); Poll::Ready(QueryEvent::Waiting(query.id(), node_id, request_body)) } - QueryPoolState::Timeout(query) => { - warn!("Query id: {:?} timed out", query.id()); - Poll::Ready(QueryEvent::TimedOut(Box::new(query))) - } + + QueryPoolState::Timeout(query) => Poll::Ready(QueryEvent::TimedOut(Box::new(query))), QueryPoolState::Waiting(None) | QueryPoolState::Idle => Poll::Pending, }) .await