Monitor aggregated logs

beacon-chain/monitor/process_block.go

@@ -7,12 +7,16 @@ import (
 	types "github.com/prysmaticlabs/eth2-types"
 	"github.com/prysmaticlabs/prysm/beacon-chain/core/blocks"
 	"github.com/prysmaticlabs/prysm/beacon-chain/state"
+	"github.com/prysmaticlabs/prysm/config/params"
 	"github.com/prysmaticlabs/prysm/encoding/bytesutil"
 	"github.com/prysmaticlabs/prysm/proto/prysm/v1alpha1/block"
 	"github.com/prysmaticlabs/prysm/time/slots"
 	"github.com/sirupsen/logrus"
 )
 
+// Number of epochs between aggregate reports
+const AggregateReportingPeriod = 5
+
 // processBlock handles the cases when
 // 1) A block was proposed by one of our tracked validators
 // 2) An attestation by one of our tracked validators was included
@@ -53,6 +57,10 @@ func (s *Service) processBlock(ctx context.Context, b block.SignedBeaconBlock) {
 	s.processSyncAggregate(state, blk)
 	s.processProposedBlock(state, root, blk)
 	s.processAttestations(ctx, state, blk)
+
+	if blk.Slot()%AggregateReportingPeriod*params.BeaconConfig().SlotsPerEpoch == 0 {
+		s.logAggregatedPerformance()
+	}
 }
 
 // processProposedBlock logs the event that one of our tracked validators proposed a block that was included
@@ -129,3 +137,41 @@ func (s *Service) processSlashings(blk block.BeaconBlock) {
 		}
 	}
 }
+
+// logAggregatedPerformance logs the performance statistics collected since the run started
+func (s *Service) logAggregatedPerformance() {
+	s.RLock()
+	defer s.RUnlock()
+
+	for idx, p := range s.aggregatedPerformance {
+		if p.totalAttestedCount == 0 || p.totalRequestedCount == 0 || p.startBalance == 0 {
+			break
+		}
+		l, ok := s.latestPerformance[idx]
+		if !ok {
+			break
+		}
+		percentAtt := float64(p.totalAttestedCount) / float64(p.totalRequestedCount)
+		percentBal := float64(l.balance-p.startBalance) / float64(p.startBalance)
+		percentDistance := float64(p.totalDistance) / float64(p.totalAttestedCount)
+		percentCorrectSource := float64(p.totalCorrectSource) / float64(p.totalAttestedCount)
+		percentCorrectHead := float64(p.totalCorrectHead) / float64(p.totalAttestedCount)
+		percentCorrectTarget := float64(p.totalCorrectTarget) / float64(p.totalAttestedCount)
+
+		log.WithFields(logrus.Fields{
+			"ValidatorIndex":           idx,
+			"StartEpoch":               p.startEpoch,
+			"StartBalance":             p.startBalance,
+			"TotalRequested":           p.totalRequestedCount,
+			"AttestationInclusion":     fmt.Sprintf("%.2f%%", percentAtt*100),
+			"BalanceChangePct":         fmt.Sprintf("%.2f%%", percentBal*100),
+			"CorrectlyVotedSourcePct":  fmt.Sprintf("%.2f%%", percentCorrectSource*100),
+			"CorrectlyVotedTargetPct":  fmt.Sprintf("%.2f%%", percentCorrectTarget*100),
+			"CorrectlyVotedHeadPct":    fmt.Sprintf("%.2f%%", percentCorrectHead*100),
+			"AverageInclusionDistance": fmt.Sprintf("%.1f", percentDistance),
+			"TotalProposedBlocks":      p.totalProposedCount,
+			"TotalAggregations":        p.totalAggregations,
+			"TotalSyncContributions":   p.totalSyncComitteeContributions,
+		}).Info("Aggregated performance since launch")
+	}
+}

beacon-chain/monitor/process_block_test.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 	"testing"
+	"time"
 
 	types "github.com/prysmaticlabs/eth2-types"
 	"github.com/prysmaticlabs/prysm/beacon-chain/core/altair"
@@ -229,3 +230,17 @@ func TestProcessBlock_AllEventsTrackedVals(t *testing.T) {
 	require.LogsContain(t, hook, wanted3)
 	require.LogsContain(t, hook, wanted4)
 }
+
+func TestLogAggregatedPerformance(t *testing.T) {
+	hook := logTest.NewGlobal()
+	s := setupService(t)
+
+	s.logAggregatedPerformance()
+	time.Sleep(3000 * time.Millisecond)
+	wanted := "\"Aggregated performance since launch\" AttestationInclusion=\"80.00%\"" +
+		" AverageInclusionDistance=1.2 BalanceChangePct=\"0.95%\" CorrectlyVotedHeadPct=\"66.67%\" " +
+		"CorrectlyVotedSourcePct=\"91.67%\" CorrectlyVotedTargetPct=\"100.00%\" StartBalance=31700000000 " +
+		"StartEpoch=0 TotalAggregations=0 TotalProposedBlocks=1 TotalRequested=15 TotalSyncContributions=0 " +
+		"ValidatorIndex=1 prefix=monitor"
+	require.LogsContain(t, hook, wanted)
+}

beacon-chain/monitor/service_test.go

@@ -65,7 +65,19 @@ func setupService(t *testing.T) *Service {
 		},
 	}
 	aggregatedPerformance := map[types.ValidatorIndex]ValidatorAggregatedPerformance{
-		1:  {},
+		1: {
+			startEpoch:                     0,
+			startBalance:                   31700000000,
+			totalAttestedCount:             12,
+			totalRequestedCount:            15,
+			totalDistance:                  14,
+			totalCorrectHead:               8,
+			totalCorrectSource:             11,
+			totalCorrectTarget:             12,
+			totalProposedCount:             1,
+			totalSyncComitteeContributions: 0,
+			totalSyncComitteeAggregations:  0,
+		},
 		2:  {},
 		12: {},
 		15: {},