refactored logging for inclusion on gossip channels. (#8733)

--------- Signed-off-by: Paul Harris <[email protected]> Co-authored-by: Enrico Del Fante <[email protected]>
Consensys · Oct 23, 2024 · 3427b34 · 3427b34
1 parent d0b0bc1
commit 3427b34
Show file tree

Hide file tree

Showing 5 changed files with 48 additions and 21 deletions.
diff --git a/...eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java b/...eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java
@@ -68,12 +68,12 @@ public void onNewAttestation(final ValidatableAttestation validatableAttestation
   }
 
   public void subscribeToSubnetId(final int subnetId) {
-    LOG.trace("Subscribing to subnet ID {}", subnetId);
+    LOG.trace("Subscribing to attestation subnet {}", subnetId);
     subnetSubscriptions.subscribeToSubnetId(subnetId);
   }
 
   public void unsubscribeFromSubnetId(final int subnetId) {
-    LOG.trace("Unsubscribing to subnet ID {}", subnetId);
+    LOG.trace("Unsubscribing to attestation subnet {}", subnetId);
     subnetSubscriptions.unsubscribeFromSubnetId(subnetId);
   }
 

diff --git a/...king/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java b/...king/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java
@@ -47,11 +47,17 @@ public synchronized void logWithSuppression(final Throwable error, final UInt64
           "Failed to publish {}(s) for slot {} because the message has already been seen",
           messageType,
           lastErroredSlot);
-    } else if (lastRootCause instanceof NoPeersForOutboundMessageException
-        || lastRootCause instanceof SemiDuplexNoOutboundStreamException) {
+    } else if (lastRootCause instanceof NoPeersForOutboundMessageException) {
       LOG.log(
           suppress ? Level.DEBUG : Level.WARN,
-          "Failed to publish {}(s) for slot {} because no peers were available on the required gossip topic",
+          "Failed to publish {}(s) for slot {}; {}",
+          messageType,
+          lastErroredSlot,
+          rootCause.getMessage());
+    } else if (lastRootCause instanceof SemiDuplexNoOutboundStreamException) {
+      LOG.log(
+          suppress ? Level.DEBUG : Level.WARN,
+          "Failed to publish {}(s) for slot {} because no active outbound stream for the required gossip topic",
           messageType,
           lastErroredSlot);
     } else {

diff --git a/...main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java b/...main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java
@@ -115,12 +115,12 @@ private void publish(final SyncCommitteeMessage message, final int subnetId) {
   }
 
   public void subscribeToSubnetId(final int subnetId) {
-    LOG.trace("Subscribing to subnet ID {}", subnetId);
+    LOG.trace("Subscribing to sync committee subnet {}", subnetId);
     subnetSubscriptions.subscribeToSubnetId(subnetId);
   }
 
   public void unsubscribeFromSubnetId(final int subnetId) {
-    LOG.trace("Unsubscribing to subnet ID {}", subnetId);
+    LOG.trace("Unsubscribing to sync committee subnet {}", subnetId);
     subnetSubscriptions.unsubscribeFromSubnetId(subnetId);
   }
 

diff --git a/.../eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java b/.../eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java
@@ -13,6 +13,7 @@
 
 package tech.pegasys.teku.networking.eth2.gossip;
 
+import io.libp2p.core.SemiDuplexNoOutboundStreamException;
 import io.libp2p.pubsub.MessageAlreadySeenException;
 import io.libp2p.pubsub.NoPeersForOutboundMessageException;
 import org.junit.jupiter.api.Test;
@@ -24,7 +25,12 @@ class GossipFailureLoggerTest {
   public static final String ALREADY_SEEN_MESSAGE =
       "Failed to publish thingy(s) for slot 1 because the message has already been seen";
   public static final UInt64 SLOT = UInt64.ONE;
+  public static final SemiDuplexNoOutboundStreamException NO_ACTIVE_STREAM_EXCEPTION =
+      new SemiDuplexNoOutboundStreamException("So Lonely");
+  public static final NoPeersForOutboundMessageException NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION =
+      new NoPeersForOutboundMessageException("no peers");
   public static final String NO_PEERS_MESSAGE = noPeersMessage(SLOT.intValue());
+  public static final String NO_ACTIVE_STREAM_MESSAGE = noActiveStreamMessage(SLOT.intValue());
 
   public static final String GENERIC_FAILURE_MESSAGE = "Failed to publish thingy(s) for slot 1";
 
@@ -43,22 +49,28 @@ void shouldLogAlreadySeenErrorsAtDebugLevel() {
   void shouldLogFirstNoPeersErrorsAtWarningLevel() {
     try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
       logger.logWithSuppression(
-          new RuntimeException("Foo", new NoPeersForOutboundMessageException("So Lonely")), SLOT);
+          new RuntimeException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
     }
   }
 
+  @Test
+  void shouldLogFirstNoActiveStreamErrorsAtWarningLevel() {
+    try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
+      logger.logWithSuppression(new RuntimeException("Foo", NO_ACTIVE_STREAM_EXCEPTION), SLOT);
+      logCaptor.assertWarnLog(NO_ACTIVE_STREAM_MESSAGE);
+    }
+  }
+
   @Test
   void shouldLogRepeatedNoPeersErrorsAtDebugLevel() {
     try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
       logger.logWithSuppression(
-          new RuntimeException("Foo", new NoPeersForOutboundMessageException("So Lonely")), SLOT);
+          new RuntimeException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.clearLogs();
 
       logger.logWithSuppression(
-          new IllegalStateException(
-              "Foo", new NoPeersForOutboundMessageException("Not a friend in the world")),
-          SLOT);
+          new IllegalStateException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.assertDebugLog(NO_PEERS_MESSAGE);
     }
   }
@@ -67,12 +79,11 @@ void shouldLogRepeatedNoPeersErrorsAtDebugLevel() {
   void shouldLogNoPeersErrorsWithDifferentSlotsAtWarnLevel() {
     try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
       logger.logWithSuppression(
-          new RuntimeException("Foo", new NoPeersForOutboundMessageException("So Lonely")), SLOT);
+          new RuntimeException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
 
       logger.logWithSuppression(
-          new IllegalStateException(
-              "Foo", new NoPeersForOutboundMessageException("Not a friend in the world")),
+          new IllegalStateException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION),
           UInt64.valueOf(2));
       logCaptor.assertWarnLog(noPeersMessage(2));
     }
@@ -82,16 +93,14 @@ void shouldLogNoPeersErrorsWithDifferentSlotsAtWarnLevel() {
   void shouldLogNoPeersErrorsAtWarnLevelWhenSeparatedByADifferentException() {
     try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
       logger.logWithSuppression(
-          new RuntimeException("Foo", new NoPeersForOutboundMessageException("So Lonely")), SLOT);
+          new RuntimeException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
       logCaptor.clearLogs();
 
       logger.logWithSuppression(new MessageAlreadySeenException("Dupe"), SLOT);
 
       logger.logWithSuppression(
-          new IllegalStateException(
-              "Foo", new NoPeersForOutboundMessageException("Not a friend in the world")),
-          SLOT);
+          new IllegalStateException("Foo", NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION), SLOT);
       logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
     }
   }
@@ -136,6 +145,13 @@ void shouldLogMultipleGenericErrorsWithDifferentCausesAtErrorLevel() {
   private static String noPeersMessage(final int slot) {
     return "Failed to publish thingy(s) for slot "
         + slot
-        + " because no peers were available on the required gossip topic";
+        + "; "
+        + NO_PEERS_FOR_OUTBOUND_MESSAGE_EXCEPTION.getMessage();
+  }
+
+  private static String noActiveStreamMessage(final int slot) {
+    return "Failed to publish thingy(s) for slot "
+        + slot
+        + " because no active outbound stream for the required gossip topic";
   }
 }
diff --git a/...rking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java b/...rking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java
@@ -13,6 +13,7 @@
 
 package tech.pegasys.teku.networking.p2p.libp2p.gossip;
 
+import com.google.common.base.Throwables;
 import io.libp2p.core.pubsub.MessageApi;
 import io.libp2p.core.pubsub.PubsubPublisherApi;
 import io.libp2p.core.pubsub.Topic;
@@ -87,6 +88,10 @@ public void gossip(final Bytes bytes) {
     SafeFuture.of(publisher.publish(Unpooled.wrappedBuffer(bytes.toArrayUnsafe()), topic))
         .finish(
             () -> LOG.trace("Successfully gossiped message on {}", topic),
-            err -> LOG.debug("Failed to gossip message on " + topic, err));
+            err ->
+                LOG.debug(
+                    "Failed to gossip message on {}, {}",
+                    topic,
+                    Throwables.getRootCause(err).getMessage()));
   }
 }