diff --git a/client/cmd/kcoin/config.go b/client/cmd/kcoin/config.go index 73ed6d5b2..e3fbf7826 100644 --- a/client/cmd/kcoin/config.go +++ b/client/cmd/kcoin/config.go @@ -104,7 +104,9 @@ func makeConfigNode(ctx *cli.Context) (*node.Node, kcoinConfig) { if err != nil { utils.Fatalf("Failed to create the protocol stack: %v", err) } + utils.SetKowalaConfig(ctx, stack, &cfg.Kowala) + if ctx.GlobalIsSet(utils.KowalaStatsURLFlag.Name) { cfg.Stats.URL = ctx.GlobalString(utils.KowalaStatsURLFlag.Name) } diff --git a/client/cmd/kcoin/main.go b/client/cmd/kcoin/main.go index 0cde134ee..976856029 100644 --- a/client/cmd/kcoin/main.go +++ b/client/cmd/kcoin/main.go @@ -23,9 +23,9 @@ import ( "github.com/kowala-tech/kcoin/client/log" "github.com/kowala-tech/kcoin/client/metrics" "github.com/kowala-tech/kcoin/client/node" - "gopkg.in/urfave/cli.v1" - "github.com/kowala-tech/kcoin/client/version" "github.com/kowala-tech/kcoin/client/params" + "github.com/kowala-tech/kcoin/client/version" + "gopkg.in/urfave/cli.v1" ) const ( diff --git a/client/cmd/utils/flags.go b/client/cmd/utils/flags.go index 9d4dca272..e323b595e 100644 --- a/client/cmd/utils/flags.go +++ b/client/cmd/utils/flags.go @@ -11,13 +11,11 @@ import ( "strings" "time" - "github.com/kowala-tech/kcoin/client/consensus/konsensus" - "github.com/kowala-tech/kcoin/client/stats" - "github.com/kowala-tech/kcoin/client/accounts" "github.com/kowala-tech/kcoin/client/accounts/keystore" "github.com/kowala-tech/kcoin/client/common" "github.com/kowala-tech/kcoin/client/common/fdlimit" + "github.com/kowala-tech/kcoin/client/consensus/konsensus" "github.com/kowala-tech/kcoin/client/core" "github.com/kowala-tech/kcoin/client/core/state" "github.com/kowala-tech/kcoin/client/core/vm" @@ -26,6 +24,7 @@ import ( "github.com/kowala-tech/kcoin/client/knode" "github.com/kowala-tech/kcoin/client/knode/downloader" "github.com/kowala-tech/kcoin/client/knode/gasprice" + "github.com/kowala-tech/kcoin/client/knode/validator" "github.com/kowala-tech/kcoin/client/log" "github.com/kowala-tech/kcoin/client/metrics" "github.com/kowala-tech/kcoin/client/metrics/influxdb" @@ -36,6 +35,7 @@ import ( "github.com/kowala-tech/kcoin/client/p2p/nat" "github.com/kowala-tech/kcoin/client/p2p/netutil" "github.com/kowala-tech/kcoin/client/params" + "github.com/kowala-tech/kcoin/client/stats" "gopkg.in/urfave/cli.v1" ) @@ -1006,6 +1006,10 @@ func SetKowalaConfig(ctx *cli.Context, stack *node.Node, cfg *knode.Config) { if gen := ctx.GlobalInt(TrieCacheGenFlag.Name); gen > 0 { state.MaxTrieCacheGen = uint16(gen) } + + cfg.ValidatorConfig = &validator.Config{ + LogDir: filepath.Join(stack.DataDir(), "log"), + } } // RegisterKowalaService adds a Kowala client to the stack. diff --git a/client/knode/config.go b/client/knode/config.go index b7f5b3985..f6aec2c5f 100644 --- a/client/knode/config.go +++ b/client/knode/config.go @@ -10,6 +10,7 @@ import ( "github.com/kowala-tech/kcoin/client/knode/currency" "github.com/kowala-tech/kcoin/client/knode/downloader" "github.com/kowala-tech/kcoin/client/knode/gasprice" + "github.com/kowala-tech/kcoin/client/knode/validator" "github.com/kowala-tech/kcoin/client/params" ) @@ -73,6 +74,8 @@ type Config struct { DocRoot string `toml:"-"` Currency string + + ValidatorConfig *validator.Config } type configMarshaling struct { diff --git a/client/knode/gen_config.go b/client/knode/gen_config.go index 2cf0cc0bf..2fc6c0162 100644 --- a/client/knode/gen_config.go +++ b/client/knode/gen_config.go @@ -11,6 +11,7 @@ import ( "github.com/kowala-tech/kcoin/client/core" "github.com/kowala-tech/kcoin/client/knode/downloader" "github.com/kowala-tech/kcoin/client/knode/gasprice" + "github.com/kowala-tech/kcoin/client/knode/validator" ) var _ = (*configMarshaling)(nil) @@ -38,6 +39,7 @@ func (c Config) MarshalTOML() (interface{}, error) { EnablePreimageRecording bool DocRoot string `toml:"-"` Currency string + ValidatorConfig *validator.Config } var enc Config enc.Genesis = c.Genesis @@ -60,6 +62,7 @@ func (c Config) MarshalTOML() (interface{}, error) { enc.EnablePreimageRecording = c.EnablePreimageRecording enc.DocRoot = c.DocRoot enc.Currency = c.Currency + enc.ValidatorConfig = c.ValidatorConfig return &enc, nil } @@ -86,6 +89,7 @@ func (c *Config) UnmarshalTOML(unmarshal func(interface{}) error) error { EnablePreimageRecording *bool DocRoot *string `toml:"-"` Currency *string + ValidatorConfig *validator.Config } var dec Config if err := unmarshal(&dec); err != nil { @@ -151,5 +155,8 @@ func (c *Config) UnmarshalTOML(unmarshal func(interface{}) error) error { if dec.Currency != nil { c.Currency = *dec.Currency } + if dec.ValidatorConfig != nil { + c.ValidatorConfig = dec.ValidatorConfig + } return nil } diff --git a/client/knode/service.go b/client/knode/service.go index 69d1559f1..ccabf4f3e 100644 --- a/client/knode/service.go +++ b/client/knode/service.go @@ -97,6 +97,7 @@ func New(ctx *node.ServiceContext, config *Config) (*Kowala, error) { if !config.SyncMode.IsValid() { return nil, fmt.Errorf("invalid sync mode %d", config.SyncMode) } + chainDb, err := CreateDB(ctx, config, "chaindata") if err != nil { return nil, err @@ -196,7 +197,7 @@ func New(ctx *node.ServiceContext, config *Config) (*Kowala, error) { } kcoin.apiBackend.gpo = gasprice.NewOracle(kcoin.apiBackend, gpoParams) - kcoin.validator = validator.New(kcoin, kcoin.consensus, kcoin.chainConfig, kcoin.EventMux(), kcoin.engine, vmConfig) + kcoin.validator = validator.New(kcoin.config.ValidatorConfig, kcoin, kcoin.consensus, kcoin.chainConfig, kcoin.EventMux(), kcoin.engine, vmConfig) kcoin.validator.SetExtra(makeExtraData(config.ExtraData)) if kcoin.protocolManager, err = NewProtocolManager(kcoin.chainConfig, config.SyncMode, config.NetworkId, kcoin.eventMux, kcoin.txPool, kcoin.engine, kcoin.blockchain, chainDb, kcoin.validator); err != nil { diff --git a/client/knode/validator/config.go b/client/knode/validator/config.go new file mode 100644 index 000000000..f5cb20f36 --- /dev/null +++ b/client/knode/validator/config.go @@ -0,0 +1,5 @@ +package validator + +type Config struct { + LogDir string +} diff --git a/client/knode/validator/states.go b/client/knode/validator/states.go index fdcf8a29d..77e0e8762 100644 --- a/client/knode/validator/states.go +++ b/client/knode/validator/states.go @@ -12,7 +12,6 @@ import ( "github.com/kowala-tech/kcoin/client/core" "github.com/kowala-tech/kcoin/client/core/state" "github.com/kowala-tech/kcoin/client/core/types" - "github.com/kowala-tech/kcoin/client/log" "github.com/kowala-tech/kcoin/client/params" "github.com/davecgh/go-spew/spew" @@ -33,7 +32,7 @@ func (val *validator) genesisNotLoggedInState() stateFn { // no need to make a deposit if the block number is 0 // since these validators will be marked as voters from the start if val.isBlockZero() { - log.Info("Deposit is not necessary for a genesis validator (first block)") + val.logger.Info("Deposit is not necessary for a genesis validator (first block)") return val.startValidating } return val.notLoggedInState @@ -42,12 +41,12 @@ func (val *validator) genesisNotLoggedInState() stateFn { func (val *validator) notLoggedInState() stateFn { isValidator, err := val.consensus.IsValidator(val.walletAccount.Account().Address) if err != nil { - log.Crit("Failed to verify if account is already a validator") + val.logger.Crit("Failed to verify if account is already a validator") } if !isValidator { if err := val.makeDeposit(); err != nil { - log.Error("Failed to make deposit", "err", err) + val.logger.Error("Failed to make deposit", "err", err) return nil } } @@ -58,26 +57,26 @@ func (val *validator) notLoggedInState() stateFn { func (val *validator) makeDeposit() error { txHash, err := val.consensus.Join(val.walletAccount, val.deposit) if err != nil { - log.Error("Error joining validators network", "err", err) + val.logger.Error("Error joining validators network", "err", err) return nil } - log.Info("Waiting confirmation to participate in the consensus") + val.logger.Info("Waiting confirmation to participate in the consensus") receipt, err := tx.WaitMinedWithTimeout(val.backend, txHash, txConfirmationTimeout) if err != nil { - log.Crit("Failed to verify the voter registration", "err", err) + val.logger.Crit("Failed to verify the voter registration", "err", err) } if receipt.Status == types.ReceiptStatusFailed { - log.Crit("Failed to register the validator - receipt status failed") + val.logger.Crit("Failed to register the validator - receipt status failed") } return nil } func (val *validator) startValidating() stateFn { - log.Info("Starting validation operation") + val.logger.Info("Starting validation operation") atomic.StoreInt32(&val.validating, 1) - log.Info("Voter has been accepted in the election", "enode", val.walletAccount.Account().Address.String()) + val.logger.Info("Voter has been accepted in the election", "enode", val.walletAccount.Account().Address.String()) val.restoreLastCommit() return val.newElectionState @@ -88,7 +87,7 @@ func (val *validator) isBlockZero() bool { } func (val *validator) newElectionState() stateFn { - log.Info("Starting a new election") + val.logger.Info("Starting a new election") // update state machine based on current state if err := val.init(); err != nil { return nil @@ -100,7 +99,7 @@ func (val *validator) newElectionState() stateFn { if val.blockNumber.Cmp(big.NewInt(1)) == 0 { numTxs, _ := val.backend.TxPool().Stats() // if val.round == 0 && numTxs == 0 { - log.Info("Waiting for a TX") + val.logger.Info("Waiting for a TX") txCh := make(chan core.NewTxsEvent) txSub := val.backend.TxPool().SubscribeNewTxsEvent(txCh) defer txSub.Unsubscribe() @@ -112,7 +111,7 @@ func (val *validator) newElectionState() stateFn { } func (val *validator) newRoundState() stateFn { - log.Info("Starting a new voting round", "start time", val.start, "block number", val.blockNumber, "round", val.round) + val.logger.Info("Starting a new voting round", "start time", val.start, "block number", val.blockNumber, "round", val.round) val.voters.NextProposer() @@ -132,10 +131,10 @@ func (val *validator) newRoundState() stateFn { func (val *validator) newProposalState() stateFn { proposer := val.voters.NextProposer() if proposer.Address() == val.walletAccount.Account().Address { - log.Info("Proposing a new block") + val.logger.Info("Proposing a new block") val.propose() } else { - log.Info("Waiting for the proposal", "addr", proposer.Address()) + val.logger.Info("Waiting for the proposal", "addr", proposer.Address()) val.waitForProposal() } return val.preVoteState @@ -146,62 +145,62 @@ func (val *validator) waitForProposal() { select { case block := <-val.blockCh: val.block = block - log.Info("Received the block", "hash", val.block.Hash()) + val.logger.Info("Received the block", "hash", val.block.Hash()) case <-time.After(timeout): - log.Info("Timeout expired", "duration", timeout) + val.logger.Info("Timeout expired", "duration", timeout) } } func (val *validator) preVoteState() stateFn { - log.Info("Pre vote sub-election") + val.logger.Info("Pre vote sub-election") val.preVote() return val.preVoteWaitState } func (val *validator) preVoteWaitState() stateFn { - log.Info("Waiting for a majority in the pre-vote sub-election") + val.logger.Info("Waiting for a majority in the pre-vote sub-election") timeout := time.Duration(params.PreVoteDuration+val.round*params.PreVoteDeltaDuration) * time.Millisecond select { case <-val.majority.Chan(): - log.Info("There's a majority in the pre-vote sub-election!") + val.logger.Info("There's a majority in the pre-vote sub-election!") // fixme shall we do something here with current stateDB? case <-time.After(timeout): - log.Info("Timeout expired", "duration", timeout) + val.logger.Info("Timeout expired", "duration", timeout) } return val.preCommitState } func (val *validator) preCommitState() stateFn { - log.Info("Pre commit sub-election") + val.logger.Info("Pre commit sub-election") val.preCommit() return val.preCommitWaitState } func (val *validator) preCommitWaitState() stateFn { - log.Info("Waiting for a majority in the pre-commit sub-election") + val.logger.Info("Waiting for a majority in the pre-commit sub-election") timeout := time.Duration(params.PreCommitDuration+val.round+params.PreCommitDeltaDuration) * time.Millisecond defer val.majority.Unsubscribe() select { case event := <-val.majority.Chan(): - log.Info("There's a majority in the pre-commit sub-election!", "event", spew.Sdump(event)) + val.logger.Info("There's a majority in the pre-commit sub-election!", "event", spew.Sdump(event)) if val.block == nil || bytes.Equal(val.block.Hash().Bytes(), common.Hash{}.Bytes()) { - log.Debug("No one block wins!") + val.logger.Debug("No one block wins!") return val.newRoundState } return val.commitState case <-time.After(timeout): - log.Info("Timeout expired", "duration", timeout) + val.logger.Info("Timeout expired", "duration", timeout) return val.newRoundState } } func (val *validator) commitState() stateFn { - log.Info("Commit state") + val.logger.Info("Commit state") blockHash := val.block.Hash() @@ -218,7 +217,7 @@ func (val *validator) commitState() stateFn { _, err := val.chain.WriteBlockWithState(val.block, val.work.receipts, val.work.state) if err != nil { - log.Error("Failed writing block to chain", "err", err) + val.logger.Error("Failed writing block to chain", "err", err) return nil } @@ -237,10 +236,10 @@ func (val *validator) commitState() stateFn { voter, err := val.consensus.IsValidator(val.walletAccount.Account().Address) if err != nil { - log.Crit("Failed to verify if the validator is a voter", "err", err) + val.logger.Crit("Failed to verify if the validator is a voter", "err", err) } if !voter { - log.Info(fmt.Sprintf("Logging out. Account %q is not a validator", val.walletAccount.Account().Address.String())) + val.logger.Info(fmt.Sprintf("Logging out. Account %q is not a validator", val.walletAccount.Account().Address.String())) return val.loggedOutState } @@ -248,7 +247,7 @@ func (val *validator) commitState() stateFn { } func (val *validator) loggedOutState() stateFn { - log.Info("Logged out") + val.logger.Info("Logged out") atomic.StoreInt32(&val.validating, 0) diff --git a/client/knode/validator/validator.go b/client/knode/validator/validator.go index 5a6597753..d2924f0a6 100644 --- a/client/knode/validator/validator.go +++ b/client/knode/validator/validator.go @@ -5,6 +5,7 @@ import ( "errors" "fmt" "math/big" + "path/filepath" "sync" "sync/atomic" "time" @@ -24,6 +25,12 @@ import ( "github.com/kowala-tech/kcoin/client/params" ) +const ( + logFilename = "validator_all.log" + logFilenameErr = "validator_err.log" + logFilenameCrit = "validator_crit.log" +) + var ( ErrCantStopNonStartedValidator = errors.New("can't stop validator, not started") ErrCantVoteNotValidating = errors.New("can't vote, not validating") @@ -69,6 +76,7 @@ type Service interface { // validator represents a consensus validator type validator struct { + config *Config VotingState // consensus internal state maxTransitions int // max number of state transitions (tests) 0 - unlimited @@ -79,11 +87,11 @@ type validator struct { signer types.Signer // blockchain - backend Backend - chain *core.BlockChain - config *params.ChainConfig - engine engine.Engine - vmConfig vm.Config + backend Backend + chain *core.BlockChain + chainConfig *params.ChainConfig + engine engine.Engine + vmConfig vm.Config walletAccount accounts.WalletAccount @@ -99,21 +107,32 @@ type validator struct { wg sync.WaitGroup handleMutex sync.Mutex + + logger log.Logger } // New returns a new consensus validator -func New(backend Backend, consensus *consensus.Consensus, config *params.ChainConfig, eventMux *event.TypeMux, engine engine.Engine, vmConfig vm.Config) *validator { +func New(config *Config, backend Backend, consensus *consensus.Consensus, chainConfig *params.ChainConfig, eventMux *event.TypeMux, engine engine.Engine, vmConfig vm.Config) *validator { validator := &validator{ - config: config, - backend: backend, - chain: backend.BlockChain(), - engine: engine, - consensus: consensus, - eventMux: eventMux, - signer: types.NewAndromedaSigner(config.ChainID), - vmConfig: vmConfig, - canStart: 0, - } + config: config, + chainConfig: chainConfig, + backend: backend, + chain: backend.BlockChain(), + engine: engine, + consensus: consensus, + eventMux: eventMux, + signer: types.NewAndromedaSigner(chainConfig.ChainID), + vmConfig: vmConfig, + canStart: 0, + logger: log.New("package", "knode/validator"), + } + + validator.logger.SetHandler(log.MultiHandler( + log.StdoutHandler, + log.Must.FileHandler(filepath.Join(config.LogDir, logFilename), log.LogfmtFormat()), + log.LvlFilterHandler(log.LvlError, log.Must.FileHandler(filepath.Join(config.LogDir, logFilenameErr), log.LogfmtFormat())), + log.LvlFilterHandler(log.LvlCrit, log.Must.FileHandler(filepath.Join(config.LogDir, logFilenameCrit), log.LogfmtFormat()))), + ) go validator.sync() @@ -122,7 +141,7 @@ func New(backend Backend, consensus *consensus.Consensus, config *params.ChainCo func (val *validator) sync() { if err := SyncWaiter(val.eventMux); err != nil { - log.Warn("Failed to sync with network", "err", err) + val.logger.Crit("Failed to sync with network", "err", err) } else { val.finishedSync() } @@ -139,7 +158,7 @@ func (val *validator) finishedSync() { func (val *validator) Start(walletAccount accounts.WalletAccount, deposit *big.Int) { if val.Validating() { - log.Warn("failed to start the validator - the state machine is already running") + val.logger.Warn("failed to start the validator - the state machine is already running") return } @@ -149,7 +168,7 @@ func (val *validator) Start(walletAccount accounts.WalletAccount, deposit *big.I val.deposit = deposit if atomic.LoadInt32(&val.canStart) == 0 { - log.Info("network syncing, will start validator afterwards") + val.logger.Info("network syncing, will start validator afterwards") return } @@ -157,7 +176,7 @@ func (val *validator) Start(walletAccount accounts.WalletAccount, deposit *big.I } func (val *validator) run() { - log.Info("Starting validation operation") + val.logger.Info("Starting validation operation") val.wg.Add(1) atomic.StoreInt32(&val.running, 1) @@ -171,7 +190,7 @@ func (val *validator) run() { initialStateFunc = val.genesisNotLoggedInState } - log.Info("Starting the consensus state machine") + val.logger.Info("Starting the consensus state machine") for state, numTransitions := initialStateFunc, 0; state != nil; numTransitions++ { state = state() if val.maxTransitions > 0 && numTransitions == val.maxTransitions { @@ -193,13 +212,13 @@ func (val *validator) Stop() error { if !val.Validating() { return ErrCantStopNonStartedValidator } - log.Info("Stopping consensus validator") + val.logger.Info("Stopping consensus validator") val.leave() val.wg.Wait() // waits until the validator is no longer registered as a voter. atomic.StoreInt32(&val.shouldStart, 0) - log.Info("Consensus validator stopped") + val.logger.Info("Consensus validator stopped") return nil } @@ -235,7 +254,7 @@ func (val *validator) SetDeposit(deposit *big.Int) error { func (val *validator) Pending() (*types.Block, *state.StateDB) { state, err := val.chain.State() if err != nil { - log.Crit("Failed to fetch the latest state", "err", err) + val.logger.Crit("Failed to fetch the latest state", "err", err) } return val.chain.CurrentBlock(), state @@ -248,11 +267,11 @@ func (val *validator) PendingBlock() *types.Block { func (val *validator) restoreLastCommit() { checksum, err := val.consensus.ValidatorsChecksum() if err != nil { - log.Crit("Failed to access the voters checksum", "err", err) + val.logger.Crit("Failed to access the voters checksum", "err", err) } if err := val.updateValidators(checksum, true); err != nil { - log.Crit("Failed to update the validator set", "err", err) + val.logger.Crit("Failed to update the validator set", "err", err) } currentBlock := val.chain.CurrentBlock() @@ -266,12 +285,12 @@ func (val *validator) init() error { checksum, err := val.consensus.ValidatorsChecksum() if err != nil { - log.Crit("Failed to access the voters checksum", "err", err) + val.logger.Crit("Failed to access the voters checksum", "err", err) } if val.votersChecksum != checksum { if err := val.updateValidators(checksum, true); err != nil { - log.Crit("Failed to update the validator set", "err", err) + val.logger.Crit("Failed to update the validator set", "err", err) } } @@ -290,7 +309,7 @@ func (val *validator) init() error { val.votingSystem, err = NewVotingSystem(val.eventMux, val.blockNumber, val.voters) if err != nil { - log.Error("Failed to create voting system", "err", err) + val.logger.Error("Failed to create voting system", "err", err) return nil } @@ -298,7 +317,7 @@ func (val *validator) init() error { val.majority = val.eventMux.Subscribe(core.NewMajorityEvent{}) if err = val.makeCurrent(parent); err != nil { - log.Error("Failed to create mining context", "err", err) + val.logger.Error("Failed to create mining context", "err", err) return nil } @@ -310,7 +329,7 @@ func (val *validator) AddProposal(proposal *types.Proposal) error { return ErrCantAddProposalNotValidating } - log.Info("Received Proposal") + val.logger.Info("Received Proposal") val.handleMutex.Lock() val.proposal = proposal @@ -334,7 +353,7 @@ func (val *validator) AddVote(vote *types.Vote) error { } if err := val.votingSystem.Add(addressVote); err != nil { - log.Error("cannot add the vote", "err", err) + val.logger.Error("cannot add the vote", "err", err) } return nil @@ -364,17 +383,17 @@ func (val *validator) commitTransactions(mux *event.TypeMux, txs *types.Transact switch err { case core.ErrGasLimitReached: // Pop the current out-of-gas transaction without shifting in the next from the account - log.Trace("Gas limit exceeded for current block", "sender", from) + val.logger.Trace("Gas limit exceeded for current block", "sender", from) txs.Pop() case core.ErrNonceTooLow: // New head notification data race between the transaction pool and miner, shift - log.Trace("Skipping transaction with low nonce", "sender", from, "nonce", tx.Nonce()) + val.logger.Trace("Skipping transaction with low nonce", "sender", from, "nonce", tx.Nonce()) txs.Shift() case core.ErrNonceTooHigh: // Reorg notification data race between the transaction pool and miner, skip account = - log.Trace("Skipping account with hight nonce", "sender", from, "nonce", tx.Nonce()) + val.logger.Trace("Skipping account with hight nonce", "sender", from, "nonce", tx.Nonce()) txs.Pop() case nil: @@ -386,7 +405,7 @@ func (val *validator) commitTransactions(mux *event.TypeMux, txs *types.Transact default: // Strange error, discard the transaction and get the next in line (note, the // nonce-too-high clause will prevent us from executing in vain). - log.Debug("Transaction failed, account skipped", "hash", tx.Hash(), "err", err) + val.logger.Debug("Transaction failed, account skipped", "hash", tx.Hash(), "err", err) txs.Shift() } } @@ -414,7 +433,7 @@ func (val *validator) commitTransactions(mux *event.TypeMux, txs *types.Transact func (val *validator) commitTransaction(tx *types.Transaction, bc *core.BlockChain, coinbase common.Address, gp *core.GasPool) (error, []*types.Log) { snap := val.state.Snapshot() - receipt, _, err := core.ApplyTransaction(val.config, bc, &coinbase, gp, val.state, val.header, tx, &val.header.GasUsed, vm.Config{}) + receipt, _, err := core.ApplyTransaction(val.chainConfig, bc, &coinbase, gp, val.state, val.header, tx, &val.header.GasUsed, vm.Config{}) if err != nil { val.state.RevertToSnapshot(snap) return err, nil @@ -428,27 +447,27 @@ func (val *validator) commitTransaction(tx *types.Transaction, bc *core.BlockCha func (val *validator) leave() { txHash, err := val.consensus.Leave(val.walletAccount) if err != nil { - log.Error("failed to leave the election", "err", err) + val.logger.Error("failed to leave the election", "err", err) } receipt, err := tx.WaitMinedWithTimeout(val.backend, txHash, txConfirmationTimeout) if err != nil { - log.Error("Failed to verify the voter deregistration", "err", err) + val.logger.Error("Failed to verify the voter deregistration", "err", err) } if receipt.Status == types.ReceiptStatusFailed { - log.Error("Failed to deregister validator - receipt status failed") + val.logger.Error("Failed to deregister validator - receipt status failed") } } func (val *validator) createProposalBlock() *types.Block { if val.lockedBlock != nil { - log.Info("Picking a locked block") + val.logger.Info("Picking a locked block") return val.lockedBlock } return val.createBlock() } func (val *validator) createBlock() *types.Block { - log.Info("Creating a new block") + val.logger.Info("Creating a new block") // new block header parent := val.chain.CurrentBlock() blockNumber := parent.Number() @@ -484,13 +503,13 @@ func (val *validator) createBlock() *types.Block { } if err := val.engine.Prepare(val.chain, header); err != nil { - log.Error("Failed to prepare header for mining", "err", err) + val.logger.Error("Failed to prepare header for mining", "err", err) return nil } pending, err := val.backend.TxPool().Pending() if err != nil { - log.Crit("Failed to fetch pending transactions", "err", err) + val.logger.Crit("Failed to fetch pending transactions", "err", err) } txs := types.NewTransactionsByPriceAndNonce(val.signer, pending) @@ -499,7 +518,7 @@ func (val *validator) createBlock() *types.Block { // Create the new block to seal with the consensus engine var block *types.Block if block, err = val.engine.Finalize(val.chain, header, val.state, val.txs, commit, val.receipts); err != nil { - log.Crit("Failed to finalize block for sealing", "err", err) + val.logger.Crit("Failed to finalize block for sealing", "err", err) } return block @@ -513,14 +532,14 @@ func (val *validator) propose() { fragments, err := block.AsFragments(int(block.Size())) if err != nil { - log.Crit("Failed to get the block as a set of fragments of information", "err", err) + val.logger.Crit("Failed to get the block as a set of fragments of information", "err", err) } proposal := types.NewProposal(val.blockNumber, val.round, fragments.Metadata(), lockedRound, lockedBlock) - signedProposal, err := val.walletAccount.SignProposal(val.walletAccount.Account(), proposal, val.config.ChainID) + signedProposal, err := val.walletAccount.SignProposal(val.walletAccount.Account(), proposal, val.chainConfig.ChainID) if err != nil { - log.Crit("Failed to sign the proposal", "err", err) + val.logger.Crit("Failed to sign the proposal", "err", err) } val.proposal = signedProposal @@ -542,13 +561,13 @@ func (val *validator) preVote() { var vote common.Hash switch { case val.lockedBlock != nil: - log.Debug("Locked Block is not nil, voting for the locked block") + val.logger.Debug("Locked Block is not nil, voting for the locked block") vote = val.lockedBlock.Hash() case val.block == nil: - log.Warn("Proposal's block is nil, voting nil") + val.logger.Warn("Proposal's block is nil, voting nil") vote = common.Hash{} default: - log.Debug("Voting for the proposal's block") + val.logger.Debug("Voting for the proposal's block") vote = val.block.Hash() } @@ -561,7 +580,7 @@ func (val *validator) preCommit() { // current leader by simple majority votingTable, err := val.votingSystem.getVoteSet(val.round, types.PreVote) if err != nil { - log.Crit("Error while preCommit stage", "err", err) + val.logger.Crit("Error while preCommit stage", "err", err) } currentLeader := votingTable.Leader() @@ -570,20 +589,20 @@ func (val *validator) preCommit() { // no majority // majority pre-voted nil case currentLeader == common.Hash{}: - log.Warn("Majority of validators pre-voted nil") + val.logger.Warn("Majority of validators pre-voted nil") // unlock locked block if val.lockedBlock != nil { val.lockedRound = 0 val.lockedBlock = nil } case val.lockedBlock != nil && currentLeader == val.lockedBlock.Hash(): - log.Debug("Majority of validators pre-voted the locked block", "block", val.lockedBlock.Hash()) + val.logger.Debug("Majority of validators pre-voted the locked block", "block", val.lockedBlock.Hash()) // update locked block round val.lockedRound = val.round // vote on the pre-vote election winner vote = currentLeader case val.block != nil && currentLeader == val.block.Hash(): - log.Debug("Majority of validators pre-voted the proposed block", "block", val.block.Hash()) + val.logger.Debug("Majority of validators pre-voted the proposed block", "block", val.block.Hash()) // lock block val.lockedRound = val.round val.lockedBlock = val.block @@ -593,7 +612,7 @@ func (val *validator) preCommit() { default: // fetch block, unlock, precommit // unlock locked block - log.Warn("preCommit default case") + val.logger.Warn("preCommit default case") val.lockedRound = 0 val.lockedBlock = nil val.block = nil @@ -603,19 +622,19 @@ func (val *validator) preCommit() { } func (val *validator) vote(vote *types.Vote) { - signedVote, err := val.walletAccount.SignVote(val.walletAccount.Account(), vote, val.config.ChainID) + signedVote, err := val.walletAccount.SignVote(val.walletAccount.Account(), vote, val.chainConfig.ChainID) if err != nil { - log.Crit("Failed to sign the vote", "err", err) + val.logger.Crit("Failed to sign the vote", "err", err) } addressVote, err := types.NewAddressVote(val.signer, signedVote) if err != nil { - log.Crit("Failed to make address Vote", "err", err) + val.logger.Crit("Failed to make address Vote", "err", err) } err = val.votingSystem.Add(addressVote) if err != nil { - log.Error("Failed to add own vote to voting table", + val.logger.Error("Failed to add own vote to voting table", "err", err, "blockHash", addressVote.Vote().BlockHash(), "hash", addressVote.Vote().Hash()) } } @@ -634,7 +653,7 @@ func (val *validator) AddBlockFragment(blockNumber *big.Int, round uint64, fragm block, err := val.blockFragments.Assemble() if err != nil { err = errors.New("Failed to assemble the block: " + err.Error()) - log.Error("error while adding a new block fragment", "err", err, "round", round, "block", blockNumber, "fragment", fragment) + val.logger.Error("error while adding a new block fragment", "err", err, "round", round, "block", blockNumber, "fragment", fragment) return err } @@ -653,7 +672,7 @@ func (val *validator) AddBlockFragment(blockNumber *big.Int, round uint64, fragm err = val.chain.Validator().ValidateBody(block) if err != nil { err = errors.New("Failed to validate thr block body: " + err.Error()) - log.Error("error while validating a block body", + val.logger.Error("error while validating a block body", "err", err, "round", round, "block", blockNumber, "fragment", fragment, "block", block) return err @@ -665,10 +684,10 @@ func (val *validator) AddBlockFragment(blockNumber *big.Int, round uint64, fragm // Process block using the parent state as reference point. receipts, _, usedGas, err := val.chain.Processor().Process(block, val.state, val.vmConfig) if err != nil { - log.Error("Failed to process the block", "err", err, + val.logger.Error("Failed to process the block", "err", err, "round", round, "block", blockNumber, "fragment", fragment, "block", block) - log.Crit("Failed to process the block", "err", err) + val.logger.Crit("Failed to process the block", "err", err) } // guarded section @@ -680,10 +699,10 @@ func (val *validator) AddBlockFragment(blockNumber *big.Int, round uint64, fragm if err != nil { val.handleMutex.Unlock() - log.Error("Failed to validate the state", "err", err, + val.logger.Error("Failed to validate the state", "err", err, "round", round, "block", blockNumber, "fragment", fragment, "block", block) - log.Crit("Failed to validate the state", "err", err) + val.logger.Crit("Failed to validate the state", "err", err) } val.block = block @@ -716,9 +735,9 @@ func (val *validator) updateValidators(checksum [32]byte, genesis bool) error { } if val.voters != nil { - log.Debug("voting. updating a list of validators", "was", val.voters.Len(), "now", validators.Len()) + val.logger.Debug("voting. updating a list of validators", "was", val.voters.Len(), "now", validators.Len()) } else { - log.Debug("voting. updating a list of validators", "was", "nil", "now", validators.Len()) + val.logger.Debug("voting. updating a list of validators", "was", "nil", "now", validators.Len()) } val.voters = validators diff --git a/e2e/godog.go b/e2e/godog.go index 26014bd01..5864fa4b4 100644 --- a/e2e/godog.go +++ b/e2e/godog.go @@ -4,6 +4,7 @@ import ( "log" "regexp" "strings" + "time" "github.com/DATA-DOG/godog" "github.com/DATA-DOG/godog/gherkin" @@ -38,6 +39,7 @@ func FeatureContext(opts *FeatureContextOpts) { validationCtx.Reset() walletBackendCtx.Reset() faucetCtx.Reset() + time.Sleep(5 * time.Second) }) // Genesis and cluster creation