Merge branch 'develop' into use-middleware-to-log-grpc-start

activation/activation.go

@@ -46,7 +46,15 @@ func DefaultPoetConfig() PoetConfig {
 	}
 }
 
-const defaultPoetRetryInterval = 5 * time.Second
+const (
+	defaultPoetRetryInterval = 5 * time.Second
+
+	// Jitter added to the wait time before building a nipost challenge.
+	// It's expressed as % of poet grace period which translates to:
+	//  mainnet (grace period 1h) -> 36s
+	//  systest (grace period 10s) -> 0.1s
+	maxNipostChallengeBuildJitter = 1.0
+)
 
 // Config defines configuration for Builder.
 type Config struct {
@@ -432,8 +440,8 @@ func (b *Builder) buildNIPostChallenge(ctx context.Context) (*types.NIPostChalle
 			ErrATXChallengeExpired, current, -until)
 	}
 	metrics.PublishOntimeWindowLatency.Observe(until.Seconds())
-	if until > b.poetCfg.GracePeriod {
-		wait := until - b.poetCfg.GracePeriod
+	wait := timeToWaitToBuildNipostChallenge(until, b.poetCfg.GracePeriod)
+	if wait >= 0 {
 		b.log.WithContext(ctx).With().Debug("waiting for fresh atxs",
 			log.Duration("till poet round", until),
 			log.Uint32("current epoch", current.Uint32()),
@@ -721,3 +729,8 @@ func SignAndFinalizeAtx(signer *signing.EdSigner, atx *types.ActivationTx) error
 	atx.SmesherID = signer.NodeID()
 	return atx.Initialize()
 }
+
+func timeToWaitToBuildNipostChallenge(untilRoundStart, gracePeriod time.Duration) time.Duration {
+	jitter := randomDurationInRange(time.Duration(0), gracePeriod*maxNipostChallengeBuildJitter/100.0)
+	return untilRoundStart + jitter - gracePeriod
+}

activation/activation_test.go

@@ -1265,3 +1265,36 @@ func TestWaitPositioningAtx(t *testing.T) {
 		})
 	}
 }
+
+func TestWaitingToBuildNipostChallengeWithJitter(t *testing.T) {
+	t.Run("before grace period", func(t *testing.T) {
+		//          ┌──grace period──┐
+		//          │                │
+		// ───▲─────|──────|─────────|----> time
+		//    │     └jitter|         └round start
+		//   now
+		wait := timeToWaitToBuildNipostChallenge(2*time.Hour, time.Hour)
+		require.Greater(t, wait, time.Hour)
+		require.LessOrEqual(t, wait, time.Hour+time.Second*36)
+	})
+	t.Run("after grace period, within max jitter value", func(t *testing.T) {
+		//          ┌──grace period──┐
+		//          │                │
+		// ─────────|──▲────|────────|----> time
+		//          └ji│tter|        └round start
+		//            now
+		wait := timeToWaitToBuildNipostChallenge(time.Hour-time.Second*10, time.Hour)
+		require.GreaterOrEqual(t, wait, -time.Second*10)
+		// jitter is 1% = 36s for 1h grace period
+		require.LessOrEqual(t, wait, time.Second*(36-10))
+	})
+	t.Run("after jitter max value", func(t *testing.T) {
+		//          ┌──grace period──┐
+		//          │                │
+		// ─────────|──────|──▲──────|----> time
+		//          └jitter|  │       └round start
+		//                   now
+		wait := timeToWaitToBuildNipostChallenge(time.Hour-time.Second*37, time.Hour)
+		require.Less(t, wait, time.Duration(0))
+	})
+}

activation/nipost.go

@@ -6,6 +6,7 @@ import (
 	"encoding/hex"
 	"errors"
 	"fmt"
+	"math/rand"
 	"time"
 
 	"github.com/spacemeshos/merkle-tree"
@@ -22,6 +23,24 @@ import (
 	"github.com/spacemeshos/go-spacemesh/signing"
 )
 
+const (
+	// Jitter values to avoid all nodes querying the poet at the same time.
+	// Note: the jitter values are represented as a percentage of cycle gap.
+	//  mainnet cycle-gap: 12h
+	//  systest cycle-gap: 30s
+
+	// Minimum jitter value before querying for the proof.
+	// Gives the poet service time to generate proof after a round ends (~8s on mainnet).
+	//  mainnet -> 8.64s
+	//  systest -> 0.36s
+	minPoetGetProofJitter = 0.02
+
+	// The maximum jitter value before querying for the proof.
+	//  mainnet -> 17.28s
+	//  systest -> 0.72s
+	maxPoetGetProofJitter = 0.04
+)
+
 //go:generate mockgen -package=activation -destination=./nipost_mocks.go -source=./nipost.go PoetProvingServiceClient
 
 // PoetProvingServiceClient provides a gateway to a trust-less public proving service, which may serve many PoET
@@ -385,10 +404,7 @@ func (nb *NIPostBuilder) getBestProof(ctx context.Context, challenge types.Hash3
 			continue
 		}
 		round := r.PoetRound.ID
-		// Time to wait before querying for the proof
-		// The additional second is an optimization to be nicer to poet
-		// and don't accidentally ask it to soon and have to retry.
-		waitTime := time.Until(r.PoetRound.End.IntoTime()) + time.Second
+		waitTime := calcGetProofWaitTime(time.Until(r.PoetRound.End.IntoTime()), nb.poetCfg.CycleGap)
 		eg.Go(func() error {
 			logger.With().Info("waiting till poet round end", log.Duration("wait time", waitTime))
 			select {
@@ -479,3 +495,16 @@ func constructMerkleProof(challenge types.Hash32, members []types.Member) (*type
 		Nodes:     nodesH32,
 	}, nil
 }
+
+func randomDurationInRange(min, max time.Duration) time.Duration {
+	return min + time.Duration(rand.Int63n(int64(max-min+1)))
+}
+
+// Calculate the time to wait before querying for the proof
+// We add a jitter to avoid all nodes querying for the proof at the same time.
+func calcGetProofWaitTime(tillRoundEnd, cycleGap time.Duration) (waitTime time.Duration) {
+	minJitter := time.Duration(float64(cycleGap) * minPoetGetProofJitter / 100.0)
+	maxJitter := time.Duration(float64(cycleGap) * maxPoetGetProofJitter / 100.0)
+	jitter := randomDurationInRange(minJitter, maxJitter)
+	return tillRoundEnd + jitter
+}

activation/nipost_test.go

@@ -1054,3 +1054,39 @@ func FuzzBuilderStateConsistency(f *testing.F) {
 func FuzzBuilderStateSafety(f *testing.F) {
 	tester.FuzzSafety[types.NIPostBuilderState](f)
 }
+
+func TestRandomDurationInRange(t *testing.T) {
+	t.Parallel()
+	test := func(min, max time.Duration) {
+		for i := 0; i < 100; i++ {
+			waittime := randomDurationInRange(min, max)
+			require.LessOrEqual(t, waittime, max)
+			require.GreaterOrEqual(t, waittime, min)
+		}
+	}
+	t.Run("min = 0", func(t *testing.T) {
+		t.Parallel()
+		test(0, 7*time.Second)
+	})
+	t.Run("min != 0", func(t *testing.T) {
+		t.Parallel()
+		test(5*time.Second, 7*time.Second)
+	})
+}
+
+func TestCalculatingGetProofWaitTime(t *testing.T) {
+	t.Parallel()
+	t.Run("past round end", func(t *testing.T) {
+		t.Parallel()
+		waitTime := calcGetProofWaitTime(-time.Hour, time.Hour*12)
+		require.Less(t, waitTime, time.Duration(0))
+	})
+	t.Run("before round end", func(t *testing.T) {
+		t.Parallel()
+		cycleGap := 12 * time.Hour
+		waitTime := calcGetProofWaitTime(time.Hour, cycleGap)
+
+		require.Greater(t, waitTime, time.Hour+time.Duration(float64(cycleGap)*minPoetGetProofJitter/100))
+		require.LessOrEqual(t, waitTime, time.Hour+time.Duration(float64(cycleGap)*maxPoetGetProofJitter/100))
+	})
+}

api/grpcserver/smesher_service.go

@@ -238,6 +238,7 @@ func statusToPbStatus(status *activation.PostSetupStatus) *pb.PostSetupStatus {
 	if status.LastOpts != nil {
 		var providerID *uint32
 		if status.LastOpts.ProviderID.Value() != nil {
+			providerID = new(uint32)
 			*providerID = uint32(*status.LastOpts.ProviderID.Value())
 		}
 

api/grpcserver/smesher_service_test.go

@@ -116,3 +116,85 @@ func TestSmesherService_PostSetupProviders(t *testing.T) {
 	require.EqualValues(t, providers[1].ID, resp.Providers[1].Id)
 	require.Equal(t, uint64(100_000), resp.Providers[1].Performance)
 }
+
+func TestSmesherService_PostSetupStatus(t *testing.T) {
+	t.Run("completed", func(t *testing.T) {
+		ctrl := gomock.NewController(t)
+		postSetupProvider := activation.NewMockpostSetupProvider(ctrl)
+		smeshingProvider := activation.NewMockSmeshingProvider(ctrl)
+		svc := grpcserver.NewSmesherService(postSetupProvider, smeshingProvider, time.Second, activation.DefaultPostSetupOpts(), logtest.New(t).WithName("grpc.Smesher"))
+
+		postSetupProvider.EXPECT().Status().Return(&activation.PostSetupStatus{
+			State:            activation.PostSetupStateComplete,
+			NumLabelsWritten: 1_000,
+			LastOpts:         nil,
+		})
+		resp, err := svc.PostSetupStatus(context.Background(), &emptypb.Empty{})
+		require.NoError(t, err)
+		require.Equal(t, pb.PostSetupStatus_STATE_COMPLETE, resp.Status.State)
+		require.EqualValues(t, 1_000, resp.Status.NumLabelsWritten)
+		require.Nil(t, resp.Status.Opts)
+	})
+
+	t.Run("completed with last Opts", func(t *testing.T) {
+		ctrl := gomock.NewController(t)
+		postSetupProvider := activation.NewMockpostSetupProvider(ctrl)
+		smeshingProvider := activation.NewMockSmeshingProvider(ctrl)
+		svc := grpcserver.NewSmesherService(postSetupProvider, smeshingProvider, time.Second, activation.DefaultPostSetupOpts(), logtest.New(t).WithName("grpc.Smesher"))
+
+		id := activation.PostProviderID{}
+		id.SetInt64(1)
+		opts := activation.PostSetupOpts{
+			DataDir:     "data-dir",
+			NumUnits:    4,
+			MaxFileSize: 1024,
+			ProviderID:  id,
+			Throttle:    true,
+		}
+		postSetupProvider.EXPECT().Status().Return(&activation.PostSetupStatus{
+			State:            activation.PostSetupStateComplete,
+			NumLabelsWritten: 1_000,
+			LastOpts:         &opts,
+		})
+		resp, err := svc.PostSetupStatus(context.Background(), &emptypb.Empty{})
+		require.NoError(t, err)
+		require.Equal(t, pb.PostSetupStatus_STATE_COMPLETE, resp.Status.State)
+		require.EqualValues(t, 1_000, resp.Status.NumLabelsWritten)
+		require.Equal(t, "data-dir", resp.Status.Opts.DataDir)
+		require.EqualValues(t, 4, resp.Status.Opts.NumUnits)
+		require.EqualValues(t, 1024, resp.Status.Opts.MaxFileSize)
+		require.EqualValues(t, 1, *resp.Status.Opts.ProviderId)
+		require.True(t, resp.Status.Opts.Throttle)
+	})
+
+	t.Run("in progress", func(t *testing.T) {
+		ctrl := gomock.NewController(t)
+		postSetupProvider := activation.NewMockpostSetupProvider(ctrl)
+		smeshingProvider := activation.NewMockSmeshingProvider(ctrl)
+		svc := grpcserver.NewSmesherService(postSetupProvider, smeshingProvider, time.Second, activation.DefaultPostSetupOpts(), logtest.New(t).WithName("grpc.Smesher"))
+
+		id := activation.PostProviderID{}
+		id.SetInt64(100)
+		opts := activation.PostSetupOpts{
+			DataDir:     "data-dir",
+			NumUnits:    4,
+			MaxFileSize: 1024,
+			ProviderID:  id,
+			Throttle:    false,
+		}
+		postSetupProvider.EXPECT().Status().Return(&activation.PostSetupStatus{
+			State:            activation.PostSetupStateInProgress,
+			NumLabelsWritten: 1_000,
+			LastOpts:         &opts,
+		})
+		resp, err := svc.PostSetupStatus(context.Background(), &emptypb.Empty{})
+		require.NoError(t, err)
+		require.Equal(t, pb.PostSetupStatus_STATE_IN_PROGRESS, resp.Status.State)
+		require.EqualValues(t, 1_000, resp.Status.NumLabelsWritten)
+		require.Equal(t, "data-dir", resp.Status.Opts.DataDir)
+		require.EqualValues(t, 4, resp.Status.Opts.NumUnits)
+		require.EqualValues(t, 1024, resp.Status.Opts.MaxFileSize)
+		require.EqualValues(t, 100, *resp.Status.Opts.ProviderId)
+		require.False(t, resp.Status.Opts.Throttle)
+	})
+}

go.mod

@@ -22,7 +22,7 @@ require (
 	github.com/ipfs/go-ds-leveldb v0.5.0
 	github.com/ipfs/go-log/v2 v2.5.1
 	github.com/libp2p/go-libp2p v0.29.2
-	github.com/libp2p/go-libp2p-kad-dht v0.24.3
+	github.com/libp2p/go-libp2p-kad-dht v0.25.0
 	github.com/libp2p/go-libp2p-pubsub v0.9.3
 	github.com/libp2p/go-libp2p-record v0.2.0
 	github.com/mitchellh/mapstructure v1.5.0

go.sum

@@ -402,8 +402,8 @@ github.com/libp2p/go-libp2p v0.29.2 h1:uPw/c8hOxoLP/KhFnzlc5Ejqf+OmAL1dwIsqE31WB
 github.com/libp2p/go-libp2p v0.29.2/go.mod h1:OU7nSq0aEZMsV2wY8nXn1+XNNt9q2UiR8LjW3Kmp2UE=
 github.com/libp2p/go-libp2p-asn-util v0.3.0 h1:gMDcMyYiZKkocGXDQ5nsUQyquC9+H+iLEQHwOCZ7s8s=
 github.com/libp2p/go-libp2p-asn-util v0.3.0/go.mod h1:B1mcOrKUE35Xq/ASTmQ4tN3LNzVVaMNmq2NACuqyB9w=
-github.com/libp2p/go-libp2p-kad-dht v0.24.3 h1:VjxtDVWaaf4UFjGBf+yl2JCiGaHx7+ctAUa9oJCR3QE=
-github.com/libp2p/go-libp2p-kad-dht v0.24.3/go.mod h1:BShPzRbK6+fN3hk8a0WGAYKpb8m4k+DtchkqouGTrSg=
+github.com/libp2p/go-libp2p-kad-dht v0.25.0 h1:T2SXQ/VlXTQVLChWY/+OyOsmGMRJvB5kiR+eJt7jtvI=
+github.com/libp2p/go-libp2p-kad-dht v0.25.0/go.mod h1:P6fz+J+u4tPigvS5J0kxQ1isksqAhmXiS/pNaEw/nFI=
 github.com/libp2p/go-libp2p-kbucket v0.6.3 h1:p507271wWzpy2f1XxPzCQG9NiN6R6lHL9GiSErbQQo0=
 github.com/libp2p/go-libp2p-kbucket v0.6.3/go.mod h1:RCseT7AH6eJWxxk2ol03xtP9pEHetYSPXOaJnOiD8i0=
 github.com/libp2p/go-libp2p-pubsub v0.9.3 h1:ihcz9oIBMaCK9kcx+yHWm3mLAFBMAUsM4ux42aikDxo=