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.

Sign up for GitHub

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

refactored logging for inclusion on gossip channels. #8733

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
f0e7ad4
refactored logging for inclusion on gossip channels.
rolfyone Oct 16, 2024
4985d4d
more message tweaks
rolfyone Oct 18, 2024
40602d1
removed some of the trace
rolfyone Oct 23, 2024
ec2c8f0
cleanup
rolfyone Oct 23, 2024
61b25de
Merge remote-tracking branch 'upstream/master' into debugging-inclusion
rolfyone Oct 23, 2024
f75b9e1
update "no active outbound stream" message
tbenr Oct 23, 2024
f9fe500
Merge branch 'master' into debugging-inclusion
tbenr Oct 23, 2024
5ccd460
revert to semicolon
tbenr Oct 23, 2024
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
4 changes: 2 additions & 2 deletions ...eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/AttestationGossipManager.java
View file
Open in desktop
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
10 changes: 8 additions & 2 deletions ...king/eth2/src/main/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -47,8 +47,14 @@ 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 {}; {}",
messageType,
lastErroredSlot,
rootCause.getMessage());
} else if (lastRootCause instanceof SemiDuplexNoOutboundStreamException) {
LOG.log(
suppress ? Level.DEBUG : Level.WARN,
"Failed to publish {}(s) for slot {} because no peers were available on the required gossip topic",
Copy link
Contributor

Choose a reason for hiding this comment

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

this seems to me the message for NoPeersForOutboundMessageException. And the above seems a more generic one so matching SemiDuplexNoOutboundStreamException

Expand Down
4 changes: 2 additions & 2 deletions ...main/java/tech/pegasys/teku/networking/eth2/gossip/SyncCommitteeMessageGossipManager.java
View file
Open in desktop
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
16 changes: 8 additions & 8 deletions .../eth2/src/test/java/tech/pegasys/teku/networking/eth2/gossip/GossipFailureLoggerTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,8 +13,8 @@

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;
import tech.pegasys.infrastructure.logging.LogCaptor;
import tech.pegasys.teku.infrastructure.unsigned.UInt64;
Expand Down Expand Up @@ -43,7 +43,7 @@ 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", new SemiDuplexNoOutboundStreamException("So Lonely")), SLOT);
Copy link
Contributor Author

Choose a reason for hiding this comment

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

this SemiDuplex exception used to share implementation with NoPeers error handling so this still tests the same thing and all the logic continues to work.

logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
}
}
Expand All @@ -52,12 +52,12 @@ void shouldLogFirstNoPeersErrorsAtWarningLevel() {
void shouldLogRepeatedNoPeersErrorsAtDebugLevel() {
try (final LogCaptor logCaptor = LogCaptor.forClass(GossipFailureLogger.class)) {
logger.logWithSuppression(
new RuntimeException("Foo", new NoPeersForOutboundMessageException("So Lonely")), SLOT);
new RuntimeException("Foo", new SemiDuplexNoOutboundStreamException("So Lonely")), SLOT);
logCaptor.clearLogs();

logger.logWithSuppression(
new IllegalStateException(
"Foo", new NoPeersForOutboundMessageException("Not a friend in the world")),
"Foo", new SemiDuplexNoOutboundStreamException("Not a friend in the world")),
SLOT);
logCaptor.assertDebugLog(NO_PEERS_MESSAGE);
}
Expand All @@ -67,12 +67,12 @@ 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", new SemiDuplexNoOutboundStreamException("So Lonely")), SLOT);
logCaptor.assertWarnLog(NO_PEERS_MESSAGE);

logger.logWithSuppression(
new IllegalStateException(
"Foo", new NoPeersForOutboundMessageException("Not a friend in the world")),
"Foo", new SemiDuplexNoOutboundStreamException("Not a friend in the world")),
UInt64.valueOf(2));
logCaptor.assertWarnLog(noPeersMessage(2));
}
Expand All @@ -82,15 +82,15 @@ 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", new SemiDuplexNoOutboundStreamException("So Lonely")), 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")),
"Foo", new SemiDuplexNoOutboundStreamException("Not a friend in the world")),
SLOT);
logCaptor.assertWarnLog(NO_PEERS_MESSAGE);
}
Expand Down
7 changes: 6 additions & 1 deletion ...rking/p2p/src/main/java/tech/pegasys/teku/networking/p2p/libp2p/gossip/GossipHandler.java
View file
Open in desktop
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()));
}
}