diff --git a/internal/consensus/state.go b/internal/consensus/state.go index d3faa2149..2e54f5a17 100644 --- a/internal/consensus/state.go +++ b/internal/consensus/state.go @@ -746,7 +746,7 @@ func (cs *State) handleTimeout( // XXX: should we fire timeout here (for timeout commit)? _ = cs.ctrl.Dispatch(ctx, &EnterNewRoundEvent{Height: ti.Height}, stateData) case cstypes.RoundStepNewRound: - _ = cs.ctrl.Dispatch(ctx, &EnterProposeEvent{Height: ti.Height}, stateData) + _ = cs.ctrl.Dispatch(ctx, &EnterProposeEvent{Height: ti.Height, Round: ti.Round}, stateData) case cstypes.RoundStepPropose: if err := cs.eventBus.PublishEventTimeoutPropose(stateData.RoundStateEvent()); err != nil { cs.logger.Error("failed publishing timeout propose", "err", err) @@ -788,7 +788,7 @@ func (cs *State) handleTxsAvailable(ctx context.Context, stateData *StateData) { cs.roundScheduler.ScheduleTimeout(timeoutCommit, stateData.Height, 0, cstypes.RoundStepNewRound) case cstypes.RoundStepNewRound: // after timeoutCommit - _ = cs.ctrl.Dispatch(ctx, &EnterProposeEvent{Height: stateData.Height}, stateData) + _ = cs.ctrl.Dispatch(ctx, &EnterProposeEvent{Height: stateData.Height, Round: stateData.Round}, stateData) } } diff --git a/internal/consensus/state_test.go b/internal/consensus/state_test.go index c50c146ce..2c6cee49b 100644 --- a/internal/consensus/state_test.go +++ b/internal/consensus/state_test.go @@ -361,6 +361,74 @@ func TestStateProposalTime(t *testing.T) { } } +// TestStateLastBlockTimeInFuture ensures that whenever the last block time is in the future at genesis, +// the node waits before generating proposal. +func TestStateLastBlockTimeInFuture(t *testing.T) { + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + + logger := log.NewTestingLoggerWithLevel(t, log.LogLevelTrace) + + config := configSetup(t) + + app, err := kvstore.NewMemoryApp(kvstore.WithDuplicateRequestDetection(false)) + require.NoError(t, err) + cs1, _ := makeState(ctx, t, makeStateArgs{config: config, validators: 1, application: app, logger: logger}) + ctx = dash.ContextWithProTxHash(ctx, cs1.privValidator.ProTxHash) + stateData := cs1.GetStateData() + height, round := stateData.Height, stateData.Round + cs1.config.DontAutoPropose = true + cs1.config.CreateEmptyBlocksInterval = 0 + stateData.state.ConsensusParams.Synchrony.MessageDelay = 5 * time.Millisecond + stateData.state.ConsensusParams.Synchrony.Precision = 10 * time.Millisecond + delay := stateData.state.ConsensusParams.Synchrony.MessageDelay + precision := stateData.state.ConsensusParams.Synchrony.Precision + + // set genesis time (==last block time at height 0) in the future + assert.Equal(t, int64(1), height, "we should be on genesis") + genesisTime := tmtime.Now().Add(delay + precision + 10*time.Millisecond) + stateData.state.LastBlockTime = genesisTime + err = stateData.Save() + require.NoError(t, err) + + newRoundCh := subscribe(ctx, t, cs1.eventBus, types.EventQueryNewRound) + + startTestRound(ctx, cs1, height, round) + + // Wait for new round so proposer is set. + ensureNewRound(t, newRoundCh, height, round) + + stateData = cs1.GetStateData() + height, round = stateData.Height, stateData.Round + cs := cs1 + // Generate proposal block + propBlock, err := cs.CreateProposalBlock(ctx) + require.NoError(t, err) + + parSet, err := propBlock.MakePartSet(types.BlockPartSizeBytes) + require.NoError(t, err) + stateData.ValidBlock = propBlock + stateData.ValidBlockParts = parSet + + // Wait for complete proposal. + err = cs.ctrl.Dispatch(ctx, &EnterProposeEvent{ + Height: height, + Round: round, + }, &stateData) + require.NoError(t, err) + + time.Sleep(delay + precision + 100*time.Millisecond) + ensureNewRound(t, newRoundCh, height+1, 0) + + stateData = cs.GetStateData() + + assert.Greater(t, stateData.Height, int64(1), "we should have at least one block") + block1 := cs.blockStore.LoadBlock(1) + require.NotNil(t, block1) + + assert.Equal(t, genesisTime, block1.Time, "expected that last block time is in the past") +} + func TestStateOversizedBlock(t *testing.T) { config := configSetup(t) ctx, cancel := context.WithCancel(context.Background()) diff --git a/internal/consensus/ticker.go b/internal/consensus/ticker.go index a768854c6..30b94d3ad 100644 --- a/internal/consensus/ticker.go +++ b/internal/consensus/ticker.go @@ -115,9 +115,9 @@ func (t *timeoutTicker) timeoutRoutine(ctx context.Context) { // NOTE time.Timer allows duration to be non-positive ti = newti t.timer.Reset(ti.Duration) - t.logger.Trace("Internal state machine timeout scheduled", "duration", ti.Duration, "height", ti.Height, "round", ti.Round, "step", ti.Step.String()) + t.logger.Trace("Internal state machine timeout scheduled", "duration", ti.Duration.String(), "height", ti.Height, "round", ti.Round, "step", ti.Step.String()) case <-t.timer.C: - t.logger.Debug("Internal state machine timeout elapsed", "duration", ti.Duration, "height", ti.Height, "round", ti.Round, "step", ti.Step.String()) + t.logger.Debug("Internal state machine timeout elapsed", "duration", ti.Duration.String(), "height", ti.Height, "round", ti.Round, "step", ti.Step.String()) // go routine here guarantees timeoutRoutine doesn't block. // Determinism comes from playback in the receiveRoutine. // We can eliminate it by merging the timeoutRoutine into receiveRoutine