standardize on length of truncated peer ID logging (hyperledger#6485)

* add a method for the loggable id to standardise the length * use same length as peer id for short enode method Signed-off-by: Sally MacFarlane <[email protected]> --------- Signed-off-by: Sally MacFarlane <[email protected]> Co-authored-by: Stefan Pingel <[email protected]>
pinges · Jan 31, 2024 · d47e526 · d47e526
1 parent 20c713b
commit d47e526
Show file tree

Hide file tree

Showing 25 changed files with 62 additions and 51 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
@@ -212,7 +212,7 @@ public void removeChainEstimatedHeightListener(final long listenerId) {
   public void recordRequestTimeout(final int requestCode) {
     LOG.atDebug()
         .setMessage("Timed out while waiting for response from peer {}...")
-        .addArgument(this::getShortNodeId)
+        .addArgument(this::getLoggableId)
         .log();
     LOG.trace("Timed out while waiting for response from peer {}", this);
     reputation.recordRequestTimeout(requestCode).ifPresent(this::disconnect);
@@ -222,7 +222,7 @@ public void recordUselessResponse(final String requestType) {
     LOG.atTrace()
         .setMessage("Received useless response for request type {} from peer {}...")
         .addArgument(requestType)
-        .addArgument(this::getShortNodeId)
+        .addArgument(this::getLoggableId)
         .log();
     reputation.recordUselessResponse(System.currentTimeMillis()).ifPresent(this::disconnect);
   }
@@ -264,7 +264,7 @@ public RequestManager.ResponseStream send(
       LOG.atDebug()
           .setMessage("Protocol {} unavailable for this peer {}...")
           .addArgument(protocolName)
-          .addArgument(this.getShortNodeId())
+          .addArgument(this.getLoggableId())
           .log();
       return null;
     }
@@ -274,7 +274,7 @@ public RequestManager.ResponseStream send(
       LOG.info(
           "Permissioning blocked sending of message code {} to {}...",
           messageData.getCode(),
-          this.getShortNodeId());
+          this.getLoggableId());
       if (LOG.isDebugEnabled()) {
         LOG.debug(
             "Permissioning blocked by providers {}",
@@ -608,7 +608,7 @@ public boolean hasSupportForMessage(final int messageCode) {
   public String toString() {
     return String.format(
         "PeerId: %s... %s, validated? %s, disconnected? %s, client: %s, %s, %s",
-        getShortNodeId(),
+        getLoggableId(),
         reputation,
         isFullyValidated(),
         isDisconnected(),
@@ -618,8 +618,9 @@ public String toString() {
   }
 
   @Nonnull
-  public String getShortNodeId() {
-    return nodeId().toString().substring(0, 20);
+  public String getLoggableId() {
+    // 8 bytes plus the 0x prefix is 18 characters
+    return nodeId().toString().substring(0, 18) + "...";
   }
 
   @Override

diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeers.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeers.java
@@ -200,7 +200,7 @@ private boolean registerDisconnect(
         if (peer.getReputation().getScore() > USEFULL_PEER_SCORE_THRESHOLD) {
           LOG.debug("Disconnected USEFULL peer {}", peer);
         } else {
-          LOG.debug("Disconnected EthPeer {}", peer.getShortNodeId());
+          LOG.debug("Disconnected EthPeer {}", peer.getLoggableId());
         }
       }
     }
@@ -389,7 +389,7 @@ public void disconnectWorstUselessPeer() {
               LOG.atDebug()
                   .setMessage(
                       "disconnecting peer {}. Waiting for better peers. Current {} of max {}")
-                  .addArgument(peer::getShortNodeId)
+                  .addArgument(peer::getLoggableId)
                   .addArgument(this::peerCount)
                   .addArgument(this::getMaxPeers)
                   .log();

diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthProtocolManager.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthProtocolManager.java
@@ -400,13 +400,16 @@ public boolean shouldConnect(final Peer peer, final boolean incoming) {
     if (peer.getForkId().map(forkIdManager::peerCheck).orElse(true)) {
       LOG.atDebug()
           .setMessage("ForkId OK or not available for peer {}")
-          .addArgument(peer::getId)
+          .addArgument(peer::getLoggableId)
           .log();
       if (ethPeers.shouldConnect(peer, incoming)) {
         return true;
       }
     }
-    LOG.atDebug().setMessage("ForkId check failed for peer {}").addArgument(peer::getId).log();
+    LOG.atDebug()
+        .setMessage("ForkId check failed for peer {}")
+        .addArgument(peer::getLoggableId)
+        .log();
     return false;
   }
 
@@ -417,10 +420,10 @@ public void handleDisconnect(
       final boolean initiatedByPeer) {
     if (ethPeers.registerDisconnect(connection)) {
       LOG.atDebug()
-          .setMessage("Disconnect - {} - {} - {}... - {} peers left")
+          .setMessage("Disconnect - {} - {} - {} - {} peers left")
           .addArgument(initiatedByPeer ? "Inbound" : "Outbound")
           .addArgument(reason::toString)
-          .addArgument(() -> connection.getPeer().getId().slice(0, 8))
+          .addArgument(() -> connection.getPeer().getLoggableId())
           .addArgument(ethPeers::peerCount)
           .log();
       LOG.atTrace().setMessage("{}").addArgument(ethPeers::toString).log();
@@ -478,7 +481,7 @@ private void handleStatusMessage(final EthPeer peer, final Message message) {
     } catch (final RLPException e) {
       LOG.atDebug()
           .setMessage("Unable to parse status message from peer {}... {}")
-          .addArgument(peer::getShortNodeId)
+          .addArgument(peer::getLoggableId)
           .addArgument(e)
           .log();
       // Parsing errors can happen when clients broadcast network ids outside the int range,
@@ -488,7 +491,7 @@ private void handleStatusMessage(final EthPeer peer, final Message message) {
   }
 
   private Object getPeerOrPeerId(final EthPeer peer) {
-    return LOG.isTraceEnabled() ? peer : peer.getShortNodeId();
+    return LOG.isTraceEnabled() ? peer : peer.getLoggableId();
   }
 
   @Override

diff --git a/...n/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java b/...n/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java
@@ -74,19 +74,19 @@ protected Optional<List<BlockHeader>> processResponse(
     final List<BlockHeader> headers = headersMessage.getHeaders(protocolSchedule);
     if (headers.isEmpty()) {
       // Message contains no data - nothing to do
-      LOG.debug("headers.isEmpty. Peer: {}", peer.getShortNodeId());
+      LOG.debug("headers.isEmpty. Peer: {}", peer.getLoggableId());
       return Optional.empty();
     }
     if (headers.size() > count) {
       // Too many headers - this isn't our response
-      LOG.debug("headers.size()>count. Peer: {}", peer.getShortNodeId());
+      LOG.debug("headers.size()>count. Peer: {}", peer.getLoggableId());
       return Optional.empty();
     }
 
     final BlockHeader firstHeader = headers.get(0);
     if (!matchesFirstHeader(firstHeader)) {
       // This isn't our message - nothing to do
-      LOG.debug("!matchesFirstHeader. Peer: {}", peer.getShortNodeId());
+      LOG.debug("!matchesFirstHeader. Peer: {}", peer.getLoggableId());
       return Optional.empty();
     }
 
@@ -100,7 +100,7 @@ protected Optional<List<BlockHeader>> processResponse(
       header = headers.get(i);
       if (header.getNumber() != prevBlockHeader.getNumber() + expectedDelta) {
         // Skip doesn't match, this isn't our data
-        LOG.debug("header not matching the expected number. Peer: {}", peer.getShortNodeId());
+        LOG.debug("header not matching the expected number. Peer: {}", peer.getLoggableId());
         return Optional.empty();
       }
       // if headers are supposed to be sequential check if a chain is formed
@@ -110,7 +110,7 @@ protected Optional<List<BlockHeader>> processResponse(
         if (!parent.getHash().equals(child.getParentHash())) {
           LOG.debug(
               "Sequential headers must form a chain through hashes (BREACH_OF_PROTOCOL), disconnecting peer: {}",
-              peer.getShortNodeId());
+              peer.getLoggableId());
           peer.disconnect(DisconnectMessage.DisconnectReason.BREACH_OF_PROTOCOL);
           return Optional.empty();
         }
@@ -129,7 +129,7 @@ protected Optional<List<BlockHeader>> processResponse(
         .setMessage("Received {} of {} headers requested from peer {}...")
         .addArgument(headersList::size)
         .addArgument(count)
-        .addArgument(peer::getShortNodeId)
+        .addArgument(peer::getLoggableId)
         .log();
     return Optional.of(headersList);
   }
@@ -138,7 +138,7 @@ private void updatePeerChainState(final EthPeer peer, final BlockHeader blockHea
     if (blockHeader.getNumber() > peer.chainState().getEstimatedHeight()) {
       LOG.atTrace()
           .setMessage("Updating chain state for peer {}... to block header {}")
-          .addArgument(peer::getShortNodeId)
+          .addArgument(peer::getLoggableId)
           .addArgument(blockHeader::toLogString)
           .log();
       peer.chainState().update(blockHeader);

diff --git a/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractPeerRequestTask.java b/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractPeerRequestTask.java
@@ -110,7 +110,7 @@ private void handleMessage(
       // Peer sent us malformed data - disconnect
       LOG.debug(
           "Disconnecting with BREACH_OF_PROTOCOL due to malformed message: {}",
-          peer.getShortNodeId(),
+          peer.getLoggableId(),
           e);
       LOG.trace("Peer {} Malformed message data: {}", peer, message.getData());
       peer.disconnect(DisconnectReason.BREACH_OF_PROTOCOL);

diff --git a/...ava/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java b/...ava/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java
@@ -146,7 +146,7 @@ private void refreshPeers() {
                 LOG.atDebug()
                     .setMessage(
                         "Refresh peers disconnecting peer {}... Waiting for better peers. Current {} of max {}")
-                    .addArgument(peer::getShortNodeId)
+                    .addArgument(peer::getLoggableId)
                     .addArgument(peers::peerCount)
                     .addArgument(peers::getMaxPeers)
                     .log();

diff --git a/...erledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java b/...erledger/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::getLoggableId)
                     .log();
 
                 transactionPool.addRemoteTransactions(retrievedTransactions);
@@ -121,7 +121,7 @@ private List<Hash> getTxHashesAnnounced() {
     LOG.atTrace()
         .setMessage(
             "Transaction hashes to request from peer {}... fresh count {}, already seen count {}")
-        .addArgument(peer::getShortNodeId)
+        .addArgument(peer::getLoggableId)
         .addArgument(toRetrieve::size)
         .addArgument(alreadySeenCount)
         .log();

diff --git a/...ain/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java b/...ain/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::getLoggableId)
               .log();
           return peer.getHeadersByHash(referenceHash, count, skip, reverse);
         },

diff --git a/...n/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java b/...n/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::getLoggableId)
               .log();
           return peer.getHeadersByNumber(blockNumber, count, skip, reverse);
         },

diff --git a/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java b/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java
@@ -69,7 +69,7 @@ protected PendingPeerRequest sendRequest() {
           LOG.atTrace()
               .setMessage("Requesting {} node data entries from peer {}...")
               .addArgument(hashes::size)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getNodeData(hashes);
         },

diff --git a/...ava/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java b/...ava/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java
@@ -64,7 +64,7 @@ protected PendingPeerRequest sendRequest() {
           LOG.atTrace()
               .setMessage("Requesting {} transaction pool entries from peer {}...")
               .addArgument(hashes::size)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getPooledTransactions(new ArrayList<>(hashes));
         },

diff --git a/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java b/...src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java
@@ -86,7 +86,7 @@ protected PendingPeerRequest sendRequest() {
           LOG.atTrace()
               .setMessage("Requesting {} receipts from peer {}...")
               .addArgument(blockHeaders::size)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getReceipts(blockHashes);
         },

diff --git a/...n/java/org/hyperledger/besu/ethereum/eth/manager/task/RetryingGetBlocksFromPeersTask.java b/...n/java/org/hyperledger/besu/ethereum/eth/manager/task/RetryingGetBlocksFromPeersTask.java
@@ -80,7 +80,7 @@ protected CompletableFuture<PeerTaskResult<List<Block>>> executeTaskOnCurrentPee
               if (peerResult.getResult().isEmpty()) {
                 currentPeer.recordUselessResponse("GetBodiesFromPeerTask");
                 throw new IncompleteResultsException(
-                    "No blocks returned by peer " + currentPeer.getShortNodeId());
+                    "No blocks returned by peer " + currentPeer.getLoggableId());
               }
 
               result.complete(peerResult);

diff --git a/...erledger/besu/ethereum/eth/manager/task/RetryingGetHeadersEndingAtFromPeerByHashTask.java b/...erledger/besu/ethereum/eth/manager/task/RetryingGetHeadersEndingAtFromPeerByHashTask.java
@@ -104,7 +104,7 @@ protected CompletableFuture<List<BlockHeader>> executeTaskOnCurrentPeer(
                     "No block headers for hash "
                         + referenceHash
                         + " returned by peer "
-                        + currentPeer.getShortNodeId());
+                        + currentPeer.getLoggableId());
               }
               result.complete(peerResult.getResult());
               return peerResult.getResult();

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
@@ -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::getLoggableId)
         .log();
     GetHeadersFromPeerByHashTask.forSingleHash(
             protocolSchedule,
@@ -92,12 +92,12 @@ public void onPeerConnected(final EthPeer peer) {
                                 + " ("
                                 + chainHeadHeader.getBlockHash()
                                 + ")")
-                    .addArgument(peer::getShortNodeId)
+                    .addArgument(peer::getLoggableId)
                     .log();
               } else {
                 LOG.atDebug()
                     .setMessage("Failed to retrieve chain head info. Disconnecting {}... {}")
-                    .addArgument(peer::getShortNodeId)
+                    .addArgument(peer::getLoggableId)
                     .addArgument(error)
                     .log();
                 peer.disconnect(DisconnectReason.USELESS_PEER);

diff --git a/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/TrailingPeerLimiter.java b/ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/TrailingPeerLimiter.java
@@ -69,7 +69,7 @@ public void enforceTrailingPeerLimit() {
               "Enforcing trailing peers limit (min height {}, max trailing peers {}) by disconnecting {}... with height {}")
           .addArgument(minimumHeightToBeUpToDate)
           .addArgument(maxTrailingPeers)
-          .addArgument(peerToDisconnect::getShortNodeId)
+          .addArgument(peerToDisconnect::getLoggableId)
           .addArgument(
               peerToDisconnect.chainState() == null
                   ? "(no chain state)"

diff --git a/...src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/PivotSelectorFromPeers.java b/...src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/PivotSelectorFromPeers.java
@@ -118,7 +118,7 @@ private long countPeersThatCanDeterminePivotBlock() {
   private boolean canPeerDeterminePivotBlock(final EthPeer peer) {
     LOG.debug(
         "peer {} hasEstimatedHeight {} isFullyValidated? {}",
-        peer.getShortNodeId(),
+        peer.getLoggableId(),
         peer.chainState().hasEstimatedHeight(),
         peer.isFullyValidated());
     return peer.chainState().hasEstimatedHeight() && peer.isFullyValidated();

diff --git a/.../eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncTargetManager.java b/.../eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncTargetManager.java
@@ -96,7 +96,7 @@ protected CompletableFuture<Optional<EthPeer>> selectBestAvailableSyncTarget() {
       if (bestPeer.chainState().getEstimatedHeight() < pivotBlockHeader.getNumber()) {
         LOG.info(
             "Best peer {} has chain height {} below pivotBlock height {}. Waiting for better peers. Current {} of max {}",
-            maybeBestPeer.map(EthPeer::getShortNodeId).orElse("none"),
+            maybeBestPeer.map(EthPeer::getLoggableId).orElse("none"),
             maybeBestPeer.map(p -> p.chainState().getEstimatedHeight()).orElse(-1L),
             pivotBlockHeader.getNumber(),
             ethPeers.peerCount(),
@@ -138,7 +138,7 @@ private CompletableFuture<Optional<EthPeer>> confirmPivotBlockHeader(final EthPe
                 }
                 LOG.debug(
                     "Retrying best peer {} with new pivot block {}",
-                    bestPeer.getShortNodeId(),
+                    bestPeer.getLoggableId(),
                     pivotBlockHeader.toLogString());
                 return confirmPivotBlockHeader(bestPeer);
               } else {

diff --git a/...ava/org/hyperledger/besu/ethereum/eth/sync/tasks/RetryingGetHeaderFromPeerByHashTask.java b/...ava/org/hyperledger/besu/ethereum/eth/sync/tasks/RetryingGetHeaderFromPeerByHashTask.java
@@ -95,7 +95,7 @@ protected CompletableFuture<List<BlockHeader>> executeTaskOnCurrentPeer(final Et
                     "No block header for hash "
                         + referenceHash
                         + " returned by peer "
-                        + peer.getShortNodeId());
+                        + peer.getLoggableId());
               }
               result.complete(peerResult.getResult());
               return peerResult.getResult();

diff --git a/...yperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java b/...yperledger/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.getLoggableId())
           .addArgument(incomingTransactionHashes::size)
           .addArgument(incomingTransactionHashes)
           .log();

diff --git a/ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/manager/EthPeersTest.java b/ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/manager/EthPeersTest.java
@@ -346,7 +346,7 @@ public void toString_hasExpectedInfo() {
             .getEthPeer();
     ethPeers.registerNewConnection(peerA.getConnection(), Collections.emptyList());
     assertThat(ethPeers.toString()).contains("1 EthPeers {");
-    assertThat(ethPeers.toString()).contains(peerA.getShortNodeId());
+    assertThat(ethPeers.toString()).contains(peerA.getLoggableId());
   }
 
   private void freeUpCapacity(final EthPeer ethPeer) {

diff --git a/...in/java/org/hyperledger/besu/ethereum/p2p/discovery/internal/DiscoveryProtocolLogger.java b/...in/java/org/hyperledger/besu/ethereum/p2p/discovery/internal/DiscoveryProtocolLogger.java
@@ -47,19 +47,19 @@ public DiscoveryProtocolLogger(final MetricsSystem metricsSystem) {
   void logSendingPacket(final Peer peer, final Packet packet) {
     outgoingMessageCounter.labels(packet.getType().name()).inc();
     LOG.trace(
-        "<<< Sending {} packet to peer {}... ({}): {}",
+        "<<< Sending {} packet to peer {} ({}): {}",
         shortenPacketType(packet),
-        peer.getId().slice(0, 16),
+        peer.getLoggableId(),
         peer.getEnodeURL(),
         packet);
   }
 
   void logReceivedPacket(final Peer peer, final Packet packet) {
     incomingMessageCounter.labels(packet.getType().name()).inc();
     LOG.trace(
-        ">>> Received {} packet from peer {}... ({}): {}",
+        ">>> Received {} packet from peer {} ({}): {}",
         shortenPacketType(packet),
-        peer.getId().slice(0, 16),
+        peer.getLoggableId(),
         peer.getEnodeURL(),
         packet);
   }