diff --git a/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java b/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java index 5f93c7c288c..11851a9b07d 100644 --- a/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java +++ b/networking/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/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java b/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java index 3fbae013bf0..a726ec68980 100644 --- a/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java +++ b/networking/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/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java b/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java index 3c1692e90dc..572291cd344 100644 --- a/networking/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java +++ b/networking/eth2/src/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/networking/eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java b/networking/eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java index 6f87429ba32..88b457f393d 100644 --- a/networking/eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java +++ b/networking/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/networking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java b/networking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java index 73a0749c4e0..c06b5f9d22f 100644 --- a/networking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java +++ b/networking/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())); } }