Clean up log messages (#7390)

This commit is contained in:
Emilia Hane
2024-03-30 03:47:38 +01:00
committed by GitHub
parent c13d7da68d
commit 87c4ae744a
2 changed files with 58 additions and 42 deletions

View File

@ -393,8 +393,8 @@ impl TransactionFetcher {
} else {
if *retries >= DEFAULT_MAX_RETRIES {
trace!(target: "net::tx",
hash=%hash,
retries=retries,
%hash,
retries,
"retry limit for `GetPooledTransactions` requests reached for hash, dropping hash"
);
@ -481,7 +481,7 @@ impl TransactionFetcher {
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
hashes=?*hashes_to_request,
conn_eth_version=%conn_eth_version,
%conn_eth_version,
"requesting hashes that were stored pending fetch from peer"
);
@ -491,8 +491,8 @@ impl TransactionFetcher {
{
debug!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
failed_to_request_hashes=?failed_to_request_hashes,
conn_eth_version=%conn_eth_version,
?failed_to_request_hashes,
%conn_eth_version,
"failed sending request to peer's session, buffering hashes"
);
@ -530,10 +530,10 @@ impl TransactionFetcher {
if size != prev_size {
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
hash=%hash,
size=size,
previously_seen_size=previously_seen_size,
client_version=%client_version,
%hash,
size,
previously_seen_size,
%client_version,
"peer announced a different size for tx, this is especially worrying if one size is much bigger..."
);
}
@ -585,9 +585,9 @@ impl TransactionFetcher {
debug!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
hash=%hash,
msg_version=?msg_version,
client_version=%client_version,
%hash,
?msg_version,
%client_version,
"failed to cache new announced hash from peer in schnellru::LruMap, dropping hash"
);
@ -608,10 +608,10 @@ impl TransactionFetcher {
#[cfg(debug_assertions)]
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
msg_version=?msg_version,
client_version=%client_version,
previously_unseen_hashes_len=?previously_unseen_hashes.len(),
previously_unseen_hashes=?previously_unseen_hashes,
?msg_version,
%client_version,
previously_unseen_hashes_len=previously_unseen_hashes.len(),
?previously_unseen_hashes,
"received previously unseen hashes in announcement from peer"
);
}
@ -634,8 +634,8 @@ impl TransactionFetcher {
if self.active_peers.len() >= self.info.max_inflight_requests {
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
new_announced_hashes=?*new_announced_hashes,
conn_eth_version=%conn_eth_version,
hashes=?*new_announced_hashes,
%conn_eth_version,
max_inflight_transaction_requests=self.info.max_inflight_requests,
"limit for concurrent `GetPooledTransactions` requests reached, dropping request for hashes to peer"
);
@ -645,7 +645,7 @@ impl TransactionFetcher {
let Some(inflight_count) = self.active_peers.get_or_insert(peer_id, || 0) else {
debug!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
new_announced_hashes=?*new_announced_hashes,
hashes=?*new_announced_hashes,
conn_eth_version=%conn_eth_version,
"failed to cache active peer in schnellru::LruMap, dropping request to peer"
);
@ -655,9 +655,9 @@ impl TransactionFetcher {
if *inflight_count >= DEFAULT_MAX_COUNT_CONCURRENT_REQUESTS_PER_PEER {
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
new_announced_hashes=?*new_announced_hashes,
conn_eth_version=%conn_eth_version,
MAX_CONCURRENT_TX_REQUESTS_PER_PEER=DEFAULT_MAX_COUNT_CONCURRENT_REQUESTS_PER_PEER,
hashes=?*new_announced_hashes,
%conn_eth_version,
max_concurrent_tx_reqs_per_peer=DEFAULT_MAX_COUNT_CONCURRENT_REQUESTS_PER_PEER,
"limit for concurrent `GetPooledTransactions` requests per peer reached"
);
return Some(new_announced_hashes)
@ -837,7 +837,7 @@ impl TransactionFetcher {
inflight_requests=self.inflight_requests.len(),
max_inflight_transaction_requests=info.max_inflight_requests,
hashes_pending_fetch=self.hashes_pending_fetch.len(),
limit=limit,
limit,
"search breadth limited in search for idle fallback peer for some hash pending fetch"
);
@ -948,7 +948,7 @@ impl TransactionFetcher {
// todo: report peer for sending hashes that weren't requested
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
unverified_len=unverified_len,
unverified_len,
verified_payload_len=verified_payload.len(),
"received `PooledTransactions` response from peer with entries that didn't verify against request, filtered out transactions"
);
@ -974,7 +974,7 @@ impl TransactionFetcher {
if validation_outcome == FilterOutcome::ReportPeer {
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
unvalidated_payload_len=unvalidated_payload_len,
unvalidated_payload_len,
valid_payload_len=valid_payload.len(),
"received invalid `PooledTransactions` response from peer, filtered out duplicate entries"
);
@ -1237,6 +1237,8 @@ impl VerifyPooledTransactionsResponse for UnverifiedPooledTransactions {
#[cfg(debug_assertions)]
let mut tx_hashes_not_requested: SmallVec<[TxHash; 16]> = smallvec!();
#[cfg(not(debug_assertions))]
let mut tx_hashes_not_requested_count = 0;
txns.0.retain(|tx| {
if !requested_hashes.contains(tx.hash()) {
@ -1244,6 +1246,10 @@ impl VerifyPooledTransactionsResponse for UnverifiedPooledTransactions {
#[cfg(debug_assertions)]
tx_hashes_not_requested.push(*tx.hash());
#[cfg(not(debug_assertions))]
{
tx_hashes_not_requested_count += 1;
}
return false
}
@ -1251,11 +1257,21 @@ impl VerifyPooledTransactionsResponse for UnverifiedPooledTransactions {
});
#[cfg(debug_assertions)]
trace!(target: "net::tx",
peer_id=format!("{_peer_id:#}"),
tx_hashes_not_requested=?tx_hashes_not_requested,
"transactions in `PooledTransactions` response from peer were not requested"
);
if !tx_hashes_not_requested.is_empty() {
trace!(target: "net::tx",
peer_id=format!("{_peer_id:#}"),
?tx_hashes_not_requested,
"transactions in `PooledTransactions` response from peer were not requested"
);
}
#[cfg(not(debug_assertions))]
if tx_hashes_not_requested_count != 0 {
trace!(target: "net::tx",
peer_id=format!("{_peer_id:#}"),
tx_hashes_not_requested_count,
"transactions in `PooledTransactions` response from peer were not requested"
);
}
(verification_outcome, VerifiedPooledTransactions::new(txns))
}

View File

@ -609,8 +609,8 @@ where
// get handle to peer's session, if the session is still active
let Some(peer) = self.peers.get_mut(&peer_id) else {
trace!(
peer_id=format!("{peer_id:#}"),
msg=?msg,
peer_id = format!("{peer_id:#}"),
?msg,
"discarding announcement from inactive peer"
);
@ -636,9 +636,9 @@ where
.increment(count_txns_already_seen_by_peer);
trace!(target: "net::tx",
count_txns_already_seen_by_peer=%count_txns_already_seen_by_peer,
%count_txns_already_seen_by_peer,
peer_id=format!("{peer_id:#}"),
client=?client,
?client,
"Peer sent hashes that have already been marked as seen by peer"
);
@ -746,8 +746,8 @@ where
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
hashes=?*hashes,
msg_version=%msg_version,
client_version=%client,
%msg_version,
%client,
"buffering hashes announced by busy peer"
);
@ -773,8 +773,8 @@ where
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
surplus_hashes=?*surplus_hashes,
msg_version=%msg_version,
client_version=%client,
%msg_version,
%client,
"some hashes in announcement from peer didn't fit in `GetPooledTransactions` request, buffering surplus hashes"
);
@ -784,8 +784,8 @@ where
trace!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
hashes=?*hashes_to_request,
msg_version=%msg_version,
client_version=%client,
%msg_version,
%client,
"sending hashes in `GetPooledTransactions` request to peer's session"
);
@ -801,8 +801,8 @@ where
debug!(target: "net::tx",
peer_id=format!("{peer_id:#}"),
failed_to_request_hashes=?*failed_to_request_hashes,
conn_eth_version=%conn_eth_version,
client_version=%client,
%conn_eth_version,
%client,
"sending `GetPooledTransactions` request to peer's session failed, buffering hashes"
);
self.transaction_fetcher.buffer_hashes(failed_to_request_hashes, Some(peer_id));