Add metrics for builder (#24)

* Add metrics for builder

* add metrics for individual simulations

* Add builder metrics to README (#34)

Author: avalonche

README.md

@@ -92,13 +92,26 @@ $ geth --help
 
     --miner.extradata value       
           Block extra data set by the miner (default = client version)
+   
+   METRICS
+
+   --metrics.builder value          (default: false)
+            Enable builder metrics collection and reporting
 ```
 
 Environment variables:
 ```
 BUILDER_TX_SIGNING_KEY - private key of the builder used to sign payment transaction, must be the same as the coinbase address
 ```
 
+## Metrics
+
+To enable metrics on the builder you will need to enable metrics with the flags `--metrics --metrics.addr 127.0.0.1 --metrics.builder` which will run
+a metrics server serving at `127.0.0.1:6060/debug/metrics`. This will record performance metrics such as block profit and block building times.
+The full list of metrics can be found in `miner/metrics.go`. 
+
+See the [metrics docs](https://geth.ethereum.org/docs/monitoring/metrics) for geth for more documentation.
+
 ## Details of the implementation
 
 There are two parts of the builder.

cmd/geth/chaincmd.go

@@ -79,6 +79,7 @@ The dumpgenesis command dumps the genesis block configuration in JSON format to
 			utils.CacheGCFlag,
 			utils.MetricsEnabledFlag,
 			utils.MetricsEnabledExpensiveFlag,
+			utils.MetricsEnabledBuilderFlag,
 			utils.MetricsHTTPFlag,
 			utils.MetricsPortFlag,
 			utils.MetricsEnableInfluxDBFlag,

cmd/geth/config.go

@@ -252,6 +252,9 @@ func applyMetricConfig(ctx *cli.Context, cfg *gethConfig) {
 	if ctx.IsSet(utils.MetricsEnabledExpensiveFlag.Name) {
 		cfg.Metrics.EnabledExpensive = ctx.Bool(utils.MetricsEnabledExpensiveFlag.Name)
 	}
+	if ctx.IsSet(utils.MetricsEnabledBuilderFlag.Name) {
+		cfg.Metrics.EnabledBuilder = ctx.Bool(utils.MetricsEnabledBuilderFlag.Name)
+	}
 	if ctx.IsSet(utils.MetricsHTTPFlag.Name) {
 		cfg.Metrics.HTTP = ctx.String(utils.MetricsHTTPFlag.Name)
 	}

cmd/geth/main.go

@@ -214,6 +214,7 @@ var (
 	metricsFlags = []cli.Flag{
 		utils.MetricsEnabledFlag,
 		utils.MetricsEnabledExpensiveFlag,
+		utils.MetricsEnabledBuilderFlag,
 		utils.MetricsHTTPFlag,
 		utils.MetricsPortFlag,
 		utils.MetricsEnableInfluxDBFlag,

cmd/utils/flags.go

@@ -1026,6 +1026,12 @@ var (
 		Usage:    "Enable expensive metrics collection and reporting",
 		Category: flags.MetricsCategory,
 	}
+	// Builder metrics flag
+	MetricsEnabledBuilderFlag = &cli.BoolFlag{
+		Name:     "metrics.builder",
+		Usage:    "Enable builder metrics collection and reporting",
+		Category: flags.MetricsCategory,
+	}
 
 	// MetricsHTTPFlag defines the endpoint for a stand-alone metrics HTTP endpoint.
 	// Since the pprof service enables sensitive/vulnerable behavior, this allows a user

core/state/metrics.go

@@ -25,4 +25,7 @@ var (
 	storageDeletedMeter        = metrics.NewRegisteredMeter("state/delete/storage", nil)
 	accountTrieCommittedMeter  = metrics.NewRegisteredMeter("state/commit/accountnodes", nil)
 	storageTriesCommittedMeter = metrics.NewRegisteredMeter("state/commit/storagenodes", nil)
+
+	stateCopyMeter     = metrics.NewRegisteredMeter("state/copy", nil)
+	stateSnapshotMeter = metrics.NewRegisteredMeter("state/snapshot", nil)
 )

core/state/statedb.go

@@ -738,6 +738,11 @@ func (s *StateDB) Copy() *StateDB {
 			state.snapStorage[k] = temp
 		}
 	}
+
+	if metrics.EnabledBuilder {
+		stateCopyMeter.Mark(1)
+	}
+
 	return state
 }
 
@@ -746,6 +751,11 @@ func (s *StateDB) Snapshot() int {
 	id := s.nextRevisionId
 	s.nextRevisionId++
 	s.validRevisions = append(s.validRevisions, revision{id, s.journal.length()})
+
+	if metrics.EnabledBuilder {
+		stateSnapshotMeter.Mark(1)
+	}
+	
 	return id
 }
 

metrics/config.go

@@ -20,6 +20,7 @@ package metrics
 type Config struct {
 	Enabled          bool   `toml:",omitempty"`
 	EnabledExpensive bool   `toml:",omitempty"`
+	EnabledBuilder	 bool   `toml:",omitempty"`
 	HTTP             string `toml:",omitempty"`
 	Port             int    `toml:",omitempty"`
 	EnableInfluxDB   bool   `toml:",omitempty"`
@@ -39,6 +40,7 @@ type Config struct {
 var DefaultConfig = Config{
 	Enabled:          false,
 	EnabledExpensive: false,
+	EnabledBuilder:   false,
 	HTTP:             "127.0.0.1",
 	Port:             6060,
 	EnableInfluxDB:   false,

metrics/metrics.go

@@ -26,12 +26,18 @@ var Enabled = false
 // for health monitoring and debug metrics that might impact runtime performance.
 var EnabledExpensive = false
 
+// EnabledBuilder is a flag meant to collect metrics and performance of the builder
+var EnabledBuilder = false
+
 // enablerFlags is the CLI flag names to use to enable metrics collections.
 var enablerFlags = []string{"metrics"}
 
 // expensiveEnablerFlags is the CLI flag names to use to enable metrics collections.
 var expensiveEnablerFlags = []string{"metrics.expensive"}
 
+// builderEnablerFlags is the CLI flag names to use to enable metrics collections.
+var builderEnablerFlags = []string{"metrics.builder"}
+
 // Init enables or disables the metrics system. Since we need this to run before
 // any other code gets to create meters and timers, we'll actually do an ugly hack
 // and peek into the command line args for the metrics flag.
@@ -51,6 +57,14 @@ func init() {
 				EnabledExpensive = true
 			}
 		}
+
+		for _, enabler := range builderEnablerFlags {
+			if !EnabledBuilder && flag == enabler {
+				log.Info("Enabling builder metrics collection")
+				EnabledBuilder = true
+				break
+			}
+		}
 	}
 }
 

miner/metrics.go

@@ -0,0 +1,26 @@
+package miner
+
+import (
+	"github.com/ethereum/go-ethereum/metrics"
+)
+
+var (
+	blockProfitHistogram   = metrics.NewRegisteredHistogram("miner/block/profit", nil, metrics.NewExpDecaySample(1028, 0.015))
+	bundleTxNumHistogram   = metrics.NewRegisteredHistogram("miner/bundle/txnum", nil, metrics.NewExpDecaySample(1028, 0.015))
+	blockProfitGauge       = metrics.NewRegisteredGauge("miner/block/profit/gauge", nil)
+	culmulativeProfitGauge = metrics.NewRegisteredGauge("miner/block/profit/culmulative", nil)
+
+	buildBlockTimer            = metrics.NewRegisteredTimer("miner/block/build", nil)
+	mergeAlgoTimer             = metrics.NewRegisteredTimer("miner/block/merge", nil)
+	blockBundleSimulationTimer = metrics.NewRegisteredTimer("miner/block/simulate", nil)
+	successfulBundleSimulationTimer	   = metrics.NewRegisteredTimer("miner/bundle/simulate/success", nil)
+	failedBundleSimulationTimer = metrics.NewRegisteredTimer("miner/bundle/simulate/failed", nil)
+	
+
+	simulationMeter          = metrics.NewRegisteredMeter("miner/block/simulation", nil)
+	simulationCommittedMeter = metrics.NewRegisteredMeter("miner/block/simulation/committed", nil)
+	simulationRevertedMeter  = metrics.NewRegisteredMeter("miner/block/simulation/reverted", nil)
+
+	gasUsedGauge        = metrics.NewRegisteredGauge("miner/block/gasused", nil)
+	transactionNumGauge = metrics.NewRegisteredGauge("miner/block/txnum", nil)
+)

miner/worker.go

@@ -37,6 +37,7 @@ import (
 	"github.com/ethereum/go-ethereum/eth/tracers/logger"
 	"github.com/ethereum/go-ethereum/event"
 	"github.com/ethereum/go-ethereum/log"
+	"github.com/ethereum/go-ethereum/metrics"
 	"github.com/ethereum/go-ethereum/params"
 	"github.com/ethereum/go-ethereum/trie"
 )
@@ -1388,7 +1389,11 @@ func (w *worker) fillTransactionsAlgoWorker(interrupt *int32, env *environment)
 	}
 
 	builder := newGreedyBuilder(w.chain, w.chainConfig, w.blockList, env, interrupt)
+	start := time.Now()
 	newEnv, blockBundles := builder.buildBlock(bundlesToConsider, pending)
+	if metrics.EnabledBuilder {
+		mergeAlgoTimer.Update(time.Since(start))
+	}
 	*env = *newEnv
 
 	return nil, blockBundles, bundlesToConsider
@@ -1432,6 +1437,14 @@ func (w *worker) generateWork(params *generateParams) (*types.Block, error) {
 		}
 
 		log.Info("Block finalized and assembled", "blockProfit", ethIntToFloat(block.Profit), "txs", len(env.txs), "bundles", len(blockBundles), "gasUsed", block.GasUsed(), "time", time.Since(start))
+		if metrics.EnabledBuilder {
+			buildBlockTimer.Update(time.Since(start))
+			blockProfitHistogram.Update(block.Profit.Int64())
+			blockProfitGauge.Update(block.Profit.Int64())
+			culmulativeProfitGauge.Inc(block.Profit.Int64())
+			gasUsedGauge.Update(int64(block.GasUsed()))
+			transactionNumGauge.Update(int64(len(env.txs)))
+		}
 		if params.onBlock != nil {
 			go params.onBlock(block, orderCloseTime, blockBundles, allBundles)
 		}
@@ -1722,17 +1735,37 @@ func (w *worker) simulateBundles(env *environment, bundles []types.MevBundle, pe
 		wg.Add(1)
 		go func(idx int, bundle types.MevBundle, state *state.StateDB) {
 			defer wg.Done()
+
+			start := time.Now()
+			if metrics.EnabledBuilder {
+				bundleTxNumHistogram.Update(int64(len(bundle.Txs)))
+			}
+
 			if len(bundle.Txs) == 0 {
 				return
 			}
 			gasPool := new(core.GasPool).AddGas(env.header.GasLimit)
 			simmed, err := w.computeBundleGas(env, bundle, state, gasPool, pendingTxs, 0)
 
+			if metrics.EnabledBuilder {
+				simulationMeter.Mark(1)
+			}
+
 			if err != nil {
+				if metrics.EnabledBuilder {
+					simulationRevertedMeter.Mark(1)
+					failedBundleSimulationTimer.UpdateSince(start)
+				}
+
 				log.Trace("Error computing gas for a bundle", "error", err)
 				return
 			}
 			simResult[idx] = &simmed
+
+			if metrics.EnabledBuilder {
+				simulationCommittedMeter.Mark(1)
+				successfulBundleSimulationTimer.UpdateSince(start)
+			}
 		}(i, bundle, env.state.Copy())
 	}
 
@@ -1748,6 +1781,9 @@ func (w *worker) simulateBundles(env *environment, bundles []types.MevBundle, pe
 	}
 
 	log.Debug("Simulated bundles", "block", env.header.Number, "allBundles", len(bundles), "okBundles", len(simulatedBundles), "time", time.Since(start))
+	if metrics.EnabledBuilder {
+		blockBundleSimulationTimer.Update(time.Since(start))
+	}
 	return simulatedBundles, nil
 }