go/consensus/tendermint: sync-worker additionally check block timestamps

.changelog/2873.feature.md

@@ -0,0 +1,6 @@
+go/consensus/tendermint: sync-worker additionally check block timestamps
+
+Sync-worker relied on Tendermint fast-sync to determine if the node is still
+catching up. This PR adds aditional condition that the latest block is not
+older than 1 minute. This prevents cases where node would report as caught up
+after stopping fast-sync, but before it has actually caught up.

go/consensus/tendermint/tendermint.go

@@ -127,6 +127,12 @@ const (
 	// StateDir is the name of the directory located inside the node's data
 	// directory which contains the tendermint state.
 	StateDir = "tendermint"
+
+	// Time difference threshold used when considering if node is done with
+	// initial syncing. If difference is greater than the specified threshold
+	// the node is considered not yet synced.
+	// NOTE: this is only used during the initial sync.
+	syncWorkerLastBlockTimeDiffThreshold = 1 * time.Minute
 )
 
 var (
@@ -1195,17 +1201,38 @@ func (t *tendermintService) syncWorker() {
 		case <-t.node.Quit():
 			return
 		case <-time.After(1 * time.Second):
-			isSyncing, err := checkSyncFn()
+			isFastSyncing, err := checkSyncFn()
 			if err != nil {
 				t.Logger.Error("Failed to poll FastSync",
 					"err", err,
 				)
 				return
 			}
-			if !isSyncing {
+			if !isFastSyncing {
 				t.Logger.Info("Tendermint Node finished fast-sync")
-				close(t.syncedCh)
-				return
+
+				// Check latest block time.
+				tmBlock, err := t.GetTendermintBlock(t.ctx, consensusAPI.HeightLatest)
+				if err != nil {
+					t.Logger.Error("Failed to get tendermint block",
+						"err", err,
+					)
+					return
+				}
+
+				now := time.Now()
+				// No committed blocks or latest block within threshold.
+				if tmBlock == nil || now.Sub(tmBlock.Header.Time) < syncWorkerLastBlockTimeDiffThreshold {
+					t.Logger.Info("Tendermint Node finished initial sync")
+					close(t.syncedCh)
+					return
+				}
+
+				t.Logger.Debug("Node still syncing",
+					"currentTime", now,
+					"latestBlockTime", tmBlock.Time,
+					"diff", now.Sub(tmBlock.Time),
+				)
 			}
 		}
 	}

go/oasis-test-runner/scenario/e2e/late_start.go

@@ -0,0 +1,73 @@
+package e2e
+
+import (
+	"time"
+
+	"github.com/oasislabs/oasis-core/go/oasis-test-runner/env"
+	"github.com/oasislabs/oasis-core/go/oasis-test-runner/oasis"
+	"github.com/oasislabs/oasis-core/go/oasis-test-runner/scenario"
+)
+
+var (
+	// LateStart is the LateStart node basic scenario.
+	LateStart scenario.Scenario = newLateStartImpl("late-start", "simple-keyvalue-client", nil)
+)
+
+const lateStartInitialWait = 2 * time.Minute
+
+type lateStartImpl struct {
+	basicImpl
+}
+
+func newLateStartImpl(name, clientBinary string, clientArgs []string) scenario.Scenario {
+	return &lateStartImpl{
+		basicImpl: *newBasicImpl(name, clientBinary, clientArgs),
+	}
+}
+
+func (sc *lateStartImpl) Fixture() (*oasis.NetworkFixture, error) {
+	f, err := sc.basicImpl.Fixture()
+	if err != nil {
+		return nil, err
+	}
+
+	// Start without a client.
+	f.Clients = []oasis.ClientFixture{}
+
+	return f, nil
+}
+
+func (sc *lateStartImpl) Run(childEnv *env.Env) error {
+	// Start the network.
+	var err error
+	if err = sc.net.Start(); err != nil {
+		return err
+	}
+
+	sc.logger.Info("Waiting before starting the client node",
+		"wait_for", lateStartInitialWait,
+	)
+	time.Sleep(lateStartInitialWait)
+
+	sc.logger.Info("Starting the client node")
+	clientFixture := &oasis.ClientFixture{}
+	client, err := clientFixture.Create(sc.net)
+	if err != nil {
+		return err
+	}
+	if err = client.Start(); err != nil {
+		return err
+	}
+
+	sc.logger.Info("Starting the basic client")
+	cmd, err := startClient(childEnv, sc.net, resolveClientBinary(sc.clientBinary), sc.clientArgs)
+	if err != nil {
+		return err
+	}
+	clientErrCh := make(chan error)
+	go func() {
+		clientErrCh <- cmd.Wait()
+	}()
+
+	return sc.wait(childEnv, cmd, clientErrCh)
+}

go/oasis-test-runner/test-runner.go

@@ -67,6 +67,8 @@ func main() {
 	_ = cmd.Register(e2e.NodeUpgradeCancel)
 	// Debonding entries from genesis test.
 	_ = cmd.Register(e2e.Debond)
+	// Late start test.
+	_ = cmd.Register(e2e.LateStart)
 
 	// Register the remote signer test cases.
 	rootCmd.Flags().AddFlagSet(remotesigner.Flags)