Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactored logging for inclusion on gossip channels. #8733

Merged
merged 8 commits into from
Oct 23, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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";

Expand All @@ -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);
}
}
Expand All @@ -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));
}
Expand All @@ -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);
}
}
Expand Down Expand Up @@ -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";
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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));
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the full stack here got pretty unusable pretty quickly.

err ->
LOG.debug(
"Failed to gossip message on {}, {}",
topic,
Throwables.getRootCause(err).getMessage()));
}
}