miner: add diagnostic attributes to block building spans

Author: jrhea

miner/miner.go

@@ -157,16 +157,17 @@ func (miner *Miner) getPending() *newPayloadResult {
 	if miner.chainConfig.IsShanghai(new(big.Int).Add(header.Number, big.NewInt(1)), timestamp) {
 		withdrawal = []*types.Withdrawal{}
 	}
-	ret := miner.generateWork(&generateParams{
-		timestamp:   timestamp,
-		forceTime:   false,
-		parentHash:  header.Hash(),
-		coinbase:    miner.config.PendingFeeRecipient,
-		random:      common.Hash{},
-		withdrawals: withdrawal,
-		beaconRoot:  nil,
-		noTxs:       false,
-	}, false) // we will never make a witness for a pending block
+	ret := miner.generateWork(context.Background(),
+		&generateParams{
+			timestamp:   timestamp,
+			forceTime:   false,
+			parentHash:  header.Hash(),
+			coinbase:    miner.config.PendingFeeRecipient,
+			random:      common.Hash{},
+			withdrawals: withdrawal,
+			beaconRoot:  nil,
+			noTxs:       false,
+		}, false) // we will never make a witness for a pending block
 	if ret.err != nil {
 		return nil
 	}

miner/payload_building.go

@@ -99,14 +99,15 @@ func newPayload(empty *types.Block, emptyRequests [][]byte, witness *stateless.W
 	return payload
 }
 
-// update updates the full-block with latest built version.
-func (payload *Payload) update(r *newPayloadResult, elapsed time.Duration) {
+// update updates the full-block with latest built version. It returns true if
+// the update was accepted (i.e. the new block has higher fees than the previous).
+func (payload *Payload) update(r *newPayloadResult, elapsed time.Duration) bool {
 	payload.lock.Lock()
 	defer payload.lock.Unlock()
 
 	select {
 	case <-payload.stop:
-		return // reject stale update
+		return false // reject stale update
 	default:
 	}
 	// Ensure the newly provided full block has a higher transaction fee.
@@ -131,8 +132,10 @@ func (payload *Payload) update(r *newPayloadResult, elapsed time.Duration) {
 			"root", r.block.Root(),
 			"elapsed", common.PrettyDuration(elapsed),
 		)
+		payload.cond.Broadcast() // fire signal for notifying full block
+		return true
 	}
-	payload.cond.Broadcast() // fire signal for notifying full block
+	return false
 }
 
 // Resolve returns the latest built payload and also terminates the background
@@ -209,7 +212,12 @@ func (payload *Payload) ResolveFull() *engine.ExecutionPayloadEnvelope {
 
 // buildPayload builds the payload according to the provided parameters.
 func (miner *Miner) buildPayload(ctx context.Context, args *BuildPayloadArgs, witness bool) (result *Payload, err error) {
-	ctx, _, spanEnd := telemetry.StartSpan(ctx, "miner.buildPayload")
+	payloadID := args.Id()
+	ctx, _, spanEnd := telemetry.StartSpan(ctx, "miner.buildPayload",
+		telemetry.StringAttribute("payload.id", payloadID.String()),
+		telemetry.StringAttribute("parent.hash", args.Parent.String()),
+		telemetry.Int64Attribute("timestamp", int64(args.Timestamp)),
+	)
 	defer spanEnd(err)
 
 	// Build the initial version with no transaction included. It should be fast
@@ -225,18 +233,25 @@ func (miner *Miner) buildPayload(ctx context.Context, args *BuildPayloadArgs, wi
 		beaconRoot:  args.BeaconRoot,
 		noTxs:       true,
 	}
-	empty := miner.generateWork(emptyParams, witness)
+	empty := miner.generateWork(ctx, emptyParams, witness)
 	if empty.err != nil {
 		return nil, empty.err
 	}
 	// Construct a payload object for return.
-	payload := newPayload(empty.block, empty.requests, empty.witness, args.Id())
+	payload := newPayload(empty.block, empty.requests, empty.witness, payloadID)
 
 	// Spin up a routine for updating the payload in background. This strategy
 	// can maximum the revenue for including transactions with highest fee.
 	go func() {
-		bCtx, bSpan, bSpanEnd := telemetry.StartSpan(ctx, "miner.background")
-		defer bSpanEnd(nil)
+		var iteration int
+
+		bCtx, bSpan, bSpanEnd := telemetry.StartSpan(ctx, "miner.background",
+			telemetry.StringAttribute("payload.id", payloadID.String()),
+		)
+		defer func() {
+			bSpan.SetAttributes(telemetry.Int64Attribute("iterations.total", int64(iteration)))
+			bSpanEnd(nil)
+		}()
 
 		// Setup the timer for re-building the payload. The initial clock is kept
 		// for triggering process immediately.
@@ -258,23 +273,31 @@ func (miner *Miner) buildPayload(ctx context.Context, args *BuildPayloadArgs, wi
 			beaconRoot:  args.BeaconRoot,
 			noTxs:       false,
 		}
-
 		for {
 			select {
 			case <-timer.C:
-				_, _, iterSpanEnd := telemetry.StartSpan(bCtx, "miner.generateWork")
+				iteration++
+				iterCtx, iterSpan, iterSpanEnd := telemetry.StartSpan(bCtx, "miner.buildIteration",
+					telemetry.Int64Attribute("iteration", int64(iteration)),
+				)
 				start := time.Now()
-
-				r := miner.generateWork(fullParams, witness)
+				r := miner.generateWork(iterCtx, fullParams, witness)
 				if r.err == nil {
-					payload.update(r, time.Since(start))
+					accepted := payload.update(r, time.Since(start))
+					iterSpan.SetAttributes(telemetry.BoolAttribute("update.accepted", accepted))
 				} else {
 					log.Info("Error while generating work", "id", payload.id, "err", r.err)
 				}
-				timer.Reset(miner.config.Recommit)
 				iterSpanEnd(r.err)
+				timer.Reset(miner.config.Recommit)
 			case <-payload.stop:
-				bSpan.SetAttributes(telemetry.StringAttribute("exit.reason", "delivery"))
+				payload.lock.Lock()
+				emptyDelivered := payload.full == nil
+				payload.lock.Unlock()
+				bSpan.SetAttributes(
+					telemetry.StringAttribute("exit.reason", "delivery"),
+					telemetry.BoolAttribute("empty.delivered", emptyDelivered),
+				)
 				log.Info("Stopping work on payload", "id", payload.id, "reason", "delivery")
 				return
 			case <-endTimer.C:

miner/worker.go

@@ -17,6 +17,7 @@
 package miner
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"math/big"
@@ -32,6 +33,7 @@ import (
 	"github.com/ethereum/go-ethereum/core/txpool"
 	"github.com/ethereum/go-ethereum/core/types"
 	"github.com/ethereum/go-ethereum/core/vm"
+	"github.com/ethereum/go-ethereum/internal/telemetry"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/params"
 	"github.com/holiman/uint256"
@@ -115,7 +117,22 @@ type generateParams struct {
 }
 
 // generateWork generates a sealing block based on the given parameters.
-func (miner *Miner) generateWork(genParam *generateParams, witness bool) *newPayloadResult {
+func (miner *Miner) generateWork(ctx context.Context, genParam *generateParams, witness bool) (result *newPayloadResult) {
+	_, span, spanEnd := telemetry.StartSpan(ctx, "miner.generateWork")
+	defer func() {
+		if result != nil && result.err == nil {
+			span.SetAttributes(
+				telemetry.Int64Attribute("txs.count", int64(len(result.block.Transactions()))),
+				telemetry.Int64Attribute("gas.used", int64(result.block.GasUsed())),
+				telemetry.StringAttribute("fees", result.fees.String()),
+			)
+		}
+		if result != nil {
+			spanEnd(result.err)
+		} else {
+			spanEnd(nil)
+		}
+	}()
 	work, err := miner.prepareWork(genParam, witness)
 	if err != nil {
 		return &newPayloadResult{err: err}