From 00413a76f3d825546a4689b44afb377d87dbf5d1 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Tue, 28 Nov 2023 11:41:42 +1000 Subject: [PATCH 01/11] moved some logs to trace level Signed-off-by: Sally MacFarlane --- .../ethereum/eth/manager/task/GetBodiesFromPeerTask.java | 8 ++++++-- .../manager/task/GetPooledTransactionsFromPeerTask.java | 6 +++++- .../besu/ethereum/eth/transactions/TransactionPool.java | 6 +++--- .../rlpx/connections/netty/HandshakeHandlerOutbound.java | 2 +- 4 files changed, 15 insertions(+), 7 deletions(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetBodiesFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetBodiesFromPeerTask.java index 9e1df148c12..4cd66830251 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetBodiesFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetBodiesFromPeerTask.java @@ -93,7 +93,11 @@ protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { - LOG.debug("Requesting {} bodies from peer {}.", blockHashes.size(), peer); + LOG.atTrace() + .setMessage("Requesting {} bodies from peer {}.") + .addArgument(blockHashes.size()) + .addArgument(peer) + .log(); return peer.getBodies(blockHashes); }, minimumRequiredBlockNumber); @@ -103,7 +107,7 @@ protected PendingPeerRequest sendRequest() { protected Optional> processResponse( final boolean streamClosed, final MessageData message, final EthPeer peer) { if (streamClosed) { - // All outstanding requests have been responded to and we still haven't found the response + // All outstanding requests have been responded to, and we still haven't found the response // we wanted. It must have been empty or contain data that didn't match. peer.recordUselessResponse("bodies"); return Optional.of(Collections.emptyList()); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java index 06151ba68c8..bef0d96b56f 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java @@ -61,7 +61,11 @@ public Set getTransactionHashes() { protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { - LOG.debug("Requesting {} transaction pool entries from peer {}.", hashes.size(), peer); + LOG.atTrace() + .setMessage("Requesting {} transaction pool entries from peer {}.") + .addArgument(hashes.size()) + .addArgument(peer) + .log(); return peer.getPooledTransactions(new ArrayList<>(hashes)); }, 0); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/TransactionPool.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/TransactionPool.java index bb0cdf70eb6..edefbc17a36 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/TransactionPool.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/TransactionPool.java @@ -182,7 +182,7 @@ public Map> addRemoteTransactio final long started = System.currentTimeMillis(); final int initialCount = transactions.size(); final List addedTransactions = new ArrayList<>(initialCount); - LOG.debug("Adding {} remote transactions", initialCount); + LOG.trace("Adding {} remote transactions", initialCount); final var validationResults = sortedBySenderAndNonce(transactions) @@ -204,7 +204,7 @@ public Map> addRemoteTransactio .addArgument(() -> pendingTransactions.logStats()) .log(); - LOG.atDebug() + LOG.atTrace() .setMessage( "Added {} transactions to the pool in {}ms, {} not added, current pool stats {}") .addArgument(addedTransactions::size) @@ -350,7 +350,7 @@ public void onBlockAdded(final BlockAddedEvent event) { .getByBlockHeader(e.getBlock().getHeader()) .getFeeMarket()); reAddTransactions(e.getRemovedTransactions()); - LOG.atDebug() + LOG.atTrace() .setMessage("Block added event {} processed in {}ms") .addArgument(e) .addArgument(() -> System.currentTimeMillis() - started) diff --git a/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/HandshakeHandlerOutbound.java b/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/HandshakeHandlerOutbound.java index 1c1391f2f79..205b6f655cc 100644 --- a/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/HandshakeHandlerOutbound.java +++ b/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/HandshakeHandlerOutbound.java @@ -84,7 +84,7 @@ public void channelActive(final ChannelHandlerContext ctx) throws Exception { .addListener( f -> { if (f.isSuccess()) { - LOG.debug( + LOG.trace( "Wrote initial crypto handshake message to {}.", ctx.channel().remoteAddress()); } }); From 518ef0f130cd251334ec075e038438f8b2555ee2 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Tue, 28 Nov 2023 12:31:02 +1000 Subject: [PATCH 02/11] more trace level Signed-off-by: Sally MacFarlane --- .../api/query/cache/TransactionLogBloomCacher.java | 2 +- .../task/AbstractGetHeadersFromPeerTask.java | 13 +++++++------ .../manager/task/GetHeadersFromPeerByHashTask.java | 11 ++++++----- .../task/GetHeadersFromPeerByNumberTask.java | 11 ++++++----- .../eth/manager/task/GetNodeDataFromPeerTask.java | 6 +++++- .../eth/manager/task/GetReceiptsFromPeerTask.java | 8 ++++++-- .../besu/ethereum/eth/sync/ChainHeadTracker.java | 9 ++++++--- .../eth/sync/backwardsync/BackwardSyncStep.java | 2 +- .../eth/sync/range/RangeHeadersFetcher.java | 2 +- .../connections/netty/AbstractHandshakeHandler.java | 2 +- 10 files changed, 40 insertions(+), 26 deletions(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java index dd6fed957ab..19fcec8402f 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java @@ -159,7 +159,7 @@ void cacheLogsBloomForBlockHeader( return; } final long blockNumber = blockHeader.getNumber(); - LOG.debug("Caching logs bloom for block {}.", "0x" + Long.toHexString(blockNumber)); + LOG.debug("Caching logs bloom for block {}", "0x" + Long.toHexString(blockNumber)); final File cacheFile = reusedCacheFile.orElse(calculateCacheFileName(blockNumber, cacheDir)); if (cacheFile.exists()) { try { diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java index b7b2e76b5ce..0b60ce69d41 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java @@ -125,18 +125,19 @@ protected Optional> processResponse( updatePeerChainState(peer, header); } - LOG.debug( - "Received {} of {} headers requested from peer {}", - headersList.size(), - count, - peer.getShortNodeId()); + LOG.atTrace() + .setMessage("Received {} of {} headers requested from peer {}...") + .addArgument(headersList.size()) + .addArgument(count) + .addArgument(peer.getShortNodeId()) + .log(); return Optional.of(headersList); } private void updatePeerChainState(final EthPeer peer, final BlockHeader blockHeader) { if (blockHeader.getNumber() > peer.chainState().getEstimatedHeight()) { LOG.atTrace() - .setMessage("Updating chain state for peer {} to block header {}") + .setMessage("Updating chain state for peer {}... to block header {}") .addArgument(peer::getShortNodeId) .addArgument(blockHeader::toLogString) .log(); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java index 8fb06b484e6..5fe90d1d6c8 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java @@ -119,11 +119,12 @@ public static AbstractGetHeadersFromPeerTask forSingleHash( protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { - LOG.debug( - "Requesting {} headers (hash {}...) from peer {}.", - count, - referenceHash.slice(0, 6), - peer.getShortNodeId()); + LOG.atTrace() + .setMessage("Requesting {} headers (hash {}...) from peer {}.") + .addArgument(count) + .addArgument(referenceHash.slice(0, 6)) + .addArgument(peer.getShortNodeId()) + .log(); return peer.getHeadersByHash(referenceHash, count, skip, reverse); }, minimumRequiredBlockNumber); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java index f136fc57eb7..ce71ecd5b44 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java @@ -77,11 +77,12 @@ public static AbstractGetHeadersFromPeerTask forSingleNumber( protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { - LOG.debug( - "Requesting {} headers (blockNumber {}) from peer {}.", - count, - blockNumber, - peer.getShortNodeId()); + LOG.atTrace() + .setMessage("Requesting {} headers (blockNumber {}) from peer {}.") + .addArgument(count) + .addArgument(blockNumber) + .addArgument(peer.getShortNodeId()) + .log(); return peer.getHeadersByNumber(blockNumber, count, skip, reverse); }, blockNumber); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java index c5d01632281..9c888b73161 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java @@ -66,7 +66,11 @@ public static GetNodeDataFromPeerTask forHashes( protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { - LOG.debug("Requesting {} node data entries from peer {}.", hashes.size(), peer); + LOG.atTrace() + .setMessage("Requesting {} node data entries from peer {}...") + .addArgument(hashes.size()) + .addArgument(peer.getShortNodeId()) + .log(); return peer.getNodeData(hashes); }, pivotBlockNumber); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java index dace85a202b..48100cf8075 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java @@ -83,7 +83,11 @@ protected PendingPeerRequest sendRequest() { .collect(toList()); return sendRequestToPeer( peer -> { - LOG.debug("Requesting {} receipts from peer {}.", blockHeaders.size(), peer); + LOG.atTrace() + .setMessage("Requesting {} receipts from peer {}...") + .addArgument(blockHeaders.size()) + .addArgument(peer.getShortNodeId()) + .log(); return peer.getReceipts(blockHashes); }, maximumRequiredBlockNumber); @@ -93,7 +97,7 @@ protected PendingPeerRequest sendRequest() { protected Optional>> processResponse( final boolean streamClosed, final MessageData message, final EthPeer peer) { if (streamClosed) { - // All outstanding requests have been responded to and we still haven't found the response + // All outstanding requests have been responded to, and we still haven't found the response // we wanted. It must have been empty or contain data that didn't match. peer.recordUselessResponse("receipts"); return Optional.of(emptyMap()); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java index d871b07a6e0..3cafc85c04f 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java @@ -66,7 +66,10 @@ public static void trackChainHeadForPeers( @Override public void onPeerConnected(final EthPeer peer) { - LOG.debug("Requesting chain head info from {}", peer); + LOG.atDebug() + .setMessage("Requesting chain head info from {}...") + .addArgument(peer.getShortNodeId()) + .log(); GetHeadersFromPeerByHashTask.forSingleHash( protocolSchedule, ethContext, @@ -82,14 +85,14 @@ public void onPeerConnected(final EthPeer peer) { peer.chainState().update(chainHeadHeader); trailingPeerLimiter.enforceTrailingPeerLimit(); LOG.atDebug() - .setMessage("Retrieved chain head info {} from {}") + .setMessage("Retrieved chain head info {} from {}...") .addArgument( () -> chainHeadHeader.getNumber() + " (" + chainHeadHeader.getBlockHash() + ")") - .addArgument(peer) + .addArgument(peer.getShortNodeId()) .log(); } else { LOG.debug("Failed to retrieve chain head info. Disconnecting {}", peer, error); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncStep.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncStep.java index 10315a60102..6f9a5822de1 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncStep.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncStep.java @@ -66,7 +66,7 @@ protected CompletableFuture> requestHeaders(final Hash hash) { } final int batchSize = context.getBatchSize(); - LOG.debug("Requesting headers for hash {}, with batch size {}", hash, batchSize); + LOG.trace("Requesting headers for hash {}, with batch size {}", hash, batchSize); final RetryingGetHeadersEndingAtFromPeerByHashTask retryingGetHeadersEndingAtFromPeerByHashTask = diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/range/RangeHeadersFetcher.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/range/RangeHeadersFetcher.java index 68e7d193b99..8ee1dc28a43 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/range/RangeHeadersFetcher.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/range/RangeHeadersFetcher.java @@ -97,7 +97,7 @@ private CompletableFuture> requestHeaders( final BlockHeader referenceHeader, final int headerCount, final int skip) { - LOG.debug( + LOG.trace( "Requesting {} range headers, starting from {}, {} blocks apart", headerCount, referenceHeader.getNumber(), diff --git a/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/AbstractHandshakeHandler.java b/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/AbstractHandshakeHandler.java index 3a827403ec3..003a6ab1d9d 100644 --- a/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/AbstractHandshakeHandler.java +++ b/ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/netty/AbstractHandshakeHandler.java @@ -153,7 +153,7 @@ private void disconnect( @Override public void exceptionCaught(final ChannelHandlerContext ctx, final Throwable throwable) { - LOG.debug("Handshake error:", throwable); + LOG.trace("Handshake error:", throwable); connectionFuture.completeExceptionally(throwable); ctx.close(); } From c6c29a3cbf06b6a05129b328c39bfb8d2fb543a9 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Tue, 28 Nov 2023 13:58:56 +1000 Subject: [PATCH 03/11] shortNodeId Signed-off-by: Sally MacFarlane --- .../org/hyperledger/besu/ethereum/eth/manager/EthPeer.java | 6 +++--- .../eth/manager/task/GetPooledTransactionsFromPeerTask.java | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java index f7995a19bb1..b9ee1fa2cb1 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java @@ -210,14 +210,14 @@ public void removeChainEstimatedHeightListener(final long listenerId) { } public void recordRequestTimeout(final int requestCode) { - LOG.debug("Timed out while waiting for response from peer {}", this.getShortNodeId()); + LOG.debug("Timed out while waiting for response from peer {}...", this.getShortNodeId()); LOG.trace("Timed out while waiting for response from peer {}", this); reputation.recordRequestTimeout(requestCode).ifPresent(this::disconnect); } public void recordUselessResponse(final String requestType) { - LOG.debug( - "Received useless response for request type {} from peer {}", + LOG.trace( + "Received useless response for request type {} from peer {}...", requestType, this.getShortNodeId()); reputation.recordUselessResponse(System.currentTimeMillis()).ifPresent(this::disconnect); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java index bef0d96b56f..24f4b16abbe 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java @@ -62,9 +62,9 @@ protected PendingPeerRequest sendRequest() { return sendRequestToPeer( peer -> { LOG.atTrace() - .setMessage("Requesting {} transaction pool entries from peer {}.") + .setMessage("Requesting {} transaction pool entries from peer {}...") .addArgument(hashes.size()) - .addArgument(peer) + .addArgument(peer.getShortNodeId()) .log(); return peer.getPooledTransactions(new ArrayList<>(hashes)); }, From 2eb6d4ffe4f916ff488391227f3747746dae091d Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Tue, 28 Nov 2023 15:24:11 +1000 Subject: [PATCH 04/11] shortNodeId Signed-off-by: Sally MacFarlane --- .../BufferedGetPooledTransactionsFromPeerFetcher.java | 8 ++++---- .../NewPooledTransactionHashesMessageProcessor.java | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java index 215202f8341..87a99d0b0bc 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java @@ -89,10 +89,10 @@ public void requestTransactions() { transactionTracker.markTransactionsAsSeen(peer, retrievedTransactions); LOG.atTrace() - .setMessage("Got {} transactions of {} hashes requested from peer {}") + .setMessage("Got {} transactions of {} hashes requested from peer {}...") .addArgument(retrievedTransactions::size) .addArgument(task.getTransactionHashes()::size) - .addArgument(peer) + .addArgument(peer.getShortNodeId()) .log(); transactionPool.addRemoteTransactions(retrievedTransactions); @@ -120,8 +120,8 @@ private List getTxHashesAnnounced() { metrics.incrementAlreadySeenTransactions(metricLabel, alreadySeenCount); LOG.atTrace() .setMessage( - "Transaction hashes to request from peer {}, fresh count {}, already seen count {}") - .addArgument(peer) + "Transaction hashes to request from peer {}... fresh count {}, already seen count {}") + .addArgument(peer.getShortNodeId()) .addArgument(toRetrieve::size) .addArgument(alreadySeenCount) .log(); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java index ede1b60beb1..db5be050d7e 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java @@ -86,8 +86,8 @@ private void processNewPooledTransactionHashesMessage( LOG.atTrace() .setMessage( - "Received pooled transaction hashes message from {}, incoming hashes {}, incoming list {}") - .addArgument(peer) + "Received pooled transaction hashes message from {}... incoming hashes {}, incoming list {}") + .addArgument(peer.getShortNodeId()) .addArgument(incomingTransactionHashes::size) .addArgument(incomingTransactionHashes) .log(); From 7c8b07e1e349e1ab40cff15c5a0bdb9ccf444e43 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Wed, 29 Nov 2023 17:48:30 +1000 Subject: [PATCH 05/11] shortNodeId Signed-off-by: Sally MacFarlane --- .../eth/manager/task/AbstractRetryingSwitchingPeerTask.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java index 24ee859baf9..f9400a6dac6 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java @@ -145,7 +145,7 @@ private void refreshPeers() { peer -> { LOG.atDebug() .setMessage( - "Refresh peers disconnecting peer {}. Waiting for better peers. Current {} of max {}") + "Refresh peers disconnecting peer {}... Waiting for better peers. Current {} of max {}") .addArgument(peer::getShortNodeId) .addArgument(peers::peerCount) .addArgument(peers::getMaxPeers) From f4b0c545e386b0b373b3cf3dbd8d0b87739b9015 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 30 Nov 2023 12:45:30 +1000 Subject: [PATCH 06/11] pr review Signed-off-by: Sally MacFarlane --- .../api/query/cache/TransactionLogBloomCacher.java | 5 ++++- .../besu/ethereum/eth/manager/EthPeer.java | 14 +++++++++----- .../task/AbstractGetHeadersFromPeerTask.java | 4 ++-- ...fferedGetPooledTransactionsFromPeerFetcher.java | 2 +- .../task/GetPooledTransactionsFromPeerTask.java | 4 ++-- .../eth/manager/task/GetReceiptsFromPeerTask.java | 4 ++-- .../besu/ethereum/eth/sync/ChainHeadTracker.java | 4 ++-- ...NewPooledTransactionHashesMessageProcessor.java | 2 +- 8 files changed, 23 insertions(+), 16 deletions(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java index 19fcec8402f..c7ab690e9fb 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java @@ -159,7 +159,10 @@ void cacheLogsBloomForBlockHeader( return; } final long blockNumber = blockHeader.getNumber(); - LOG.debug("Caching logs bloom for block {}", "0x" + Long.toHexString(blockNumber)); + LOG.atDebug() + .setMessage("Caching logs bloom for block {}") + .addArgument("0x" + Long.toHexString(blockNumber)) + .log(); final File cacheFile = reusedCacheFile.orElse(calculateCacheFileName(blockNumber, cacheDir)); if (cacheFile.exists()) { try { diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java index 98d64d0fde1..4e734447035 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java @@ -210,16 +210,20 @@ public void removeChainEstimatedHeightListener(final long listenerId) { } public void recordRequestTimeout(final int requestCode) { - LOG.debug("Timed out while waiting for response from peer {}...", this.getShortNodeId()); + LOG.atDebug() + .setMessage("Timed out while waiting for response from peer {}...") + .addArgument(this::getShortNodeId) + .log(); LOG.trace("Timed out while waiting for response from peer {}", this); reputation.recordRequestTimeout(requestCode).ifPresent(this::disconnect); } public void recordUselessResponse(final String requestType) { - LOG.trace( - "Received useless response for request type {} from peer {}...", - requestType, - this.getShortNodeId()); + LOG.atTrace() + .setMessage("Received useless response for request type {} from peer {}...") + .addArgument(requestType) + .addArgument(this::getShortNodeId) + .log(); reputation.recordUselessResponse(System.currentTimeMillis()).ifPresent(this::disconnect); } diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java index 0b60ce69d41..83af1e0b32d 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java @@ -127,9 +127,9 @@ protected Optional> processResponse( LOG.atTrace() .setMessage("Received {} of {} headers requested from peer {}...") - .addArgument(headersList.size()) + .addArgument(headersList::size) .addArgument(count) - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); return Optional.of(headersList); } diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java index 87a99d0b0bc..7ea9d3f0441 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java @@ -92,7 +92,7 @@ public void requestTransactions() { .setMessage("Got {} transactions of {} hashes requested from peer {}...") .addArgument(retrievedTransactions::size) .addArgument(task.getTransactionHashes()::size) - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); transactionPool.addRemoteTransactions(retrievedTransactions); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java index 24f4b16abbe..e3a45418d18 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java @@ -63,8 +63,8 @@ protected PendingPeerRequest sendRequest() { peer -> { LOG.atTrace() .setMessage("Requesting {} transaction pool entries from peer {}...") - .addArgument(hashes.size()) - .addArgument(peer.getShortNodeId()) + .addArgument(hashes::size) + .addArgument(peer::getShortNodeId) .log(); return peer.getPooledTransactions(new ArrayList<>(hashes)); }, diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java index 48100cf8075..42e0928829f 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java @@ -85,8 +85,8 @@ protected PendingPeerRequest sendRequest() { peer -> { LOG.atTrace() .setMessage("Requesting {} receipts from peer {}...") - .addArgument(blockHeaders.size()) - .addArgument(peer.getShortNodeId()) + .addArgument(blockHeaders::size) + .addArgument(peer::getShortNodeId) .log(); return peer.getReceipts(blockHashes); }, diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java index 3cafc85c04f..5e4862da1ec 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java @@ -68,7 +68,7 @@ public static void trackChainHeadForPeers( public void onPeerConnected(final EthPeer peer) { LOG.atDebug() .setMessage("Requesting chain head info from {}...") - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); GetHeadersFromPeerByHashTask.forSingleHash( protocolSchedule, @@ -92,7 +92,7 @@ public void onPeerConnected(final EthPeer peer) { + " (" + chainHeadHeader.getBlockHash() + ")") - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); } else { LOG.debug("Failed to retrieve chain head info. Disconnecting {}", peer, error); diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java index db5be050d7e..a474140651d 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java @@ -87,7 +87,7 @@ private void processNewPooledTransactionHashesMessage( LOG.atTrace() .setMessage( "Received pooled transaction hashes message from {}... incoming hashes {}, incoming list {}") - .addArgument(peer.getShortNodeId()) + .addArgument(peer == null ? null : peer.getShortNodeId()) .addArgument(incomingTransactionHashes::size) .addArgument(incomingTransactionHashes) .log(); From a750b66a0d5e10ff0151c74695c8a914e0c61a25 Mon Sep 17 00:00:00 2001 From: Fabio Di Fabio Date: Thu, 30 Nov 2023 09:48:34 +0100 Subject: [PATCH 07/11] Update ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java Signed-off-by: Fabio Di Fabio --- .../task/BufferedGetPooledTransactionsFromPeerFetcher.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java index 7ea9d3f0441..0e414ba5db8 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java @@ -121,7 +121,7 @@ private List getTxHashesAnnounced() { LOG.atTrace() .setMessage( "Transaction hashes to request from peer {}... fresh count {}, already seen count {}") - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .addArgument(toRetrieve::size) .addArgument(alreadySeenCount) .log(); From f2781028785f7cdd071f71c9ed9f452662a47cdb Mon Sep 17 00:00:00 2001 From: Fabio Di Fabio Date: Thu, 30 Nov 2023 09:52:14 +0100 Subject: [PATCH 08/11] Apply suggestions from code review Signed-off-by: Fabio Di Fabio --- .../eth/manager/task/GetHeadersFromPeerByNumberTask.java | 2 +- .../ethereum/eth/manager/task/GetNodeDataFromPeerTask.java | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java index ce71ecd5b44..3f6e153df37 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java @@ -81,7 +81,7 @@ protected PendingPeerRequest sendRequest() { .setMessage("Requesting {} headers (blockNumber {}) from peer {}.") .addArgument(count) .addArgument(blockNumber) - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); return peer.getHeadersByNumber(blockNumber, count, skip, reverse); }, diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java index 9c888b73161..d6b0de35069 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java @@ -68,8 +68,8 @@ protected PendingPeerRequest sendRequest() { peer -> { LOG.atTrace() .setMessage("Requesting {} node data entries from peer {}...") - .addArgument(hashes.size()) - .addArgument(peer.getShortNodeId()) + .addArgument(hashes::size) + .addArgument(peer::getShortNodeId) .log(); return peer.getNodeData(hashes); }, From 53a6ecb4f96a35c56f246f20ea316480edc37465 Mon Sep 17 00:00:00 2001 From: Fabio Di Fabio Date: Thu, 30 Nov 2023 09:53:03 +0100 Subject: [PATCH 09/11] Update ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java Signed-off-by: Fabio Di Fabio --- .../ethereum/api/query/cache/TransactionLogBloomCacher.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java index c7ab690e9fb..31132a4655e 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/query/cache/TransactionLogBloomCacher.java @@ -161,7 +161,7 @@ void cacheLogsBloomForBlockHeader( final long blockNumber = blockHeader.getNumber(); LOG.atDebug() .setMessage("Caching logs bloom for block {}") - .addArgument("0x" + Long.toHexString(blockNumber)) + .addArgument(() -> "0x" + Long.toHexString(blockNumber)) .log(); final File cacheFile = reusedCacheFile.orElse(calculateCacheFileName(blockNumber, cacheDir)); if (cacheFile.exists()) { From 101dc5fe422e8182c4b436943b1325b957892cbd Mon Sep 17 00:00:00 2001 From: Fabio Di Fabio Date: Thu, 30 Nov 2023 09:53:19 +0100 Subject: [PATCH 10/11] Update ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java Signed-off-by: Fabio Di Fabio --- .../NewPooledTransactionHashesMessageProcessor.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java index a474140651d..f447c1df315 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java @@ -87,7 +87,7 @@ private void processNewPooledTransactionHashesMessage( LOG.atTrace() .setMessage( "Received pooled transaction hashes message from {}... incoming hashes {}, incoming list {}") - .addArgument(peer == null ? null : peer.getShortNodeId()) + .addArgument(() -> peer == null ? null : peer.getShortNodeId()) .addArgument(incomingTransactionHashes::size) .addArgument(incomingTransactionHashes) .log(); From c25b70d14a5bc9ba6b370a14780bebd48d144a6e Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 30 Nov 2023 19:16:09 +1000 Subject: [PATCH 11/11] lambda Signed-off-by: Sally MacFarlane --- .../ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java index ed303c39f16..4fb2ef226f4 100644 --- a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java +++ b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java @@ -123,7 +123,7 @@ protected PendingPeerRequest sendRequest() { .setMessage("Requesting {} headers (hash {}...) from peer {}...") .addArgument(count) .addArgument(referenceHash.slice(0, 6)) - .addArgument(peer.getShortNodeId()) + .addArgument(peer::getShortNodeId) .log(); return peer.getHeadersByHash(referenceHash, count, skip, reverse); },