From 8aed71fe2090f8abad51de97793f89e8e1d51d32 Mon Sep 17 00:00:00 2001 From: Courtney <45641759+courtneyeh@users.noreply.github.com> Date: Fri, 27 Oct 2023 14:11:50 +1300 Subject: [PATCH] Capture time taken creating and signing attestations in AttestationProductionDuty (#7630) * Capture time taken creating and signing attestations in AttestationProductionDuty * Update signing timer * Validate before recording metric --- .../attestations/AttestationDutyFactory.java | 3 +- .../AttestationProductionDuty.java | 35 +++++++++++---- .../duties/AttestationProductionDutyTest.java | 44 ++++++++++++++++++- 3 files changed, 70 insertions(+), 12 deletions(-) diff --git a/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationDutyFactory.java b/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationDutyFactory.java index 660d8c09ae4..f0bbeafe82e 100644 --- a/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationDutyFactory.java +++ b/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationDutyFactory.java @@ -51,7 +51,8 @@ public AttestationProductionDuty createProductionDuty( slot, forkProvider, validatorApiChannel, - new BatchAttestationSendingStrategy<>(validatorApiChannel::sendSignedAttestations)); + new BatchAttestationSendingStrategy<>(validatorApiChannel::sendSignedAttestations), + validatorDutyMetrics); } @Override diff --git a/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationProductionDuty.java b/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationProductionDuty.java index e70192cd64f..2abb0585336 100644 --- a/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationProductionDuty.java +++ b/validator/client/src/main/java/tech/pegasys/teku/validator/client/duties/attestations/AttestationProductionDuty.java @@ -38,6 +38,8 @@ import tech.pegasys.teku.validator.client.duties.DutyResult; import tech.pegasys.teku.validator.client.duties.DutyType; import tech.pegasys.teku.validator.client.duties.ProductionResult; +import tech.pegasys.teku.validator.client.duties.ValidatorDutyMetrics; +import tech.pegasys.teku.validator.client.duties.ValidatorDutyMetrics.Step; public class AttestationProductionDuty implements Duty { private static final Logger LOG = LogManager.getLogger(); @@ -48,18 +50,21 @@ public class AttestationProductionDuty implements Duty { private final ForkProvider forkProvider; private final ValidatorApiChannel validatorApiChannel; private final SendingStrategy sendingStrategy; + private final ValidatorDutyMetrics validatorDutyMetrics; public AttestationProductionDuty( final Spec spec, final UInt64 slot, final ForkProvider forkProvider, final ValidatorApiChannel validatorApiChannel, - final SendingStrategy sendingStrategy) { + final SendingStrategy sendingStrategy, + final ValidatorDutyMetrics validatorDutyMetrics) { this.spec = spec; this.slot = slot; this.forkProvider = forkProvider; this.validatorApiChannel = validatorApiChannel; this.sendingStrategy = sendingStrategy; + this.validatorDutyMetrics = validatorDutyMetrics; } @Override @@ -121,7 +126,10 @@ private List>> produceAttestationsForCo final int committeeIndex, final ScheduledCommittee committee) { final SafeFuture> unsignedAttestationFuture = - validatorApiChannel.createAttestationData(slot, committeeIndex); + validatorDutyMetrics.record( + () -> validatorApiChannel.createAttestationData(slot, committeeIndex), + this, + ValidatorDutyMetrics.Step.CREATE); unsignedAttestationFuture.propagateTo(committee.getAttestationDataFuture()); return committee.getValidators().stream() @@ -143,8 +151,14 @@ private SafeFuture> signAttestationForValidatorInC maybeUnsignedAttestation -> maybeUnsignedAttestation .map( - attestationData -> - signAttestationForValidator(slot, forkInfo, attestationData, validator)) + attestationData -> { + validateAttestationData(slot, attestationData); + return validatorDutyMetrics.record( + () -> + signAttestationForValidator(forkInfo, attestationData, validator), + this, + Step.SIGN); + }) .orElseGet( () -> SafeFuture.completedFuture( @@ -159,16 +173,19 @@ private SafeFuture> signAttestationForValidatorInC .exceptionally(error -> ProductionResult.failure(validator.getPublicKey(), error)); } - private SafeFuture> signAttestationForValidator( - final UInt64 slot, - final ForkInfo forkInfo, - final AttestationData attestationData, - final ValidatorWithCommitteePositionAndIndex validator) { + private static void validateAttestationData( + final UInt64 slot, final AttestationData attestationData) { checkArgument( attestationData.getSlot().equals(slot), "Unsigned attestation slot (%s) does not match expected slot %s", attestationData.getSlot(), slot); + } + + private SafeFuture> signAttestationForValidator( + final ForkInfo forkInfo, + final AttestationData attestationData, + final ValidatorWithCommitteePositionAndIndex validator) { return validator .getSigner() .signAttestationData(attestationData, forkInfo) diff --git a/validator/client/src/test/java/tech/pegasys/teku/validator/client/duties/AttestationProductionDutyTest.java b/validator/client/src/test/java/tech/pegasys/teku/validator/client/duties/AttestationProductionDutyTest.java index 02a2d991464..a6f8d0df07e 100644 --- a/validator/client/src/test/java/tech/pegasys/teku/validator/client/duties/AttestationProductionDutyTest.java +++ b/validator/client/src/test/java/tech/pegasys/teku/validator/client/duties/AttestationProductionDutyTest.java @@ -20,6 +20,7 @@ import static org.mockito.ArgumentMatchers.argThat; import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.spy; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.verifyNoInteractions; @@ -39,6 +40,7 @@ import tech.pegasys.teku.bls.BLSSignature; import tech.pegasys.teku.infrastructure.async.SafeFuture; import tech.pegasys.teku.infrastructure.logging.ValidatorLogger; +import tech.pegasys.teku.infrastructure.metrics.StubMetricsSystem; import tech.pegasys.teku.infrastructure.ssz.collections.SszBitlist; import tech.pegasys.teku.infrastructure.unsigned.UInt64; import tech.pegasys.teku.spec.Spec; @@ -54,6 +56,7 @@ import tech.pegasys.teku.validator.api.ValidatorApiChannel; import tech.pegasys.teku.validator.client.ForkProvider; import tech.pegasys.teku.validator.client.Validator; +import tech.pegasys.teku.validator.client.duties.ValidatorDutyMetrics.Step; import tech.pegasys.teku.validator.client.duties.attestations.AttestationProductionDuty; import tech.pegasys.teku.validator.client.duties.attestations.BatchAttestationSendingStrategy; @@ -68,6 +71,8 @@ class AttestationProductionDutyTest { private final ForkProvider forkProvider = mock(ForkProvider.class); private final ValidatorApiChannel validatorApiChannel = mock(ValidatorApiChannel.class); private final ValidatorLogger validatorLogger = mock(ValidatorLogger.class); + private final ValidatorDutyMetrics validatorDutyMetrics = + spy(ValidatorDutyMetrics.create(new StubMetricsSystem())); private final AttestationProductionDuty duty = new AttestationProductionDuty( @@ -75,7 +80,8 @@ class AttestationProductionDutyTest { SLOT, forkProvider, validatorApiChannel, - new BatchAttestationSendingStrategy<>(validatorApiChannel::sendSignedAttestations)); + new BatchAttestationSendingStrategy<>(validatorApiChannel::sendSignedAttestations), + validatorDutyMetrics); @BeforeEach public void setUp() { @@ -88,7 +94,7 @@ public void setUp() { public void shouldNotProduceAnyAttestationsWhenNoValidatorsAdded() { performAndReportDuty(); - verifyNoInteractions(validatorApiChannel, validatorLogger); + verifyNoInteractions(validatorApiChannel, validatorLogger, validatorDutyMetrics); } @Test @@ -109,6 +115,9 @@ public void shouldFailWhenUnsignedAttestationCanNotBeCreated() { eq(Set.of(validator.getPublicKey().toAbbreviatedString())), any(IllegalStateException.class)); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); } @Test @@ -154,6 +163,10 @@ public void shouldPublishProducedAttestationsWhenSomeUnsignedAttestationsCanNotB eq(Set.of(validator1.getPublicKey().toAbbreviatedString())), any(IllegalStateException.class)); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics, times(2)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics).record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @Test @@ -198,6 +211,10 @@ public void shouldPublishProducedAttestationsWhenSomeUnsignedAttestationsFail() verify(validatorLogger) .dutyFailed(TYPE, SLOT, Set.of(validator1.getPublicKey().toAbbreviatedString()), failure); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics, times(2)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics).record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @Test @@ -237,6 +254,11 @@ public void shouldPublishProducedAttestationsWhenSignerFailsForSomeAttestations( .dutyFailed( TYPE, SLOT, Set.of(validator1.getPublicKey().toAbbreviatedString()), signingFailure); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics, times(2)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @Test @@ -260,6 +282,10 @@ public void shouldCreateAttestationForSingleValidator() { .dutyCompleted( TYPE, SLOT, 1, Set.of(attestationData.getBeaconBlockRoot()), Optional.empty()); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics).record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @Test @@ -294,6 +320,10 @@ void shouldReportFailureWhenAttestationIsInvalid() { error instanceof RestApiReportedException && error.getMessage().equals("Naughty attestation"))); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics).record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @SuppressWarnings("unchecked") @@ -345,6 +375,11 @@ public void shouldCreateAttestationForMultipleValidatorsInSameCommittee() { .dutyCompleted( TYPE, SLOT, 3, Set.of(attestationData.getBeaconBlockRoot()), Optional.empty()); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics, times(3)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } @SuppressWarnings("unchecked") @@ -406,6 +441,11 @@ public void shouldCreateAttestationForMultipleValidatorsInDifferentCommittees() unsignedAttestation2.getBeaconBlockRoot()), Optional.empty()); verifyNoMoreInteractions(validatorLogger); + + verify(validatorDutyMetrics, times(2)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.CREATE)); + verify(validatorDutyMetrics, times(3)) + .record(any(), any(AttestationProductionDuty.class), eq(Step.SIGN)); } public Validator createValidator() {