chore(proposervm): timestamp metrics for block acceptance (#3680)

Signed-off-by: Arran Schlosberg <519948+ARR4N@users.noreply.github.com>
Co-authored-by: Darioush Jalali <darioush.jalali@avalabs.org>
Co-authored-by: Quentin McGaw <quentin.mcgaw@avalabs.org>

Author: 3 people

vms/proposervm/post_fork_block.go

@@ -5,6 +5,7 @@ package proposervm
 
 import (
 	"context"
+	"time"
 
 	"github.com/ava-labs/avalanchego/ids"
 	"github.com/ava-labs/avalanchego/snow/consensus/snowman"
@@ -37,9 +38,21 @@ func (b *postForkBlock) Accept(ctx context.Context) error {
 	if b.slot != nil {
 		b.vm.acceptedBlocksSlotHistogram.Observe(float64(*b.slot))
 	}
+	b.updateLastAcceptedTimestampMetric(outerBlockTypeMetricLabel, b.Timestamp())
+	b.updateLastAcceptedTimestampMetric(innerBlockTypeMetricLabel, b.innerBlk.Timestamp())
 	return nil
 }
 
+const (
+	innerBlockTypeMetricLabel = "inner"
+	outerBlockTypeMetricLabel = "proposervm"
+)
+
+func (b *postForkBlock) updateLastAcceptedTimestampMetric(blockTypeLabel string, t time.Time) {
+	g := b.vm.lastAcceptedTimestampGaugeVec.WithLabelValues(blockTypeLabel)
+	g.Set(float64(t.Unix()))
+}
+
 func (b *postForkBlock) acceptOuterBlk() error {
 	// Update in-memory references
 	b.vm.lastAcceptedTime = b.Timestamp()

vms/proposervm/vm.go

@@ -105,6 +105,10 @@ type VM struct {
 	// acceptedBlocksSlotHistogram reports the slots that accepted blocks were
 	// proposed in.
 	acceptedBlocksSlotHistogram prometheus.Histogram
+
+	// lastAcceptedTimestampGaugeVec reports timestamps for the last-accepted
+	// [postForkBlock] and its inner block.
+	lastAcceptedTimestampGaugeVec *prometheus.GaugeVec
 }
 
 // New performs best when [minBlkDelay] is whole seconds. This is because block
@@ -231,10 +235,18 @@ func (vm *VM) Initialize(
 		// of comparing floating point of the same numerical value.
 		Buckets: []float64{0.5, 1.5, 2.5},
 	})
+	vm.lastAcceptedTimestampGaugeVec = prometheus.NewGaugeVec(
+		prometheus.GaugeOpts{
+			Name: "last_accepted_timestamp",
+			Help: "timestamp of the last block accepted",
+		},
+		[]string{"block_type"},
+	)
 
 	return errors.Join(
 		vm.Config.Registerer.Register(vm.proposerBuildSlotGauge),
 		vm.Config.Registerer.Register(vm.acceptedBlocksSlotHistogram),
+		vm.Config.Registerer.Register(vm.lastAcceptedTimestampGaugeVec),
 	)
 }
 

vms/proposervm/vm_test.go

@@ -13,6 +13,7 @@ import (
 	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/testutil"
 	"github.com/stretchr/testify/require"
 	"go.uber.org/mock/gomock"
 
@@ -2530,3 +2531,43 @@ func TestLocalParse(t *testing.T) {
 		})
 	}
 }
+
+func TestTimestampMetrics(t *testing.T) {
+	ctx := context.Background()
+
+	coreVM, _, proVM, _ := initTestProposerVM(t, time.Unix(0, 0), mockable.MaxTime, 0)
+	defer func() {
+		require.NoError(t, proVM.Shutdown(ctx))
+	}()
+
+	innerBlock := snowmantest.BuildChild(snowmantest.Genesis)
+
+	outerTime := time.Unix(314159, 0)
+	innerTime := time.Unix(142857, 0)
+	proVM.Clock.Set(outerTime)
+	innerBlock.TimestampV = innerTime
+
+	coreVM.BuildBlockF = func(context.Context) (snowman.Block, error) {
+		return innerBlock, nil
+	}
+	outerBlock, err := proVM.BuildBlock(ctx)
+	require.NoError(t, err)
+	require.IsType(t, &postForkBlock{}, outerBlock)
+	require.NoError(t, outerBlock.Accept(ctx))
+
+	gaugeVec := proVM.lastAcceptedTimestampGaugeVec
+	tests := []struct {
+		blockType string
+		want      time.Time
+	}{
+		{innerBlockTypeMetricLabel, innerTime},
+		{outerBlockTypeMetricLabel, outerTime},
+	}
+	for _, tt := range tests {
+		t.Run(tt.blockType, func(t *testing.T) {
+			gauge, err := gaugeVec.GetMetricWithLabelValues(tt.blockType)
+			require.NoError(t, err)
+			require.Equal(t, float64(tt.want.Unix()), testutil.ToFloat64(gauge))
+		})
+	}
+}