Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Adjust some logs #225

Merged
merged 7 commits into from
Dec 11, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions src/handler/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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",
);
}
}
Expand Down
27 changes: 12 additions & 15 deletions src/service.rs
Original file line number Diff line number Diff line change
Expand Up @@ -324,7 +324,7 @@ impl Service {
ip_mode,
};

info!("Discv5 Service started");
info!(mode = ?service.ip_mode, "Discv5 Service started");
service.start().await;
}));

Expand All @@ -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 => {
Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -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(
Expand Down Expand Up @@ -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))),
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
QueryPoolState::Timeout(query) => Poll::Ready(QueryEvent::TimedOut(Box::new(query))),
debug!("Query id: {:?} timed out", query.id());
QueryPoolState::Timeout(query) => Poll::Ready(QueryEvent::TimedOut(Box::new(query))),

Users can set the max time for a query. It's useful to know if the results were partial or not. How about downgrading to a debug?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The reason why I removed it is because a query timeout is on itself an event emited via the callback. Also queries belong to request so I'm not sure the query id on itself is useful info.

Do you still prefer to have this as a debug statement?

QueryPoolState::Waiting(None) | QueryPoolState::Idle => Poll::Pending,
})
.await
Expand Down