diff --git a/app/elapse_info.go b/app/elapse_info.go index efb581a7ae..9df6e713dd 100644 --- a/app/elapse_info.go +++ b/app/elapse_info.go @@ -46,7 +46,7 @@ var ( trace.Tx, trace.SimTx, trace.BlockSize, - trace.TimeoutInterval, + trace.BTInterval, trace.LastBlockTime, trace.GasUsed, trace.SimGasUsed, diff --git a/libs/system/trace/schema.go b/libs/system/trace/schema.go index 9c3054abcd..9546a1773a 100644 --- a/libs/system/trace/schema.go +++ b/libs/system/trace/schema.go @@ -64,10 +64,10 @@ const ( Persist = "persist" //MempoolUpdate = "mpUpdate" //SaveState = "saveState" - ApplyBlock = "ApplyBlock" - Consensus = "Consensus" - LastBlockTime = "LastBlockTime" - TimeoutInterval = "TimeoutInterval" + ApplyBlock = "ApplyBlock" + Consensus = "Consensus" + LastBlockTime = "LastBlockTime" + BTInterval = "BTInterval" MempoolCheckTxCnt = "CheckTx" MempoolTxsCnt = "MempoolTxs" diff --git a/libs/tendermint/consensus/consensus.go b/libs/tendermint/consensus/consensus.go index d1e0eb43be..501124ebb4 100644 --- a/libs/tendermint/consensus/consensus.go +++ b/libs/tendermint/consensus/consensus.go @@ -154,9 +154,8 @@ type State struct { // for reporting metrics metrics *Metrics - trc *trace.Tracer - blockTimeTrc *trace.Tracer - timeoutIntervalTrc *trace.Tracer + trc *trace.Tracer + blockTimeTrc *trace.Tracer prerunTx bool bt *BlockTransport @@ -188,28 +187,27 @@ func NewState( options ...StateOption, ) *State { cs := &State{ - config: config, - blockExec: blockExec, - blockStore: blockStore, - txNotifier: txNotifier, - peerMsgQueue: make(chan msgInfo, msgQueueSize), - internalMsgQueue: make(chan msgInfo, msgQueueSize), - timeoutTicker: NewTimeoutTicker(), - statsMsgQueue: make(chan msgInfo, msgQueueSize), - done: make(chan struct{}), - doWALCatchup: true, - wal: nilWAL{}, - evpool: evpool, - evsw: tmevents.NewEventSwitch(), - metrics: NopMetrics(), - trc: trace.NewTracer(trace.Consensus), - prerunTx: viper.GetBool(EnablePrerunTx), - bt: &BlockTransport{}, - blockTimeTrc: trace.NewTracer(trace.LastBlockTime), - timeoutIntervalTrc: trace.NewTracer(trace.TimeoutInterval), - vcHeight: make(map[int64]string), - taskResultChan: make(chan *preBlockTaskRes, 1), - preBlockTaskChan: make(chan *preBlockTask, 100), + config: config, + blockExec: blockExec, + blockStore: blockStore, + txNotifier: txNotifier, + peerMsgQueue: make(chan msgInfo, msgQueueSize), + internalMsgQueue: make(chan msgInfo, msgQueueSize), + timeoutTicker: NewTimeoutTicker(), + statsMsgQueue: make(chan msgInfo, msgQueueSize), + done: make(chan struct{}), + doWALCatchup: true, + wal: nilWAL{}, + evpool: evpool, + evsw: tmevents.NewEventSwitch(), + metrics: NopMetrics(), + trc: trace.NewTracer(trace.Consensus), + prerunTx: viper.GetBool(EnablePrerunTx), + bt: &BlockTransport{}, + blockTimeTrc: trace.NewTracer(trace.LastBlockTime), + vcHeight: make(map[int64]string), + taskResultChan: make(chan *preBlockTaskRes, 1), + preBlockTaskChan: make(chan *preBlockTask, 100), } // set function defaults (may be overwritten before calling Start) cs.decideProposal = cs.defaultDecideProposal diff --git a/libs/tendermint/consensus/consensus_commit.go b/libs/tendermint/consensus/consensus_commit.go index 206398c53f..55083ce689 100644 --- a/libs/tendermint/consensus/consensus_commit.go +++ b/libs/tendermint/consensus/consensus_commit.go @@ -24,6 +24,7 @@ func (cs *State) initNewHeight() { // init StartTime cs.StartTime = tmtime.Now() cs.dumpElapsed(cs.blockTimeTrc, trace.LastBlockTime) + cs.traceDump() } } @@ -186,16 +187,19 @@ func (cs *State) finalizeCommit(height int64) { fail.Fail() // XXX // Save to blockStore. + blockTime := block.Time if cs.blockStore.Height() < block.Height { // NOTE: the seenCommit is local justification to commit this block, // but may differ from the LastCommit included in the next block precommits := cs.Votes.Precommits(cs.CommitRound) seenCommit := precommits.MakeCommit() + blockTime = sm.MedianTime(seenCommit, cs.Validators) cs.blockStore.SaveBlock(block, blockParts, seenCommit) } else { // Happens during replay if we already saved the block but didn't commit cs.Logger.Info("Calling finalizeCommit on already stored block", "height", block.Height) } + trace.GetElapsedInfo().AddInfo(trace.BTInterval, fmt.Sprintf("%dms", blockTime.Sub(block.Time).Milliseconds())) fail.Fail() // XXX @@ -354,7 +358,6 @@ func (cs *State) updateToState(state sm.State) { // RoundState fields cs.updateHeight(height) cs.updateRoundStep(0, cstypes.RoundStepNewHeight) - cs.traceDump() cs.bt.reset(height) cs.Validators = validators diff --git a/libs/tendermint/consensus/consensus_main_routine.go b/libs/tendermint/consensus/consensus_main_routine.go index 7f2384abb3..79619ef46e 100644 --- a/libs/tendermint/consensus/consensus_main_routine.go +++ b/libs/tendermint/consensus/consensus_main_routine.go @@ -3,7 +3,6 @@ package consensus import ( "bytes" "fmt" - "github.com/okex/exchain/libs/system/trace" cfg "github.com/okex/exchain/libs/tendermint/config" cstypes "github.com/okex/exchain/libs/tendermint/consensus/types" "github.com/okex/exchain/libs/tendermint/libs/fail" @@ -249,10 +248,6 @@ func (cs *State) handleMsg(mi msgInfo) (added bool) { func (cs *State) handleTimeout(ti timeoutInfo, rs cstypes.RoundState) { cs.Logger.Debug("Received tock", "timeout", ti.Duration, "height", ti.Height, "round", ti.Round, "step", ti.Step) - if ti.Step == cstypes.RoundStepNewHeight { - cs.dumpElapsed(cs.timeoutIntervalTrc, trace.TimeoutInterval) - } - // timeouts must be for current height, round, step if ti.Height != rs.Height || ti.Round < rs.Round || (ti.Round == rs.Round && ti.Step < rs.Step) { cs.Logger.Debug("Ignoring tock because we're ahead", "height", rs.Height, "round", rs.Round, "step", rs.Step)