Skip to content

core: more detailed metrics for block processing #18119

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Nov 28, 2018
Merged

core: more detailed metrics for block processing #18119

Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
13 changes: 12 additions & 1 deletion core/blockchain.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -47,7 +47,10 @@ import (
)

var (
blockInsertTimer = metrics.NewRegisteredTimer("chain/inserts", nil)
blockInsertTimer = metrics.NewRegisteredTimer("chain/inserts", nil)
blockValidationTimer = metrics.NewRegisteredTimer("chain/validation", nil)
blockExecutionTimer = metrics.NewRegisteredTimer("chain/execution", nil)
blockWriteTimer = metrics.NewRegisteredTimer("chain/write", nil)

ErrNoGenesis = errors.New("Genesis not found in chain")
)
Expand Down Expand Up @@ -1188,7 +1191,9 @@ func (bc *BlockChain) insertChain(chain types.Blocks, verifySeals bool) (int, []
return it.index, events, coalescedLogs, err
}
// Process block using the parent state as reference point.
t0 := time.Now()
receipts, logs, usedGas, err := bc.processor.Process(block, state, bc.vmConfig)
t1 := time.Now()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of measuring and updating, perhaps it would be cleaner to update on the fly?

		start := time.Now()
		receipts, logs, usedGas, err := bc.processor.Process(block, state, bc.vmConfig)
		blockExecutionTimer.Update(time.Since(start))

if err != nil {
bc.reportBlock(block, receipts, err)
return it.index, events, coalescedLogs, err
Expand All @@ -1198,13 +1203,19 @@ func (bc *BlockChain) insertChain(chain types.Blocks, verifySeals bool) (int, []
bc.reportBlock(block, receipts, err)
return it.index, events, coalescedLogs, err
}
t2 := time.Now()
proctime := time.Since(start)

// Write the block to the chain and get the status.
status, err := bc.WriteBlockWithState(block, receipts, state)
t3 := time.Now()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of measuring and updating, perhaps it would be cleaner to update on the fly?

		start = time.Now()
		status, err := bc.WriteBlockWithState(block, receipts, state)
		blockWriteTimer.Update(time.Since(start))

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I kind of disagree. The three variables will always cover the entire time spent, the next one continuing from where the last one left off. Your methods leaves gaps, and we're not certain that we don't miss something

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The only thing it doesn't cover is the timer updates. But my solution does cover bad blocks and failures too, whereas yours only counts successful blocks.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe its just the t0, t1, etc that bother me. Perhaps if they had more meaningful names it would be fine. This feels like some left in debug code., not production.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, ok. You want to measure N identifiable and specific things, whereas my approach "we have this chunk of code and want to divvy it up in N places". So for me t0, t1.. makes sense, but I can see why you dislike it....

if err != nil {
return it.index, events, coalescedLogs, err
}
blockInsertTimer.UpdateSince(start)
blockExecutionTimer.Update(t1.Sub(t0))
blockValidationTimer.Update(t2.Sub(t1))
blockWriteTimer.Update(t3.Sub(t2))
switch status {
case CanonStatTy:
log.Debug("Inserted new block", "number", block.Number(), "hash", block.Hash(),
Expand Down