consensus/bor: ensure late blocks have sufficient build time

When a parent block is sealed late (actual seal time exceeds its timestamp), the next block had insufficient time to include transactions, resulting in empty blocks.

Problem:
- Parent block timestamp: T=2s, sealed at T=4s (2s late)
- Next block gets timestamp: parent + period = 4s
- Current time: 4s
- Build time available: 0s → empty block

Solution:
Set header.Time = now + blockPeriod when scheduled time has passed, giving blocks full build time regardless of parent seal latency.

Author: cffls

consensus/bor/bor.go

@@ -1041,9 +1041,13 @@ func (c *Bor) Prepare(chain consensus.ChainHeaderReader, header *types.Header) e
 
 	now := time.Now()
 	if header.Time < uint64(now.Unix()) {
-		header.Time = uint64(now.Unix())
+		additionalBlockTime := time.Duration(c.config.CalculatePeriod(number)) * time.Second
+		if c.blockTime > 0 {
+			additionalBlockTime = c.blockTime
+		}
+		header.Time = uint64(now.Add(additionalBlockTime).Unix())
 		if c.blockTime > 0 && c.config.IsRio(header.Number) {
-			header.ActualTime = now
+			header.ActualTime = now.Add(additionalBlockTime)
 		}
 	}
 

consensus/bor/bor_test.go

@@ -743,7 +743,7 @@ func TestCustomBlockTimeClampsToNowAlsoUpdatesActualTime(t *testing.T) {
 
 	addr1 := common.HexToAddress("0x1")
 	// Force parent time far in the past so that after adding blockTime, header.Time is still < now
-	// and the "clamp to now" block triggers.
+	// and the "clamp to now + blockTime" block triggers.
 	pastParentTime := time.Now().Add(-10 * time.Minute).Unix()
 
 	sp := &fakeSpanner{vals: []*valset.Validator{{Address: addr1, VotingPower: 1}}}
@@ -771,18 +771,27 @@ func TestCustomBlockTimeClampsToNowAlsoUpdatesActualTime(t *testing.T) {
 
 	require.NoError(t, err)
 
-	// Validate the clamp happened: header.Time should be "now-ish", not the past-derived time.
-	require.GreaterOrEqual(t, int64(header.Time), before.Unix(), "header.Time should be clamped up to now")
-	require.LessOrEqual(t, int64(header.Time), after.Unix()+1, "header.Time should be close to now")
+	// With the late block fix, header.Time should be "now + blockTime", not just "now"
+	// This gives the block builder sufficient time to include transactions
+	expectedMinTime := before.Add(b.blockTime).Unix()
+	expectedMaxTime := after.Add(b.blockTime).Unix() + 1 // +1 for timing tolerance
+
+	require.GreaterOrEqual(t, int64(header.Time), expectedMinTime,
+		"header.Time should be at least now + blockTime to provide build time")
+	require.LessOrEqual(t, int64(header.Time), expectedMaxTime,
+		"header.Time should be approximately now + blockTime")
 
 	// Critical regression assertion:
-	// When custom blockTime is enabled for Rio, clamping header.Time to now must also set ActualTime = now.
+	// When custom blockTime is enabled for Rio, clamping header.Time must also set ActualTime = now + blockTime.
 	require.False(t, header.ActualTime.IsZero(), "ActualTime should be set when blockTime > 0 and Rio is enabled")
-	require.GreaterOrEqual(t, header.ActualTime.Unix(), before.Unix(), "ActualTime should be updated to now when clamping occurs")
-	require.LessOrEqual(t, header.ActualTime.Unix(), after.Unix()+1, "ActualTime should be close to now when clamping occurs")
-
-	// Optional: since clamping sets both from the same `now`, they should match on Unix seconds.
-	require.Equal(t, int64(header.Time), header.ActualTime.Unix(), "header.Time and ActualTime should align after clamping")
+	require.GreaterOrEqual(t, header.ActualTime.Unix(), expectedMinTime,
+		"ActualTime should be at least now + blockTime when clamping occurs")
+	require.LessOrEqual(t, header.ActualTime.Unix(), expectedMaxTime,
+		"ActualTime should be approximately now + blockTime when clamping occurs")
+
+	// Since clamping sets both from the same calculation, they should match on Unix seconds.
+	require.Equal(t, int64(header.Time), header.ActualTime.Unix(),
+		"header.Time and ActualTime should align after clamping")
 }
 
 func TestVerifySealRejectsOversizedDifficulty(t *testing.T) {
@@ -869,3 +878,67 @@ func TestVerifySealRejectsOversizedDifficulty(t *testing.T) {
 			diffErr.Actual, uint64(math.MaxUint64))
 	}
 }
+
+// TestLateBlockTimestampFix verifies that late blocks get sufficient build time
+// by setting header.Time = now + blockPeriod instead of just clamping to now.
+func TestLateBlockTimestampFix(t *testing.T) {
+	t.Parallel()
+
+	addr1 := common.HexToAddress("0x1")
+	borCfg := &params.BorConfig{
+		Sprint: map[string]uint64{"0": 64},
+		Period: map[string]uint64{"0": 2},
+	}
+
+	t.Run("late parent gets future timestamp", func(t *testing.T) {
+		sp := &fakeSpanner{vals: []*valset.Validator{{Address: addr1, VotingPower: 1}}}
+		oldParentTime := time.Now().Add(-4 * time.Second).Unix()
+		chain, b := newChainAndBorForTest(t, sp, borCfg, true, addr1, uint64(oldParentTime))
+
+		header := &types.Header{Number: big.NewInt(1), ParentHash: chain.HeaderChain().GetHeaderByNumber(0).Hash()}
+
+		before := time.Now()
+		require.NoError(t, b.Prepare(chain.HeaderChain(), header))
+
+		// Should give full 2s build time from now, not from parent
+		expectedMin := before.Add(2 * time.Second).Unix()
+		require.GreaterOrEqual(t, int64(header.Time), expectedMin)
+	})
+
+	t.Run("on-time parent uses normal calculation", func(t *testing.T) {
+		sp := &fakeSpanner{vals: []*valset.Validator{{Address: addr1, VotingPower: 1}}}
+		recentParentTime := time.Now().Unix()
+		chain, b := newChainAndBorForTest(t, sp, borCfg, true, addr1, uint64(recentParentTime))
+
+		header := &types.Header{Number: big.NewInt(1), ParentHash: chain.HeaderChain().GetHeaderByNumber(0).Hash()}
+
+		require.NoError(t, b.Prepare(chain.HeaderChain(), header))
+
+		// Should use parent.Time + period
+		genesis := chain.HeaderChain().GetHeaderByNumber(0)
+		require.GreaterOrEqual(t, header.Time, genesis.Time+borCfg.Period["0"])
+	})
+
+	t.Run("custom blockTime with Rio", func(t *testing.T) {
+		sp := &fakeSpanner{vals: []*valset.Validator{{Address: addr1, VotingPower: 1}}}
+		rioCfg := &params.BorConfig{
+			Sprint:   map[string]uint64{"0": 64},
+			Period:   map[string]uint64{"0": 2},
+			RioBlock: big.NewInt(0),
+		}
+
+		oldParentTime := time.Now().Add(-4 * time.Second).Unix()
+		chain, b := newChainAndBorForTest(t, sp, rioCfg, true, addr1, uint64(oldParentTime))
+		b.blockTime = 3 * time.Second
+
+		header := &types.Header{Number: big.NewInt(1), ParentHash: chain.HeaderChain().GetHeaderByNumber(0).Hash()}
+
+		before := time.Now()
+		require.NoError(t, b.Prepare(chain.HeaderChain(), header))
+
+		expectedMin := before.Add(3 * time.Second).Unix()
+		require.GreaterOrEqual(t, int64(header.Time), expectedMin)
+		require.False(t, header.ActualTime.IsZero())
+		require.GreaterOrEqual(t, header.ActualTime.Unix(), expectedMin)
+	})
+}

tests/bor/bor_test.go

@@ -2065,3 +2065,185 @@ func TestCustomBlockTimeMining(t *testing.T) {
 	require.LessOrEqual(t, blocksMinedCount, maxExpectedBlocks,
 		fmt.Sprintf("Too many blocks mined. Expected at most %d, got %d", maxExpectedBlocks, blocksMinedCount))
 }
+
+// TestLateBlockNotEmpty tests that when a parent block is sealed late,
+// blocks still have sufficient time to include transactions.
+// This verifies the fix for empty blocks caused by late parent blocks.
+func TestLateBlockNotEmpty(t *testing.T) {
+	t.Parallel()
+	log.SetDefault(log.NewLogger(log.NewTerminalHandlerWithLevel(os.Stderr, log.LevelInfo, true)))
+	fdlimit.Raise(2048)
+
+	faucets := make([]*ecdsa.PrivateKey, 128)
+	for i := 0; i < len(faucets); i++ {
+		faucets[i], _ = crypto.GenerateKey()
+	}
+
+	genesis := InitGenesis(t, faucets, "./testdata/genesis_2val.json", 16)
+	genesis.Config.Bor.Period = map[string]uint64{"0": 2}
+	genesis.Config.Bor.Sprint = map[string]uint64{"0": 16}
+	genesis.Config.Bor.RioBlock = big.NewInt(0)
+
+	// Start a single miner node
+	stack, ethBackend, err := InitMiner(genesis, keys[0], true)
+	require.NoError(t, err)
+	defer stack.Close()
+
+	for stack.Server().NodeInfo().Ports.Listener == 0 {
+		time.Sleep(250 * time.Millisecond)
+	}
+
+	// Start mining
+	err = ethBackend.StartMining()
+	require.NoError(t, err)
+
+	// Wait for initial blocks
+	log.Info("Waiting for initial blocks...")
+	for {
+		time.Sleep(500 * time.Millisecond)
+		if ethBackend.BlockChain().CurrentBlock().Number.Uint64() >= 3 {
+			break
+		}
+	}
+
+	// Stop mining and wait for it to fully stop
+	ethBackend.StopMining()
+	time.Sleep(500 * time.Millisecond)
+
+	// Capture parent block
+	parentBlock := ethBackend.BlockChain().CurrentBlock()
+	parentNumber := parentBlock.Number.Uint64()
+	parentTime := parentBlock.Time
+
+	log.Info("Parent block", "number", parentNumber, "time", parentTime)
+
+	// Add transactions BEFORE waiting (they should be in pool when we resume)
+	txpool := ethBackend.TxPool()
+	senderKey := pkey1
+	senderAddr := crypto.PubkeyToAddress(senderKey.PublicKey)
+	recipientAddr := crypto.PubkeyToAddress(pkey2.PublicKey)
+	nonce := txpool.Nonce(senderAddr)
+	signer := types.LatestSignerForChainID(genesis.Config.ChainID)
+
+	// Start goroutine to continuously add transactions
+	stopTxs := make(chan struct{})
+	txNonce := nonce
+	go func() {
+		ticker := time.NewTicker(100 * time.Millisecond)
+		defer ticker.Stop()
+		for {
+			select {
+			case <-stopTxs:
+				return
+			case <-ticker.C:
+				// Add 5 transactions every 100ms
+				for i := 0; i < 5; i++ {
+					tx := types.NewTransaction(
+						txNonce,
+						recipientAddr,
+						big.NewInt(1000),
+						21000,
+						big.NewInt(30000000000),
+						nil,
+					)
+					signedTx, _ := types.SignTx(tx, signer, senderKey)
+					if txpool.Add([]*types.Transaction{signedTx}, true)[0] == nil {
+						txNonce++
+					}
+				}
+			}
+		}
+	}()
+	defer close(stopTxs)
+
+	// Wait a bit for initial transactions to be added
+	time.Sleep(300 * time.Millisecond)
+
+	pending, queued := txpool.Stats()
+	log.Info("Txpool after initial txs", "pending", pending, "queued", queued)
+	require.Greater(t, pending, 0, "Expected transactions in pending")
+
+	// Wait for parent to become older than block period (simulates late parent)
+	blockPeriod := time.Duration(genesis.Config.Bor.Period["0"]) * time.Second
+
+	// Wait until parent age > blockPeriod (not just equal)
+	var parentAge int64
+	for {
+		parentBlock = ethBackend.BlockChain().CurrentBlock()
+		parentNumber = parentBlock.Number.Uint64()
+		parentTime = parentBlock.Time
+		parentAge = time.Now().Unix() - int64(parentTime)
+
+		if parentAge > int64(blockPeriod.Seconds()) {
+			log.Info("Parent is now late", "number", parentNumber, "age", parentAge, "blockPeriod", blockPeriod.Seconds())
+			break
+		}
+
+		time.Sleep(100 * time.Millisecond)
+	}
+
+	// Resume mining
+	err = ethBackend.StartMining()
+	require.NoError(t, err)
+
+	// Wait for blocks to be mined and check that they ALL contain transactions
+	log.Info("Waiting for blocks after resume...")
+	blocksToCheck := uint64(3)
+	maxWait := 10 * time.Second
+	deadline := time.Now().Add(maxWait)
+	allBlocksChecked := false
+
+	var currentNumber uint64
+	for time.Now().Before(deadline) {
+		time.Sleep(500 * time.Millisecond)
+		currentNumber = ethBackend.BlockChain().CurrentBlock().Number.Uint64()
+
+		if currentNumber >= parentNumber+blocksToCheck {
+			allBlocksChecked = true
+			break
+		}
+	}
+
+	require.True(t, allBlocksChecked, "Expected %d blocks to be mined", blocksToCheck)
+
+	// Verify ALL blocks after parent contain transactions
+	totalTxsInBlocks := 0
+	actualNow := time.Now().Unix()
+	parentAge = actualNow - int64(parentTime) // Update parent age for error messages
+
+	for i := uint64(1); i <= blocksToCheck; i++ {
+		block := ethBackend.BlockChain().GetBlockByNumber(parentNumber + i)
+		require.NotNil(t, block)
+		txCount := len(block.Transactions())
+		totalTxsInBlocks += txCount
+
+		// Calculate expected build time
+		expectedMinTime := int64(parentTime) + int64(blockPeriod.Seconds())
+		actualBuildTime := int64(block.Time()) - actualNow
+		timeFromParent := int64(block.Time()) - int64(parentTime)
+
+		log.Info("Block check",
+			"number", block.Number().Uint64(),
+			"txCount", txCount,
+			"blockTime", block.Time(),
+			"actualNow", actualNow,
+			"buildTime", actualBuildTime,
+			"timeFromParent", timeFromParent,
+			"expectedMin", expectedMinTime)
+
+		// KEY ASSERTION: With the fix, ALL blocks should contain transactions
+		// when there are pending transactions in the pool
+		require.Greater(t, txCount, 0,
+			"Block %d is empty! With late block fix, all blocks should include "+
+				"transactions when txpool has pending txs. Parent age was %d seconds. "+
+				"Block time: %d, Now: %d, Build time available: %d seconds.",
+			block.Number().Uint64(), parentAge, block.Time(), actualNow, actualBuildTime)
+	}
+
+	log.Info("SUCCESS: All blocks after late parent contain transactions",
+		"blocksChecked", blocksToCheck,
+		"totalTxs", totalTxsInBlocks,
+		"parentAge", parentAge)
+
+	ethBackend.StopMining()
+}

tests/bor/helper.go

@@ -607,11 +607,12 @@ func InitMinerWithBlockTime(genesis *core.Genesis, privKey *ecdsa.PrivateKey, wi
 		TxPool:          legacypool.DefaultConfig,
 		GPO:             ethconfig.Defaults.GPO,
 		Miner: miner.Config{
-			Etherbase: crypto.PubkeyToAddress(privKey.PublicKey),
-			GasCeil:   genesis.GasLimit * 11 / 10,
-			GasPrice:  big.NewInt(1),
-			Recommit:  time.Second,
-			BlockTime: blockTime,
+			Etherbase:           crypto.PubkeyToAddress(privKey.PublicKey),
+			GasCeil:             genesis.GasLimit * 11 / 10,
+			GasPrice:            big.NewInt(1),
+			Recommit:            time.Second,
+			BlockTime:           blockTime,
+			CommitInterruptFlag: true,
 		},
 		WithoutHeimdall: withoutHeimdall,
 	})