From 87c4ae744ae8430ef64e8055d9531a7cdcc2f164 Mon Sep 17 00:00:00 2001 From: Emilia Hane Date: Sat, 30 Mar 2024 03:47:38 +0100 Subject: [PATCH] Clean up log messages (#7390) --- .../net/network/src/transactions/fetcher.rs | 76 +++++++++++-------- crates/net/network/src/transactions/mod.rs | 24 +++--- 2 files changed, 58 insertions(+), 42 deletions(-) diff --git a/crates/net/network/src/transactions/fetcher.rs b/crates/net/network/src/transactions/fetcher.rs index 45260ba7b0..4e708b0216 100644 --- a/crates/net/network/src/transactions/fetcher.rs +++ b/crates/net/network/src/transactions/fetcher.rs @@ -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)) } diff --git a/crates/net/network/src/transactions/mod.rs b/crates/net/network/src/transactions/mod.rs index c81763e60e..32d855ca10 100644 --- a/crates/net/network/src/transactions/mod.rs +++ b/crates/net/network/src/transactions/mod.rs @@ -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));