Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 6 additions & 2 deletions consensus/bor/bor.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
}

Expand Down
96 changes: 86 additions & 10 deletions consensus/bor/bor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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}}}
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -869,3 +878,70 @@ 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)
// Add upper bound check to ensure timestamp is within reasonable range (allow 100ms execution time)
expectedMax := before.Add(2*time.Second + 100*time.Millisecond).Unix()
require.LessOrEqual(t, int64(header.Time), expectedMax)
})

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)
})
}
182 changes: 182 additions & 0 deletions tests/bor/bor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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()
}
11 changes: 6 additions & 5 deletions tests/bor/helper.go
Original file line number Diff line number Diff line change
Expand Up @@ -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,
})
Expand Down
Loading