standardize on length of truncated peer ID logging (#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 <macfarla.github@gmail.com>

---------

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Co-authored-by: Stefan Pingel <16143240+pinges@users.noreply.github.com>

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeer.java

@@ -212,7 +212,7 @@ public class EthPeer implements Comparable<EthPeer> {
   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 class EthPeer implements Comparable<EthPeer> {
     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 class EthPeer implements Comparable<EthPeer> {
       LOG.atDebug()
           .setMessage("Protocol {} unavailable for this peer {}...")
           .addArgument(protocolName)
-          .addArgument(this.getShortNodeId())
+          .addArgument(this.getLoggableId())
           .log();
       return null;
     }
@@ -274,7 +274,7 @@ public class EthPeer implements Comparable<EthPeer> {
       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 class EthPeer implements Comparable<EthPeer> {
   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 class EthPeer implements Comparable<EthPeer> {
   }
 
   @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

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthPeers.java

@@ -200,7 +200,7 @@ public class EthPeers {
         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 class EthPeers {
               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();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/EthProtocolManager.java

@@ -400,13 +400,16 @@ public class EthProtocolManager implements ProtocolManager, MinedBlockObserver {
     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 class EthProtocolManager implements ProtocolManager, MinedBlockObserver {
       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 @@ public class EthProtocolManager implements ProtocolManager, MinedBlockObserver {
     } 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 @@ public class EthProtocolManager implements ProtocolManager, MinedBlockObserver {
   }
 
   private Object getPeerOrPeerId(final EthPeer peer) {
-    return LOG.isTraceEnabled() ? peer : peer.getShortNodeId();
+    return LOG.isTraceEnabled() ? peer : peer.getLoggableId();
   }
 
   @Override

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractGetHeadersFromPeerTask.java

@@ -74,19 +74,19 @@ public abstract class AbstractGetHeadersFromPeerTask
     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 @@ public abstract class AbstractGetHeadersFromPeerTask
       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 @@ public abstract class AbstractGetHeadersFromPeerTask
         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 @@ public abstract class AbstractGetHeadersFromPeerTask
         .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 @@ public abstract class AbstractGetHeadersFromPeerTask
     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);

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractPeerRequestTask.java

@@ -110,7 +110,7 @@ public abstract class AbstractPeerRequestTask<R> extends AbstractPeerTask<R> {
       // 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);

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/AbstractRetryingSwitchingPeerTask.java

@@ -146,7 +146,7 @@ public abstract class AbstractRetryingSwitchingPeerTask<T> extends AbstractRetry
                 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();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/BufferedGetPooledTransactionsFromPeerFetcher.java

@@ -92,7 +92,7 @@ public class BufferedGetPooledTransactionsFromPeerFetcher {
                     .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 @@ public class BufferedGetPooledTransactionsFromPeerFetcher {
     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();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByHashTask.java

@@ -123,7 +123,7 @@ public class GetHeadersFromPeerByHashTask extends AbstractGetHeadersFromPeerTask
               .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);
         },

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetHeadersFromPeerByNumberTask.java

@@ -81,7 +81,7 @@ public class GetHeadersFromPeerByNumberTask extends AbstractGetHeadersFromPeerTa
               .setMessage("Requesting {} headers (blockNumber {}) from peer {}.")
               .addArgument(count)
               .addArgument(blockNumber)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getHeadersByNumber(blockNumber, count, skip, reverse);
         },

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetNodeDataFromPeerTask.java

@@ -69,7 +69,7 @@ public class GetNodeDataFromPeerTask extends AbstractPeerRequestTask<Map<Hash, B
           LOG.atTrace()
               .setMessage("Requesting {} node data entries from peer {}...")
               .addArgument(hashes::size)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getNodeData(hashes);
         },

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetPooledTransactionsFromPeerTask.java

@@ -64,7 +64,7 @@ public class GetPooledTransactionsFromPeerTask extends AbstractPeerRequestTask<L
           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));
         },

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/GetReceiptsFromPeerTask.java

@@ -86,7 +86,7 @@ public class GetReceiptsFromPeerTask
           LOG.atTrace()
               .setMessage("Requesting {} receipts from peer {}...")
               .addArgument(blockHeaders::size)
-              .addArgument(peer::getShortNodeId)
+              .addArgument(peer::getLoggableId)
               .log();
           return peer.getReceipts(blockHashes);
         },

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/RetryingGetBlocksFromPeersTask.java

@@ -80,7 +80,7 @@ public class RetryingGetBlocksFromPeersTask
               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);

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/manager/task/RetryingGetHeadersEndingAtFromPeerByHashTask.java

@@ -104,7 +104,7 @@ public class RetryingGetHeadersEndingAtFromPeerByHashTask
                     "No block headers for hash "
                         + referenceHash
                         + " returned by peer "
-                        + currentPeer.getShortNodeId());
+                        + currentPeer.getLoggableId());
               }
               result.complete(peerResult.getResult());
               return peerResult.getResult();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/ChainHeadTracker.java

@@ -68,7 +68,7 @@ public class ChainHeadTracker implements ConnectCallback {
   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 class ChainHeadTracker implements ConnectCallback {
                                 + " ("
                                 + 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);

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/TrailingPeerLimiter.java

@@ -69,7 +69,7 @@ public class TrailingPeerLimiter implements BlockAddedObserver {
               "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)"

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/PivotSelectorFromPeers.java

@@ -118,7 +118,7 @@ public class PivotSelectorFromPeers implements PivotBlockSelector {
   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();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncTargetManager.java

@@ -96,7 +96,7 @@ public class SyncTargetManager extends AbstractSyncTargetManager {
       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 @@ public class SyncTargetManager extends AbstractSyncTargetManager {
                 }
                 LOG.debug(
                     "Retrying best peer {} with new pivot block {}",
-                    bestPeer.getShortNodeId(),
+                    bestPeer.getLoggableId(),
                     pivotBlockHeader.toLogString());
                 return confirmPivotBlockHeader(bestPeer);
               } else {

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/tasks/RetryingGetHeaderFromPeerByHashTask.java

@@ -95,7 +95,7 @@ public class RetryingGetHeaderFromPeerByHashTask
                     "No block header for hash "
                         + referenceHash
                         + " returned by peer "
-                        + peer.getShortNodeId());
+                        + peer.getLoggableId());
               }
               result.complete(peerResult.getResult());
               return peerResult.getResult();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/transactions/NewPooledTransactionHashesMessageProcessor.java

@@ -87,7 +87,7 @@ public class NewPooledTransactionHashesMessageProcessor {
       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();

ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/manager/EthPeersTest.java

@@ -346,7 +346,7 @@ public class EthPeersTest {
             .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) {

ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/discovery/internal/DiscoveryProtocolLogger.java

@@ -47,9 +47,9 @@ public class DiscoveryProtocolLogger {
   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);
   }
@@ -57,9 +57,9 @@ public class DiscoveryProtocolLogger {
   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);
   }

ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/peers/DefaultPeerId.java

@@ -34,6 +34,11 @@ public class DefaultPeerId implements PeerId {
     return id;
   }
 
+  @Override
+  public String getLoggableId() {
+    return getId().slice(0, 8) + "...";
+  }
+
   @Override
   public Bytes32 keccak256() {
     if (keccak256 == null) {

ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/peers/PeerId.java

@@ -33,4 +33,6 @@ public interface PeerId {
    * @return The Keccak-256 hash of the peer's ID.
    */
   Bytes32 keccak256();
+
+  String getLoggableId();
 }

ethereum/p2p/src/main/java/org/hyperledger/besu/ethereum/p2p/rlpx/connections/AbstractPeerConnection.java

@@ -86,9 +86,9 @@ public abstract class AbstractPeerConnection implements PeerConnection {
     this.initiatedAt = System.currentTimeMillis();
 
     LOG.atDebug()
-        .setMessage("New PeerConnection ({}) established with peer {}...")
+        .setMessage("New PeerConnection ({}) established with peer {}")
         .addArgument(this)
-        .addArgument(peer.getId().slice(0, 16))
+        .addArgument(peer.getLoggableId())
         .log();
   }
 
@@ -188,9 +188,9 @@ public abstract class AbstractPeerConnection implements PeerConnection {
       connectionEventDispatcher.dispatchDisconnect(this, reason, false);
       doSend(null, DisconnectMessage.create(reason));
       LOG.atDebug()
-          .setMessage("Disconnecting connection {}, peer {}... reason {}")
+          .setMessage("Disconnecting connection {}, peer {} reason {}")
           .addArgument(this.hashCode())
-          .addArgument(peer.getId().slice(0, 16))
+          .addArgument(peer.getLoggableId())
           .addArgument(reason)
           .log();
       closeConnection();