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.

Sign up for GitHub

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

Adjust some logs #225

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
8c89fed
remove log for timed out query. This is always informed in the callback
divagant-martian Dec 10, 2023
020d2ce
expand common logs, unify info on startup
divagant-martian Dec 10, 2023
a18c201
adjust auth header log
divagant-martian Dec 10, 2023
f0e0d88
Update src/service.rs
AgeManning Dec 11, 2023
be2d8f1
Appease clippy
AgeManning Dec 11, 2023
a8ae735
Realised I was wrong. Don't need this log, my bad
AgeManning Dec 11, 2023
7602d77
fmt
AgeManning Dec 11, 2023
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
View file
Open in desktop
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
View file
Open in desktop
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