From 78831e067791804b68bf322092d2ab87bfc181fa Mon Sep 17 00:00:00 2001 From: setunapo Date: Wed, 16 Nov 2022 22:30:51 +0800 Subject: [PATCH 1/4] worker: fix a bug of the delay timer. `fillTransactions` will call `commitTransactions` twice, if the delay timer is expired during the first call, it will make the delay timer never be triggered in the second commitTransactions call. Pseudo code: x := time.NewTimer(time.Second) <-x.C fmt.Println("read delay 1") <-x.C fmt.Println("read delay 2") // will never hit --- miner/worker.go | 1 + 1 file changed, 1 insertion(+) diff --git a/miner/worker.go b/miner/worker.go index 2d43f6c866..1d44ee0fa5 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -809,6 +809,7 @@ LOOP: select { case <-stopTimer.C: log.Info("Not enough time for further transactions", "txs", len(env.txs)) + stopTimer.Reset(0) // re-active the timer, in case it will be used later. break LOOP default: } From ad55d231cb60676987d712e302c3c9fc4090e490 Mon Sep 17 00:00:00 2001 From: setunapo Date: Fri, 28 Oct 2022 12:01:18 +0800 Subject: [PATCH 2/4] fair: some block produce enhancement of work.go ** try fillTransactions several times for the best ** drop current mining block on new block imported ** commitTransactions return with a reason ** code refactor, use error code --- consensus/beacon/consensus.go | 4 + consensus/clique/clique.go | 5 ++ consensus/consensus.go | 6 ++ consensus/ethash/consensus.go | 4 + consensus/parlia/parlia.go | 9 +- miner/worker.go | 162 +++++++++++++++++++++++++++++----- 6 files changed, 168 insertions(+), 22 deletions(-) diff --git a/consensus/beacon/consensus.go b/consensus/beacon/consensus.go index 8282ed7cb4..4f4c272a0a 100644 --- a/consensus/beacon/consensus.go +++ b/consensus/beacon/consensus.go @@ -363,6 +363,10 @@ func (beacon *Beacon) SetThreads(threads int) { } } +func (p *Beacon) DropOnNewBlock(*types.Header) bool { + return true +} + // IsTTDReached checks if the TotalTerminalDifficulty has been surpassed on the `parentHash` block. // It depends on the parentHash already being stored in the database. // If the parentHash is not stored in the database a UnknownAncestor error is returned. diff --git a/consensus/clique/clique.go b/consensus/clique/clique.go index a258f1fe5f..11287e74ef 100644 --- a/consensus/clique/clique.go +++ b/consensus/clique/clique.go @@ -705,6 +705,11 @@ func (c *Clique) APIs(chain consensus.ChainHeaderReader) []rpc.API { }} } +func (p *Clique) DropOnNewBlock(header *types.Header) bool { + // drop the block if it is not in turn. + return header.Difficulty.Cmp(diffNoTurn) == 0 +} + // SealHash returns the hash of a block prior to it being sealed. func SealHash(header *types.Header) (hash common.Hash) { hasher := sha3.NewLegacyKeccak256() diff --git a/consensus/consensus.go b/consensus/consensus.go index 87632a9d0d..367a703678 100644 --- a/consensus/consensus.go +++ b/consensus/consensus.go @@ -130,6 +130,12 @@ type Engine interface { // Close terminates any background threads maintained by the consensus engine. Close() error + + // DropOnNewBlock determine the action of mining when it is interrupted by new imported block. + // Return + // true: the mining result will be dropped + // false: the mining result will be kept and move on to the next mine step. + DropOnNewBlock(header *types.Header) bool } // PoW is a consensus engine based on proof-of-work. diff --git a/consensus/ethash/consensus.go b/consensus/ethash/consensus.go index 12a69c127a..0bf77a8ae0 100644 --- a/consensus/ethash/consensus.go +++ b/consensus/ethash/consensus.go @@ -647,6 +647,10 @@ var ( big32 = big.NewInt(32) ) +func (p *Ethash) DropOnNewBlock(*types.Header) bool { + return true +} + // AccumulateRewards credits the coinbase of the given block with the mining // reward. The total reward consists of the static block reward and rewards for // included uncles. The coinbase of each uncle block is also rewarded. diff --git a/consensus/parlia/parlia.go b/consensus/parlia/parlia.go index 2e544803ef..89343a8c8f 100644 --- a/consensus/parlia/parlia.go +++ b/consensus/parlia/parlia.go @@ -864,7 +864,9 @@ func (p *Parlia) Seal(chain consensus.ChainHeaderReader, block *types.Block, res // Sweet, the protocol permits us to sign the block, wait for our time delay := p.delayForRamanujanFork(snap, header) - log.Info("Sealing block with", "number", number, "delay", delay, "headerDifficulty", header.Difficulty, "val", val.Hex()) + log.Info("Sealing block with", "number", number, "delay", delay, + "header.Time Second", time.Unix(int64(header.Time), 0).Second(), + "headerDifficulty", header.Difficulty, "val", val.Hex()) // Sign all the things! sig, err := signFn(accounts.Account{Address: val}, accounts.MimetypeParlia, ParliaRLP(header, p.chainConfig.ChainID)) @@ -976,6 +978,11 @@ func (p *Parlia) CalcDifficulty(chain consensus.ChainHeaderReader, time uint64, return CalcDifficulty(snap, p.val) } +func (p *Parlia) DropOnNewBlock(header *types.Header) bool { + // drop the block if it is not in turn. + return header.Difficulty.Cmp(diffNoTurn) == 0 +} + // CalcDifficulty is the difficulty adjustment algorithm. It returns the difficulty // that a new block should have based on the previous blocks in the chain and the // current signer. diff --git a/miner/worker.go b/miner/worker.go index 1d44ee0fa5..de314a43f8 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -19,6 +19,7 @@ package miner import ( "errors" "fmt" + "math/big" "sync" "sync/atomic" "time" @@ -67,6 +68,11 @@ const ( var ( writeBlockTimer = metrics.NewRegisteredTimer("worker/writeblock", nil) finalizeBlockTimer = metrics.NewRegisteredTimer("worker/finalizeblock", nil) + + errBlockInterruptedByNewHead = errors.New("new head arrived while building block") + errBlockInterruptedByRecommit = errors.New("recommit interrupt while building block") + errBlockInterruptedByTimeout = errors.New("timeout while building block") + errBlockInterruptedByOutOfGas = errors.New("out of gas while building block") ) // environment is the worker's current environment and holds all @@ -142,8 +148,11 @@ type task struct { } const ( - commitInterruptNewHead int32 = 1 - commitInterruptResubmit int32 = 2 + commitInterruptNone int32 = iota + commitInterruptNewHead + commitInterruptResubmit + commitInterruptTimeout + commitInterruptOutOfGas ) // newWorkReq represents a request for new sealing work submitting with relative interrupt notifier. @@ -401,6 +410,7 @@ func (w *worker) newWorkLoop(recommit time.Duration) { commit(commitInterruptNewHead) case head := <-w.chainHeadCh: + log.Info("newWorkLoop chainHeadCh", "block number", head.Block.NumberU64()) if !w.isRunning() { continue } @@ -471,6 +481,7 @@ func (w *worker) mainLoop() { for { select { case req := <-w.newWorkCh: + log.Info("mainLoop newWorkCh") w.commitWork(req.interruptCh, req.timestamp) case req := <-w.getWorkCh: @@ -754,7 +765,7 @@ func (w *worker) commitTransaction(env *environment, tx *types.Transaction, rece } func (w *worker) commitTransactions(env *environment, txs *types.TransactionsByPriceAndNonce, - interruptCh chan int32, stopTimer *time.Timer) bool { + interruptCh chan int32, stopTimer *time.Timer) error { gasLimit := env.header.GasLimit if env.gasPool == nil { env.gasPool = new(core.GasPool).AddGas(gasLimit) @@ -781,6 +792,7 @@ func (w *worker) commitTransactions(env *environment, txs *types.TransactionsByP txCurr := &tx w.prefetcher.PrefetchMining(txsPrefetch, env.header, env.gasPool.Gas(), env.state.CopyDoPrefetch(), *w.chain.GetVMConfig(), stopPrefetchCh, txCurr) + signal := commitInterruptNone LOOP: for { // In the following three cases, we will interrupt the execution of the transaction. @@ -791,18 +803,19 @@ LOOP: // For the third case, the semi-finished work will be submitted to the consensus engine. if interruptCh != nil { select { - case reason, ok := <-interruptCh: + case signal, ok := <-interruptCh: if !ok { // should never be here, since interruptCh should not be read before - log.Warn("commit transactions stopped unknown") + log.Error("commit transactions stopped unknown") } - return reason == commitInterruptNewHead + return signalToErr(signal) default: } } // If we don't have enough gas for any further transactions then we're done if env.gasPool.Gas() < params.TxGas { log.Trace("Not enough gas for further transactions", "have", env.gasPool, "want", params.TxGas) + signal = commitInterruptOutOfGas break } if stopTimer != nil { @@ -810,6 +823,7 @@ LOOP: case <-stopTimer.C: log.Info("Not enough time for further transactions", "txs", len(env.txs)) stopTimer.Reset(0) // re-active the timer, in case it will be used later. + signal = commitInterruptTimeout break LOOP default: } @@ -885,7 +899,7 @@ LOOP: } w.pendingLogsFeed.Send(cpy) } - return false + return signalToErr(signal) } // generateParams wraps various of settings for generating sealing task. @@ -988,7 +1002,7 @@ func (w *worker) prepareWork(genParams *generateParams) (*environment, error) { // fillTransactions retrieves the pending transactions from the txpool and fills them // into the given sealing block. The transaction selection and ordering strategy can // be customized with the plugin in the future. -func (w *worker) fillTransactions(interruptCh chan int32, env *environment) { +func (w *worker) fillTransactions(interruptCh chan int32, env *environment) (err error) { // Split the pending transactions into locals and remotes // Fill the block with all available pending transactions. pending := w.eth.TxPool().Pending(false) @@ -1008,18 +1022,23 @@ func (w *worker) fillTransactions(interruptCh chan int32, env *environment) { defer stopTimer.Stop() } + err = nil if len(localTxs) > 0 { txs := types.NewTransactionsByPriceAndNonce(env.signer, localTxs, env.header.BaseFee) - if w.commitTransactions(env, txs, interruptCh, stopTimer) { + err = w.commitTransactions(env, txs, interruptCh, stopTimer) + if err == errBlockInterruptedByNewHead || err == errBlockInterruptedByOutOfGas || err == errBlockInterruptedByTimeout { return } } if len(remoteTxs) > 0 { txs := types.NewTransactionsByPriceAndNonce(env.signer, remoteTxs, env.header.BaseFee) - if w.commitTransactions(env, txs, interruptCh, stopTimer) { + err = w.commitTransactions(env, txs, interruptCh, stopTimer) + if err == errBlockInterruptedByNewHead || err == errBlockInterruptedByOutOfGas || err == errBlockInterruptedByTimeout { return } } + + return } // generateWork generates a sealing block based on the given parameters. @@ -1049,24 +1068,106 @@ func (w *worker) commitWork(interruptCh chan int32, timestamp int64) { } coinbase = w.coinbase // Use the preset address as the fee recipient } - work, err := w.prepareWork(&generateParams{ - timestamp: uint64(timestamp), - coinbase: coinbase, - }) - if err != nil { - return - } + var stopTimer *time.Timer + // validator can try several times to get the most profitable block, + // as long as the timestamp is not reached. + workList := make([]*environment, 0, 10) + var bestWork *environment + // workList clean up + defer func() { + for _, w := range workList { + // only keep the best work, discard others. + if w == bestWork { + continue + } + w.discard() + } + }() +LOOP: + for { + work, err := w.prepareWork(&generateParams{ + timestamp: uint64(timestamp), + coinbase: coinbase, + }) + if err != nil { + return + } + log.Info("commitWork for", "block", work.header.Number, "timestamp", time.Unix(int64(timestamp), 0).Second()) + workList = append(workList, work) + + if stopTimer == nil { + delay := w.engine.Delay(w.chain, work.header, &w.config.DelayLeftOver) + if delay != nil { + left := *delay - w.config.DelayLeftOver + if left <= 0 { + log.Info("Not enough time for commitWork", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) + break + } + log.Info("commitWork stopTimer", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) + stopTimer = time.NewTimer(left) + defer stopTimer.Stop() + } + } + // subscribe before fillTransactions + txsCh := make(chan core.NewTxsEvent, txChanSize) + sub := w.eth.TxPool().SubscribeNewTxsEvent(txsCh) + defer sub.Unsubscribe() + // Fill pending transactions from the txpool + err = w.fillTransactions(interruptCh, work) + switch { + case errors.Is(err, errBlockInterruptedByNewHead): + // For Parlia, it will drop the work on receiving new block if it is not inturn. + if w.engine.DropOnNewBlock(work.header) { + log.Info("drop the block, when new block is imported") + return + } + case errors.Is(err, errBlockInterruptedByTimeout): + // break the loop to get the best work + log.Info("commitWork timeout") + break LOOP + case errors.Is(err, errBlockInterruptedByOutOfGas): + log.Info("commitWork out of gas") + break LOOP + } - // Fill pending transactions from the txpool - w.fillTransactions(interruptCh, work) - w.commit(work, w.fullTaskHook, true, start) + if interruptCh == nil { + log.Info("commitWork interruptChan is nil") + break + } + done := false + select { + case <-stopTimer.C: + // log.Info("commitWork stopTimer expired") + done = true + case <-txsCh: + // log.Info("commitWork txsCh arrived") + case <-interruptCh: + log.Info("commitWork interruptChan closed, new block imported or resubmit triggered") + return + } + if done { + break + } + } + // get the most profitable work + bestWork = workList[0] + bestReward := new(big.Int) + for i, w := range workList { + balance := w.state.GetBalance(consensus.SystemAddress) + log.Debug("Get the best work", "index", i, "balance", balance, "bestReward", bestReward) + if balance.Cmp(bestReward) > 0 { + bestWork = w + bestReward = balance + } + } + w.commit(bestWork, w.fullTaskHook, true, start) // Swap out the old work with the new one, terminating any leftover // prefetcher processes in the mean time and starting a new one. if w.current != nil { w.current.discard() } - w.current = work + w.current = bestWork } // commit runs any post-transaction state modifications, assembles the final block @@ -1167,3 +1268,22 @@ func (w *worker) postSideBlock(event core.ChainSideEvent) { case <-w.exitCh: } } + +// signalToErr converts the interruption signal to a concrete error type for return. +// The given signal must be a valid interruption signal. +func signalToErr(signal int32) error { + switch signal { + case commitInterruptNone: + return nil + case commitInterruptNewHead: + return errBlockInterruptedByNewHead + case commitInterruptResubmit: + return errBlockInterruptedByRecommit + case commitInterruptTimeout: + return errBlockInterruptedByTimeout + case commitInterruptOutOfGas: + return errBlockInterruptedByOutOfGas + default: + panic(fmt.Errorf("undefined signal %d", signal)) + } +} From e1719b7a8d32ff6c4d94546eb766ccf48b73c30a Mon Sep 17 00:00:00 2001 From: setunapo Date: Tue, 15 Nov 2022 13:47:54 +0800 Subject: [PATCH 3/4] fair: add left time check before fillTransactions. --- consensus/parlia/parlia.go | 4 +- miner/worker.go | 78 ++++++++++++++++++++------------------ 2 files changed, 42 insertions(+), 40 deletions(-) diff --git a/consensus/parlia/parlia.go b/consensus/parlia/parlia.go index 89343a8c8f..c16b36ac12 100644 --- a/consensus/parlia/parlia.go +++ b/consensus/parlia/parlia.go @@ -864,9 +864,7 @@ func (p *Parlia) Seal(chain consensus.ChainHeaderReader, block *types.Block, res // Sweet, the protocol permits us to sign the block, wait for our time delay := p.delayForRamanujanFork(snap, header) - log.Info("Sealing block with", "number", number, "delay", delay, - "header.Time Second", time.Unix(int64(header.Time), 0).Second(), - "headerDifficulty", header.Difficulty, "val", val.Hex()) + log.Info("Sealing block with", "number", number, "delay", delay, "headerDifficulty", header.Difficulty, "val", val.Hex()) // Sign all the things! sig, err := signFn(accounts.Account{Address: val}, accounts.MimetypeParlia, ParliaRLP(header, p.chainConfig.ChainID)) diff --git a/miner/worker.go b/miner/worker.go index de314a43f8..0595395329 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -383,6 +383,7 @@ func (w *worker) newWorkLoop(recommit time.Duration) { close(interruptCh) } interruptCh = make(chan int32, 1) + log.Info("newWorkLoop commit", "reason", reason) select { case w.newWorkCh <- &newWorkReq{interruptCh: interruptCh, timestamp: timestamp}: case <-w.exitCh: @@ -407,6 +408,7 @@ func (w *worker) newWorkLoop(recommit time.Duration) { case <-w.startCh: clearPending(w.chain.CurrentBlock().NumberU64()) timestamp = time.Now().Unix() + log.Info("newWorkLoop commit on start") commit(commitInterruptNewHead) case head := <-w.chainHeadCh: @@ -777,7 +779,7 @@ func (w *worker) commitTransactions(env *environment, txs *types.TransactionsByP } var coalescedLogs []*types.Log - // initilise bloom processors + // initialize bloom processors processorCapacity := 100 if txs.CurrentSize() < processorCapacity { processorCapacity = txs.CurrentSize() @@ -1002,7 +1004,7 @@ func (w *worker) prepareWork(genParams *generateParams) (*environment, error) { // fillTransactions retrieves the pending transactions from the txpool and fills them // into the given sealing block. The transaction selection and ordering strategy can // be customized with the plugin in the future. -func (w *worker) fillTransactions(interruptCh chan int32, env *environment) (err error) { +func (w *worker) fillTransactions(interruptCh chan int32, env *environment, stopTimer *time.Timer) (err error) { // Split the pending transactions into locals and remotes // Fill the block with all available pending transactions. pending := w.eth.TxPool().Pending(false) @@ -1014,14 +1016,6 @@ func (w *worker) fillTransactions(interruptCh chan int32, env *environment) (err } } - var stopTimer *time.Timer - delay := w.engine.Delay(w.chain, env.header, &w.config.DelayLeftOver) - if delay != nil { - stopTimer = time.NewTimer(*delay) - log.Debug("Time left for mining work", "delay", delay.String()) - defer stopTimer.Stop() - } - err = nil if len(localTxs) > 0 { txs := types.NewTransactionsByPriceAndNonce(env.signer, localTxs, env.header.BaseFee) @@ -1049,7 +1043,7 @@ func (w *worker) generateWork(params *generateParams) (*types.Block, error) { } defer work.discard() - w.fillTransactions(nil, work) + w.fillTransactions(nil, work, nil) block, _, err := w.engine.FinalizeAndAssemble(w.chain, work.header, work.state, work.txs, work.unclelist(), work.receipts) return block, err } @@ -1068,7 +1062,11 @@ func (w *worker) commitWork(interruptCh chan int32, timestamp int64) { } coinbase = w.coinbase // Use the preset address as the fee recipient } - var stopTimer *time.Timer + + stopTimer := time.NewTimer(0) + defer stopTimer.Stop() + <-stopTimer.C // discard the initial tick + // validator can try several times to get the most profitable block, // as long as the timestamp is not reached. workList := make([]*environment, 0, 10) @@ -1092,28 +1090,31 @@ LOOP: if err != nil { return } - log.Info("commitWork for", "block", work.header.Number, "timestamp", time.Unix(int64(timestamp), 0).Second()) + + log.Info("commitWork for", "block", work.header.Number, + "until header time", time.Until(time.Unix(int64(work.header.Time), 0))) workList = append(workList, work) - if stopTimer == nil { - delay := w.engine.Delay(w.chain, work.header, &w.config.DelayLeftOver) - if delay != nil { - left := *delay - w.config.DelayLeftOver - if left <= 0 { - log.Info("Not enough time for commitWork", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) - break - } - log.Info("commitWork stopTimer", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) - stopTimer = time.NewTimer(left) - defer stopTimer.Stop() - } + delay := w.engine.Delay(w.chain, work.header, &w.config.DelayLeftOver) + if delay == nil { + log.Warn("commitWork delay is nil, something is wrong") + stopTimer = nil + } else if *delay <= 0 { + log.Info("Not enough time for commitWork") + break + } else { + log.Info("commitWork stopTimer", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) + stopTimer.Reset(*delay) } + // subscribe before fillTransactions txsCh := make(chan core.NewTxsEvent, txChanSize) sub := w.eth.TxPool().SubscribeNewTxsEvent(txsCh) defer sub.Unsubscribe() // Fill pending transactions from the txpool - err = w.fillTransactions(interruptCh, work) + startT := time.Now() + err = w.fillTransactions(interruptCh, work, stopTimer) + fillDuration := time.Since(startT) switch { case errors.Is(err, errBlockInterruptedByNewHead): // For Parlia, it will drop the work on receiving new block if it is not inturn. @@ -1130,31 +1131,34 @@ LOOP: break LOOP } - if interruptCh == nil { - log.Info("commitWork interruptChan is nil") + if interruptCh == nil || stopTimer == nil { + // it is single commit work, no need to try several time. + log.Info("commitWork interruptCh or stopTimer is nil") break } - done := false + select { - case <-stopTimer.C: - // log.Info("commitWork stopTimer expired") - done = true case <-txsCh: - // log.Info("commitWork txsCh arrived") + delay := w.engine.Delay(w.chain, work.header, &w.config.DelayLeftOver) + log.Info("commitWork txsCh arrived", "fillDuration", fillDuration.String(), "delay", delay.String()) + if fillDuration > *delay { + // there may not have enough time for another fillTransactions + break LOOP + } + case <-stopTimer.C: + log.Info("commitWork stopTimer expired") + break LOOP case <-interruptCh: log.Info("commitWork interruptChan closed, new block imported or resubmit triggered") return } - if done { - break - } } // get the most profitable work bestWork = workList[0] bestReward := new(big.Int) for i, w := range workList { balance := w.state.GetBalance(consensus.SystemAddress) - log.Debug("Get the best work", "index", i, "balance", balance, "bestReward", bestReward) + log.Debug("Get the most profitable work", "index", i, "balance", balance, "bestReward", bestReward) if balance.Cmp(bestReward) > 0 { bestWork = w bestReward = balance From 4c8fc5a0df8deb36b14e1d0cdc95799a2af6a573 Mon Sep 17 00:00:00 2001 From: setunapo Date: Wed, 16 Nov 2022 23:35:58 +0800 Subject: [PATCH 4/4] fair: less debug log --- miner/worker.go | 27 ++++++++++++--------------- 1 file changed, 12 insertions(+), 15 deletions(-) diff --git a/miner/worker.go b/miner/worker.go index 0595395329..d376ae9ad8 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -383,7 +383,7 @@ func (w *worker) newWorkLoop(recommit time.Duration) { close(interruptCh) } interruptCh = make(chan int32, 1) - log.Info("newWorkLoop commit", "reason", reason) + log.Debug("newWorkLoop commit", "reason", reason) select { case w.newWorkCh <- &newWorkReq{interruptCh: interruptCh, timestamp: timestamp}: case <-w.exitCh: @@ -408,11 +408,9 @@ func (w *worker) newWorkLoop(recommit time.Duration) { case <-w.startCh: clearPending(w.chain.CurrentBlock().NumberU64()) timestamp = time.Now().Unix() - log.Info("newWorkLoop commit on start") commit(commitInterruptNewHead) case head := <-w.chainHeadCh: - log.Info("newWorkLoop chainHeadCh", "block number", head.Block.NumberU64()) if !w.isRunning() { continue } @@ -483,7 +481,6 @@ func (w *worker) mainLoop() { for { select { case req := <-w.newWorkCh: - log.Info("mainLoop newWorkCh") w.commitWork(req.interruptCh, req.timestamp) case req := <-w.getWorkCh: @@ -1091,7 +1088,7 @@ LOOP: return } - log.Info("commitWork for", "block", work.header.Number, + log.Debug("commitWork for", "block", work.header.Number, "until header time", time.Until(time.Unix(int64(work.header.Time), 0))) workList = append(workList, work) @@ -1100,10 +1097,10 @@ LOOP: log.Warn("commitWork delay is nil, something is wrong") stopTimer = nil } else if *delay <= 0 { - log.Info("Not enough time for commitWork") + log.Debug("Not enough time for commitWork") break } else { - log.Info("commitWork stopTimer", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) + log.Debug("commitWork stopTimer", "delay", *delay, "DelayLeftOver", w.config.DelayLeftOver) stopTimer.Reset(*delay) } @@ -1112,22 +1109,22 @@ LOOP: sub := w.eth.TxPool().SubscribeNewTxsEvent(txsCh) defer sub.Unsubscribe() // Fill pending transactions from the txpool - startT := time.Now() + fillStart := time.Now() err = w.fillTransactions(interruptCh, work, stopTimer) - fillDuration := time.Since(startT) + fillDuration := time.Since(fillStart) switch { case errors.Is(err, errBlockInterruptedByNewHead): // For Parlia, it will drop the work on receiving new block if it is not inturn. if w.engine.DropOnNewBlock(work.header) { - log.Info("drop the block, when new block is imported") + log.Debug("drop the block, when new block is imported") return } case errors.Is(err, errBlockInterruptedByTimeout): // break the loop to get the best work - log.Info("commitWork timeout") + log.Debug("commitWork timeout") break LOOP case errors.Is(err, errBlockInterruptedByOutOfGas): - log.Info("commitWork out of gas") + log.Debug("commitWork out of gas") break LOOP } @@ -1140,16 +1137,16 @@ LOOP: select { case <-txsCh: delay := w.engine.Delay(w.chain, work.header, &w.config.DelayLeftOver) - log.Info("commitWork txsCh arrived", "fillDuration", fillDuration.String(), "delay", delay.String()) + log.Debug("commitWork txsCh arrived", "fillDuration", fillDuration.String(), "delay", delay.String()) if fillDuration > *delay { // there may not have enough time for another fillTransactions break LOOP } case <-stopTimer.C: - log.Info("commitWork stopTimer expired") + log.Debug("commitWork stopTimer expired") break LOOP case <-interruptCh: - log.Info("commitWork interruptChan closed, new block imported or resubmit triggered") + log.Debug("commitWork interruptCh closed, new block imported or resubmit triggered") return } }