[IBFT] Consensus timeout takes into account block production time (#582)

* Fix issue that block production doesn't work if block time config exceeds 10s

* Fix lint error

* Remove debug code

* Calculate IBFT timeout from block time

* Fix indent

* Fix lint error

* Update timeout.go

* Fix explain about --ibft-base-timeout

* Make IBFT e2e tests run in parallel

* Fix lint error

* Add debug code

* Revert code

* Add debug code

* Merge IBFT e2e tests

* Fix lint error

* Fix timeout

* Fix timeout

* Add debug log

command/server/config/config.go

@@ -27,6 +27,7 @@ type Config struct {
 	LogLevel          string     `json:"log_level" yaml:"log_level"`
 	RestoreFile       string     `json:"restore_file" yaml:"restore_file"`
 	BlockTime         uint64     `json:"block_time_s" yaml:"block_time_s"`
+	IBFTBaseTimeout   uint64     `json:"ibft_base_time_s" yaml:"ibft_base_time_s"`
 	Headers           *Headers   `json:"headers" yaml:"headers"`
 	LogFilePath       string     `json:"log_to" yaml:"log_to"`
 }
@@ -58,8 +59,17 @@ type Headers struct {
 	AccessControlAllowOrigins []string `json:"access_control_allow_origins" yaml:"access_control_allow_origins"`
 }
 
-// minimum block generation time in seconds
-const defaultBlockTime uint64 = 2
+const (
+	// minimum block generation time in seconds
+	DefaultBlockTime uint64 = 2
+
+	// IBFT timeout in seconds
+	DefaultIBFTBaseTimeout uint64 = 10
+
+	// Multiplier to get IBFT timeout from block time
+	// timeout is calculated when IBFT timeout is not specified
+	BlockTimeMultiplierForTimeout uint64 = 5
+)
 
 // DefaultConfig returns the default server configuration
 func DefaultConfig() *Config {
@@ -85,9 +95,10 @@ func DefaultConfig() *Config {
 			PriceLimit: 0,
 			MaxSlots:   4096,
 		},
-		LogLevel:    "INFO",
-		RestoreFile: "",
-		BlockTime:   defaultBlockTime,
+		LogLevel:        "INFO",
+		RestoreFile:     "",
+		BlockTime:       DefaultBlockTime,
+		IBFTBaseTimeout: DefaultIBFTBaseTimeout,
 		Headers: &Headers{
 			AccessControlAllowOrigins: []string{"*"},
 		},

command/server/init.go

@@ -3,10 +3,11 @@ package server
 import (
 	"errors"
 	"fmt"
-	"github.com/0xPolygon/polygon-edge/command/server/config"
 	"math"
 	"net"
 
+	"github.com/0xPolygon/polygon-edge/command/server/config"
+
 	"github.com/0xPolygon/polygon-edge/network/common"
 
 	"github.com/0xPolygon/polygon-edge/chain"
@@ -19,6 +20,7 @@ import (
 
 var (
 	errInvalidBlockTime       = errors.New("invalid block time specified")
+	errWrongIBFTBaseTimeout   = errors.New("IBFT base timeout needs to be higher than block time")
 	errDataDirectoryUndefined = errors.New("data directory not defined")
 )
 
@@ -53,6 +55,10 @@ func (p *serverParams) initRawParams() error {
 		return err
 	}
 
+	if err := p.initIBFTBaseTimeout(); err != nil {
+		return err
+	}
+
 	if p.isDevMode {
 		p.initDevMode()
 	}
@@ -71,6 +77,21 @@ func (p *serverParams) initBlockTime() error {
 	return nil
 }
 
+func (p *serverParams) initIBFTBaseTimeout() error {
+	if p.rawConfig.IBFTBaseTimeout == 0 {
+		// Calculate from block time
+		p.rawConfig.IBFTBaseTimeout = p.rawConfig.BlockTime * config.BlockTimeMultiplierForTimeout
+
+		return nil
+	}
+
+	if p.rawConfig.IBFTBaseTimeout <= p.rawConfig.BlockTime {
+		return errWrongIBFTBaseTimeout
+	}
+
+	return nil
+}
+
 func (p *serverParams) initDataDirLocation() error {
 	if p.rawConfig.DataDir == "" {
 		return errDataDirectoryUndefined

command/server/params.go

@@ -2,9 +2,10 @@ package server
 
 import (
 	"errors"
-	"github.com/0xPolygon/polygon-edge/command/server/config"
 	"net"
 
+	"github.com/0xPolygon/polygon-edge/command/server/config"
+
 	"github.com/0xPolygon/polygon-edge/chain"
 	"github.com/0xPolygon/polygon-edge/network"
 	"github.com/0xPolygon/polygon-edge/secrets"
@@ -31,6 +32,7 @@ const (
 	secretsConfigFlag     = "secrets-config"
 	restoreFlag           = "restore"
 	blockTimeFlag         = "block-time"
+	ibftBaseTimeoutFlag   = "ibft-base-timeout"
 	devIntervalFlag       = "dev-interval"
 	devFlag               = "dev"
 	corsOriginFlag        = "access-control-allow-origins"
@@ -160,14 +162,15 @@ func (p *serverParams) generateConfig() *server.Config {
 			MaxOutboundPeers: p.rawConfig.Network.MaxOutboundPeers,
 			Chain:            p.genesisConfig,
 		},
-		DataDir:        p.rawConfig.DataDir,
-		Seal:           p.rawConfig.ShouldSeal,
-		PriceLimit:     p.rawConfig.TxPool.PriceLimit,
-		MaxSlots:       p.rawConfig.TxPool.MaxSlots,
-		SecretsManager: p.secretsConfig,
-		RestoreFile:    p.getRestoreFilePath(),
-		BlockTime:      p.rawConfig.BlockTime,
-		LogLevel:       hclog.LevelFromString(p.rawConfig.LogLevel),
-		LogFilePath:    p.logFileLocation,
+		DataDir:         p.rawConfig.DataDir,
+		Seal:            p.rawConfig.ShouldSeal,
+		PriceLimit:      p.rawConfig.TxPool.PriceLimit,
+		MaxSlots:        p.rawConfig.TxPool.MaxSlots,
+		SecretsManager:  p.secretsConfig,
+		RestoreFile:     p.getRestoreFilePath(),
+		BlockTime:       p.rawConfig.BlockTime,
+		IBFTBaseTimeout: p.rawConfig.IBFTBaseTimeout,
+		LogLevel:        hclog.LevelFromString(p.rawConfig.LogLevel),
+		LogFilePath:     p.logFileLocation,
 	}
 }

command/server/server.go

@@ -2,6 +2,7 @@ package server
 
 import (
 	"fmt"
+
 	"github.com/0xPolygon/polygon-edge/command"
 	"github.com/0xPolygon/polygon-edge/command/server/config"
 	"github.com/0xPolygon/polygon-edge/command/server/export"
@@ -183,6 +184,17 @@ func setFlags(cmd *cobra.Command) {
 		"minimum block time in seconds (at least 1s)",
 	)
 
+	cmd.Flags().Uint64Var(
+		&params.rawConfig.IBFTBaseTimeout,
+		ibftBaseTimeoutFlag,
+		// Calculate from block time if it is not given
+		0,
+		fmt.Sprintf(
+			"base IBFT timeout in seconds, it needs to be larger than block time. (block time * %d) is set if it's zero",
+			config.BlockTimeMultiplierForTimeout,
+		),
+	)
+
 	cmd.Flags().StringArrayVar(
 		&params.corsAllowedOrigins,
 		corsOriginFlag,

consensus/consensus.go

@@ -60,18 +60,19 @@ type Config struct {
 }
 
 type ConsensusParams struct {
-	Context        context.Context
-	Seal           bool
-	Config         *Config
-	Txpool         *txpool.TxPool
-	Network        *network.Server
-	Blockchain     *blockchain.Blockchain
-	Executor       *state.Executor
-	Grpc           *grpc.Server
-	Logger         hclog.Logger
-	Metrics        *Metrics
-	SecretsManager secrets.SecretsManager
-	BlockTime      uint64
+	Context         context.Context
+	Seal            bool
+	Config          *Config
+	Txpool          *txpool.TxPool
+	Network         *network.Server
+	Blockchain      *blockchain.Blockchain
+	Executor        *state.Executor
+	Grpc            *grpc.Server
+	Logger          hclog.Logger
+	Metrics         *Metrics
+	SecretsManager  secrets.SecretsManager
+	BlockTime       uint64
+	IBFTBaseTimeout uint64
 }
 
 // Factory is the factory function to create a discovery backend

consensus/ibft/ibft.go

@@ -102,7 +102,8 @@ type Ibft struct {
 
 	mechanisms []ConsensusMechanism // IBFT ConsensusMechanism used (PoA / PoS)
 
-	blockTime time.Duration // Minimum block generation time in seconds
+	blockTime       time.Duration // Minimum block generation time in seconds
+	ibftBaseTimeout time.Duration // Base timeout for IBFT message in seconds
 }
 
 // runHook runs a specified hook if it is present in the hook map
@@ -177,6 +178,7 @@ func Factory(
 		metrics:            params.Metrics,
 		secretsManager:     params.SecretsManager,
 		blockTime:          time.Duration(params.BlockTime) * time.Second,
+		ibftBaseTimeout:    time.Duration(params.IBFTBaseTimeout) * time.Second,
 	}
 
 	// Initialize the mechanism
@@ -830,7 +832,7 @@ func (i *Ibft) runAcceptState() { // start new round
 	// we are NOT a proposer for the block. Then, we have to wait
 	// for a pre-prepare message from the proposer
 
-	timeout := exponentialTimeout(i.state.view.Round)
+	timeout := i.getTimeout()
 	for i.getState() == AcceptState {
 		msg, ok := i.getNextMessage(timeout)
 		if !ok {
@@ -930,7 +932,7 @@ func (i *Ibft) runValidateState() {
 		}
 	}
 
-	timeout := exponentialTimeout(i.state.view.Round)
+	timeout := i.getTimeout()
 	for i.getState() == ValidateState {
 		msg, ok := i.getNextMessage(timeout)
 		if !ok {
@@ -1139,7 +1141,7 @@ func (i *Ibft) runRoundChangeState() {
 	}
 
 	// create a timer for the round change
-	timeout := exponentialTimeout(i.state.view.Round)
+	timeout := i.getTimeout()
 	for i.getState() == RoundChangeState {
 		msg, ok := i.getNextMessage(timeout)
 		if !ok {
@@ -1151,7 +1153,7 @@ func (i *Ibft) runRoundChangeState() {
 			i.logger.Debug("round change timeout")
 			checkTimeout()
 			// update the timeout duration
-			timeout = exponentialTimeout(i.state.view.Round)
+			timeout = i.getTimeout()
 
 			continue
 		}
@@ -1162,7 +1164,8 @@ func (i *Ibft) runRoundChangeState() {
 		if num == i.state.validators.MaxFaultyNodes()+1 && i.state.view.Round < msg.View.Round {
 			// weak certificate, try to catch up if our round number is smaller
 			// update timer
-			timeout = exponentialTimeout(i.state.view.Round)
+			timeout = i.getTimeout()
+
 			sendRoundChange(msg.View.Round)
 		} else if num == i.quorumSize(i.state.view.Sequence)(i.state.validators) {
 			// start a new round immediately
@@ -1429,6 +1432,11 @@ func (i *Ibft) pushMessage(msg *proto.MessageReq) {
 	}
 }
 
+// getTimeout returns the IBFT timeout based on round and config
+func (i *Ibft) getTimeout() time.Duration {
+	return exponentialTimeout(i.state.view.Round, i.ibftBaseTimeout)
+}
+
 // startNewSequence changes the sequence and resets the round in the view of state
 func (i *Ibft) startNewSequence() {
 	header := i.blockchain.Header()

consensus/ibft/timeout.go

@@ -6,15 +6,16 @@ import (
 )
 
 const (
-	baseTimeout = 10 * time.Second
-	maxTimeout  = 300 * time.Second
+	maxTimeoutMultiplier = 30
 )
 
 // exponentialTimeout calculates the timeout duration in seconds as exponential function
-// where maximum value returned can't exceed 300 seconds
-// t = 10 + 2^exponent	where exponent > 0
-// t = 10				where exponent = 0
-func exponentialTimeout(exponent uint64) time.Duration {
+// where maximum value returned can't exceed 30 * baseTimeout
+// t = baseTimeout * maxTimeoutMultiplier where exponent > 8
+// t = baseTimeout + 2^exponent	          where exponent > 0
+// t = baseTimeout			  where exponent = 0
+func exponentialTimeout(exponent uint64, baseTimeout time.Duration) time.Duration {
+	maxTimeout := baseTimeout * maxTimeoutMultiplier
 	if exponent > 8 {
 		return maxTimeout
 	}

consensus/ibft/timeout_test.go

@@ -1,28 +1,32 @@
 package ibft
 
 import (
-	"github.com/stretchr/testify/assert"
 	"testing"
 	"time"
+
+	"github.com/stretchr/testify/assert"
 )
 
 func TestExponentialTimeout(t *testing.T) {
 	testCases := []struct {
 		description string
 		exponent    uint64
+		baseTimeout time.Duration
 		expected    time.Duration
 	}{
-		{"for exponent 0 returns 10s", 0, 10 * time.Second},
-		{"for exponent 1 returns 12s", 1, (10 + 2) * time.Second},
-		{"for exponent 2 returns 14s", 2, (10 + 4) * time.Second},
-		{"for exponent 8 returns 256s", 8, (10 + 256) * time.Second},
-		{"for exponent 9 returns 300s", 9, 300 * time.Second},
-		{"for exponent 10 returns 300s", 10, 5 * time.Minute},
+		{"for exponent 0 returns 10s", 0, 10 * time.Second, 10 * time.Second},
+		{"for exponent 1 returns 12s", 1, 10 * time.Second, (10 + 2) * time.Second},
+		{"for exponent 2 returns 14s", 2, 10 * time.Second, (10 + 4) * time.Second},
+		{"for exponent 8 returns 256s", 8, 10 * time.Second, (10 + 256) * time.Second},
+		{"for exponent 9 returns 300s", 9, 10 * time.Second, 300 * time.Second},
+		{"for exponent 10 returns 300s", 10, 10 * time.Second, 5 * time.Minute},
+		{"for block timeout 20s, exponent 0 returns 20s", 0, 20 * time.Second, 20 * time.Second},
+		{"for block timeout 20s, exponent 10 returns 600s", 10, 20 * time.Second, 10 * time.Minute},
 	}
 
 	for _, test := range testCases {
 		t.Run(test.description, func(t *testing.T) {
-			timeout := exponentialTimeout(test.exponent)
+			timeout := exponentialTimeout(test.exponent, test.baseTimeout)
 
 			assert.Equal(t, test.expected, timeout)
 		})

e2e/framework/config.go

@@ -49,6 +49,7 @@ type TestServerConfig struct {
 	MinValidatorCount       uint64               // Min validator count
 	MaxValidatorCount       uint64               // Max validator count
 	BlockTime               uint64               // Minimum block generation time (in s)
+	IBFTBaseTimeout         uint64               // Base Timeout in seconds for IBFT
 }
 
 // DataDir returns path of data directory server uses
@@ -69,6 +70,10 @@ func (t *TestServerConfig) SetBlockTime(blockTime uint64) {
 	t.BlockTime = blockTime
 }
 
+func (t *TestServerConfig) SetIBFTBaseTimeout(baseTimeout uint64) {
+	t.IBFTBaseTimeout = baseTimeout
+}
+
 // PrivateKey returns a private key in data directory
 func (t *TestServerConfig) PrivateKey() (*ecdsa.PrivateKey, error) {
 	return crypto.GenerateOrReadPrivateKey(filepath.Join(t.DataDir(), "consensus", ibft.IbftKeyName))

e2e/framework/helper.go

@@ -5,7 +5,6 @@ import (
 	"crypto/ecdsa"
 	"errors"
 	"fmt"
-	"github.com/umbracle/ethgo"
 	"io/ioutil"
 	"math/big"
 	"net"
@@ -15,6 +14,8 @@ import (
 	"testing"
 	"time"
 
+	"github.com/umbracle/ethgo"
+
 	"github.com/0xPolygon/polygon-edge/contracts/abis"
 	"github.com/0xPolygon/polygon-edge/contracts/staking"
 	"github.com/0xPolygon/polygon-edge/crypto"
@@ -483,10 +484,10 @@ func NewTestServers(t *testing.T, num int, conf func(*TestServerConfig)) []*Test
 	var wg sync.WaitGroup
 
 	for i, srv := range srvs {
-		wg.Add(1)
-
 		i, srv := i, srv
 
+		wg.Add(1)
+
 		go func() {
 			defer wg.Done()
 
@@ -499,8 +500,7 @@ func NewTestServers(t *testing.T, num int, conf func(*TestServerConfig)) []*Test
 			ctx, cancel := context.WithTimeout(context.Background(), DefaultTimeout)
 			defer cancel()
 
-			err := srv.Start(ctx)
-			if err != nil {
+			if err := srv.Start(ctx); err != nil {
 				errors.Append(fmt.Errorf("server %d failed to start, error=%w", i, err))
 			}
 		}()