From 82bf625e677e9cf58320b298f27df2de36915395 Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 13:27:50 +0530 Subject: [PATCH 1/8] core, miner: add sub-spans for tracing --- core/blockchain.go | 75 ++++++++++++++++++++++++++++++++++++---------- miner/worker.go | 4 +-- 2 files changed, 62 insertions(+), 17 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index cbcf02fef4..5214b46196 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -18,6 +18,7 @@ package core import ( + "context" "errors" "fmt" "io" @@ -28,11 +29,14 @@ import ( "time" lru "github.com/hashicorp/golang-lru" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/trace" "github.com/ethereum/go-ethereum" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common/mclock" "github.com/ethereum/go-ethereum/common/prque" + "github.com/ethereum/go-ethereum/common/tracing" "github.com/ethereum/go-ethereum/consensus" "github.com/ethereum/go-ethereum/core/rawdb" "github.com/ethereum/go-ethereum/core/state" @@ -1349,43 +1353,84 @@ func (bc *BlockChain) writeBlockWithState(block *types.Block, receipts []*types. } // WriteBlockWithState writes the block and all associated state to the database. -func (bc *BlockChain) WriteBlockAndSetHead(block *types.Block, receipts []*types.Receipt, logs []*types.Log, state *state.StateDB, emitHeadEvent bool) (status WriteStatus, err error) { +func (bc *BlockChain) WriteBlockAndSetHead(ctx context.Context, block *types.Block, receipts []*types.Receipt, logs []*types.Log, state *state.StateDB, emitHeadEvent bool) (status WriteStatus, err error) { if !bc.chainmu.TryLock() { return NonStatTy, errChainStopped } defer bc.chainmu.Unlock() - return bc.writeBlockAndSetHead(block, receipts, logs, state, emitHeadEvent) + return bc.writeBlockAndSetHead(ctx, block, receipts, logs, state, emitHeadEvent) } // writeBlockAndSetHead writes the block and all associated state to the database, // and also it applies the given block as the new chain head. This function expects // the chain mutex to be held. -func (bc *BlockChain) writeBlockAndSetHead(block *types.Block, receipts []*types.Receipt, logs []*types.Log, state *state.StateDB, emitHeadEvent bool) (status WriteStatus, err error) { +func (bc *BlockChain) writeBlockAndSetHead(ctx context.Context, block *types.Block, receipts []*types.Receipt, logs []*types.Log, state *state.StateDB, emitHeadEvent bool) (status WriteStatus, err error) { var stateSyncLogs []*types.Log - if stateSyncLogs, err = bc.writeBlockWithState(block, receipts, logs, state); err != nil { + + tracing.Exec(ctx, "blockchain.writeBlockWithState", func(_ context.Context, span trace.Span) { + stateSyncLogs, err = bc.writeBlockWithState(block, receipts, logs, state) + tracing.SetAttributes( + span, + attribute.Int("number", int(block.Number().Uint64())), + attribute.Bool("error", err != nil), + ) + }) + if err != nil { return NonStatTy, err } + currentBlock := bc.CurrentBlock() - reorg, err := bc.forker.ReorgNeeded(currentBlock.Header(), block.Header()) + + var reorg bool + tracing.Exec(ctx, "blockchain.ReorgNeeded", func(_ context.Context, span trace.Span) { + reorg, err = bc.forker.ReorgNeeded(currentBlock.Header(), block.Header()) + tracing.SetAttributes( + span, + attribute.Int("number", int(block.Number().Uint64())), + attribute.Int("current block", int(currentBlock.Number().Uint64())), + attribute.Bool("reorg needed", reorg), + attribute.Bool("error", err != nil), + ) + }) if err != nil { return NonStatTy, err } - if reorg { - // Reorganise the chain if the parent is not the head block - if block.ParentHash() != currentBlock.Hash() { - if err := bc.reorg(currentBlock, block); err != nil { - return NonStatTy, err + + tracing.Exec(ctx, "blockchain.reorg", func(_ context.Context, span trace.Span) { + if reorg { + // Reorganise the chain if the parent is not the head block + if block.ParentHash() != currentBlock.Hash() { + if err = bc.reorg(currentBlock, block); err != nil { + status = NonStatTy + } } + status = CanonStatTy + } else { + status = SideStatTy } - status = CanonStatTy - } else { - status = SideStatTy + + tracing.SetAttributes( + span, + attribute.Int("number", int(block.Number().Uint64())), + attribute.Int("current block", int(currentBlock.Number().Uint64())), + attribute.Bool("reorg needed", reorg), + attribute.Bool("error", err != nil), + attribute.String("status", string(status)), + ) + }) + + if status == NonStatTy { + return } + // Set new head. if status == CanonStatTy { - bc.writeHeadBlock(block) + tracing.Exec(ctx, "blockchain.writeHeadBlock", func(_ context.Context, _ trace.Span) { + bc.writeHeadBlock(block) + }) } + bc.futureBlocks.Remove(block.Hash()) if status == CanonStatTy { @@ -1782,7 +1827,7 @@ func (bc *BlockChain) insertChain(chain types.Blocks, verifySeals, setHead bool) // Don't set the head, only insert the block _, err = bc.writeBlockWithState(block, receipts, logs, statedb) } else { - status, err = bc.writeBlockAndSetHead(block, receipts, logs, statedb, false) + status, err = bc.writeBlockAndSetHead(context.Background(), block, receipts, logs, statedb, false) } atomic.StoreUint32(&followupInterrupt, 1) if err != nil { diff --git a/miner/worker.go b/miner/worker.go index 30809cd558..08acc56d55 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -782,8 +782,8 @@ func (w *worker) resultLoop() { } // Commit block and state to database. - tracing.ElapsedTime(ctx, span, "WriteBlockAndSetHead time taken", func(_ context.Context, _ trace.Span) { - _, err = w.chain.WriteBlockAndSetHead(block, receipts, logs, task.state, true) + tracing.Exec(ctx, "resultLoop.WriteBlockAndSetHead", func(ctx context.Context, span trace.Span) { + _, err = w.chain.WriteBlockAndSetHead(ctx, block, receipts, logs, task.state, true) }) tracing.SetAttributes( From 5cf2309a36fcfd51b6a92d7f9e862f91414ec79e Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 14:02:43 +0530 Subject: [PATCH 2/8] fix linters --- core/blockchain.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/core/blockchain.go b/core/blockchain.go index 5214b46196..e1dfcafc12 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -1376,6 +1376,7 @@ func (bc *BlockChain) writeBlockAndSetHead(ctx context.Context, block *types.Blo attribute.Bool("error", err != nil), ) }) + if err != nil { return NonStatTy, err } @@ -1383,6 +1384,7 @@ func (bc *BlockChain) writeBlockAndSetHead(ctx context.Context, block *types.Blo currentBlock := bc.CurrentBlock() var reorg bool + tracing.Exec(ctx, "blockchain.ReorgNeeded", func(_ context.Context, span trace.Span) { reorg, err = bc.forker.ReorgNeeded(currentBlock.Header(), block.Header()) tracing.SetAttributes( From c10763c46c50ca310255440962bd07e9f0f27a7d Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 14:12:30 +0530 Subject: [PATCH 3/8] core: add logs for debugging --- core/blockchain.go | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/core/blockchain.go b/core/blockchain.go index e1dfcafc12..b2429377f0 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -2183,10 +2183,27 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { } // Both sides of the reorg are at the same number, reduce both until the common // ancestor is found + + log.Info("[DEBUG] About to perform reorg", "old block", oldBlock.NumberU64(), "old block hash", oldBlock.Hash(), "new block", newBlock.NumberU64(), "new block hash", newBlock.Hash()) + for { // If the common ancestor was found, bail out if oldBlock.Hash() == newBlock.Hash() { commonBlock = oldBlock + + log.Info("[DEBUG] Found common ancestor in reorg", "number", commonBlock.NumberU64()) + if len(oldChain) > 0 { + log.Info("[DEBUG] Old chain", "start", oldChain[0], "end", oldChain[len(oldChain)-1], "length", len(oldChain)) + } else { + log.Info("[DEBUG] Empty old chain") + } + + if len(newChain) > 0 { + log.Info("[DEBUG] New chain", "start", newChain[0], "end", newChain[len(newChain)-1], "length", len(newChain)) + } else { + log.Info("[DEBUG] Empty new chain") + } + break } // Remove an old block as well as stash away a new block From 464dc7c1c8665c08580a7c49cd9728878aebe9d8 Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 16:07:39 +0530 Subject: [PATCH 4/8] core: add more logs to print tdd while reorg --- core/blockchain.go | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/core/blockchain.go b/core/blockchain.go index b2429377f0..95b5c66992 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -2186,6 +2186,19 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { log.Info("[DEBUG] About to perform reorg", "old block", oldBlock.NumberU64(), "old block hash", oldBlock.Hash(), "new block", newBlock.NumberU64(), "new block hash", newBlock.Hash()) + var ( + tdOld int = -1 + tdNew int = -1 + ) + if td := bc.GetTd(oldBlock.Hash(), oldBlock.NumberU64()); td != nil { + tdOld = int(td.Uint64()) + } + if td := bc.GetTd(newBlock.Hash(), newBlock.NumberU64()); td != nil { + tdNew = int(td.Uint64()) + } + + log.Info("[DEBUG] Total difficulty", "old block", tdOld, "new block", tdNew) + for { // If the common ancestor was found, bail out if oldBlock.Hash() == newBlock.Hash() { From c0f98117214961e5658550a1720cefb9f55a3a49 Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 16:09:09 +0530 Subject: [PATCH 5/8] fix linters --- core/blockchain.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/core/blockchain.go b/core/blockchain.go index 95b5c66992..45ba8b210a 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -2190,9 +2190,11 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { tdOld int = -1 tdNew int = -1 ) + if td := bc.GetTd(oldBlock.Hash(), oldBlock.NumberU64()); td != nil { tdOld = int(td.Uint64()) } + if td := bc.GetTd(newBlock.Hash(), newBlock.NumberU64()); td != nil { tdNew = int(td.Uint64()) } @@ -2205,6 +2207,7 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { commonBlock = oldBlock log.Info("[DEBUG] Found common ancestor in reorg", "number", commonBlock.NumberU64()) + if len(oldChain) > 0 { log.Info("[DEBUG] Old chain", "start", oldChain[0], "end", oldChain[len(oldChain)-1], "length", len(oldChain)) } else { From 888ca4a5e5544746e919ed2bdc1c36871f4a3c55 Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 17:03:43 +0530 Subject: [PATCH 6/8] core: minor fix --- core/blockchain.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index 45ba8b210a..22177b6b14 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -2209,13 +2209,13 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { log.Info("[DEBUG] Found common ancestor in reorg", "number", commonBlock.NumberU64()) if len(oldChain) > 0 { - log.Info("[DEBUG] Old chain", "start", oldChain[0], "end", oldChain[len(oldChain)-1], "length", len(oldChain)) + log.Info("[DEBUG] Old chain", "start", oldChain[0].NumberU64(), "end", oldChain[len(oldChain)-1].NumberU64(), "length", len(oldChain)) } else { log.Info("[DEBUG] Empty old chain") } if len(newChain) > 0 { - log.Info("[DEBUG] New chain", "start", newChain[0], "end", newChain[len(newChain)-1], "length", len(newChain)) + log.Info("[DEBUG] New chain", "start", newChain[0].NumberU64(), "end", newChain[len(newChain)-1].NumberU64(), "length", len(newChain)) } else { log.Info("[DEBUG] Empty new chain") } From ce81ffd8eb27b3ebbd0d889b3260e6c14c63fa84 Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 17:55:39 +0530 Subject: [PATCH 7/8] core: remove debug logs --- core/blockchain.go | 33 --------------------------------- 1 file changed, 33 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index 22177b6b14..e1dfcafc12 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -2183,43 +2183,10 @@ func (bc *BlockChain) reorg(oldBlock, newBlock *types.Block) error { } // Both sides of the reorg are at the same number, reduce both until the common // ancestor is found - - log.Info("[DEBUG] About to perform reorg", "old block", oldBlock.NumberU64(), "old block hash", oldBlock.Hash(), "new block", newBlock.NumberU64(), "new block hash", newBlock.Hash()) - - var ( - tdOld int = -1 - tdNew int = -1 - ) - - if td := bc.GetTd(oldBlock.Hash(), oldBlock.NumberU64()); td != nil { - tdOld = int(td.Uint64()) - } - - if td := bc.GetTd(newBlock.Hash(), newBlock.NumberU64()); td != nil { - tdNew = int(td.Uint64()) - } - - log.Info("[DEBUG] Total difficulty", "old block", tdOld, "new block", tdNew) - for { // If the common ancestor was found, bail out if oldBlock.Hash() == newBlock.Hash() { commonBlock = oldBlock - - log.Info("[DEBUG] Found common ancestor in reorg", "number", commonBlock.NumberU64()) - - if len(oldChain) > 0 { - log.Info("[DEBUG] Old chain", "start", oldChain[0].NumberU64(), "end", oldChain[len(oldChain)-1].NumberU64(), "length", len(oldChain)) - } else { - log.Info("[DEBUG] Empty old chain") - } - - if len(newChain) > 0 { - log.Info("[DEBUG] New chain", "start", newChain[0].NumberU64(), "end", newChain[len(newChain)-1].NumberU64(), "length", len(newChain)) - } else { - log.Info("[DEBUG] Empty new chain") - } - break } // Remove an old block as well as stash away a new block From 884e0f2283c1fa7976bcfea8f2a9bdb160def64c Mon Sep 17 00:00:00 2001 From: Manav Darji Date: Thu, 23 Feb 2023 18:07:15 +0530 Subject: [PATCH 8/8] core: use different span for write block and set head --- core/blockchain.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/core/blockchain.go b/core/blockchain.go index e1dfcafc12..8fb4035f4b 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -1366,9 +1366,12 @@ func (bc *BlockChain) WriteBlockAndSetHead(ctx context.Context, block *types.Blo // and also it applies the given block as the new chain head. This function expects // the chain mutex to be held. func (bc *BlockChain) writeBlockAndSetHead(ctx context.Context, block *types.Block, receipts []*types.Receipt, logs []*types.Log, state *state.StateDB, emitHeadEvent bool) (status WriteStatus, err error) { + writeBlockAndSetHeadCtx, span := tracing.StartSpan(ctx, "blockchain.writeBlockAndSetHead") + defer tracing.EndSpan(span) + var stateSyncLogs []*types.Log - tracing.Exec(ctx, "blockchain.writeBlockWithState", func(_ context.Context, span trace.Span) { + tracing.Exec(writeBlockAndSetHeadCtx, "blockchain.writeBlockWithState", func(_ context.Context, span trace.Span) { stateSyncLogs, err = bc.writeBlockWithState(block, receipts, logs, state) tracing.SetAttributes( span,