Implements metrics

.gitignore

@@ -1,2 +1,3 @@
 build/bin/
 nodelogs/
+/data/

cmd/go-quai/start.go

@@ -13,6 +13,7 @@ import (
 	"github.com/dominant-strategies/go-quai/cmd/utils"
 	"github.com/dominant-strategies/go-quai/common"
 	"github.com/dominant-strategies/go-quai/log"
+	"github.com/dominant-strategies/go-quai/metrics_config"
 	"github.com/dominant-strategies/go-quai/p2p/node"
 )
 
@@ -41,6 +42,11 @@ func init() {
 	for _, flag := range utils.RPCFlags {
 		utils.CreateAndBindFlag(flag, startCmd)
 	}
+
+	// Create and bind all metrics flags to the start command
+	for _, flag := range utils.MetricsFlags {
+		utils.CreateAndBindFlag(flag, startCmd)
+	}
 }
 
 func startCmdPreRun(cmd *cobra.Command, args []string) error {
@@ -94,6 +100,12 @@ func runStart(cmd *cobra.Command, args []string) error {
 		log.Fatalf("error starting gossipsub: %s", err)
 	}
 
+	if viper.IsSet(utils.MetricsEnabledFlag.Name) {
+		log.Info("Starting metrics")
+		metrics_config.EnableMetrics()
+		go metrics_config.StartProcessMetrics()
+	}
+
 	// wait for a SIGINT or SIGTERM signal
 	ch := make(chan os.Signal, 1)
 	signal.Notify(ch, syscall.SIGINT, syscall.SIGTERM)

cmd/utils/cmd.go

@@ -13,6 +13,7 @@ import (
 	"github.com/dominant-strategies/go-quai/core/vm"
 	"github.com/dominant-strategies/go-quai/internal/quaiapi"
 	"github.com/dominant-strategies/go-quai/log"
+	"github.com/dominant-strategies/go-quai/metrics_config"
 	"github.com/dominant-strategies/go-quai/node"
 	"github.com/dominant-strategies/go-quai/params"
 	"github.com/dominant-strategies/go-quai/quai"
@@ -72,8 +73,9 @@ func StartNode(stack *node.Node) {
 func makeConfigNode(nodeLocation common.Location, logger log.Logger) (*node.Node, quaiconfig.QuaiConfig) {
 	// Load defaults.
 	cfg := quaiconfig.QuaiConfig{
-		Quai: quaiconfig.Defaults,
-		Node: defaultNodeConfig(),
+		Quai:    quaiconfig.Defaults,
+		Node:    defaultNodeConfig(),
+		Metrics: metrics_config.DefaultConfig,
 	}
 
 	// Apply flags.

cmd/utils/flags.go

@@ -21,6 +21,7 @@ import (
 	"github.com/dominant-strategies/go-quai/core/rawdb"
 	"github.com/dominant-strategies/go-quai/ethdb"
 	"github.com/dominant-strategies/go-quai/log"
+	"github.com/dominant-strategies/go-quai/metrics_config"
 	"github.com/dominant-strategies/go-quai/node"
 	"github.com/dominant-strategies/go-quai/params"
 	"github.com/dominant-strategies/go-quai/quai/gasprice"
@@ -121,6 +122,13 @@ var RPCFlags = []Flag{
 	SendFullStatsFlag,
 }
 
+var MetricsFlags = []Flag{
+	MetricsEnabledFlag,
+	MetricsEnabledExpensiveFlag,
+	MetricsHTTPFlag,
+	MetricsPortFlag,
+}
+
 var (
 	// ****************************************
 	// **                                    **
@@ -304,7 +312,26 @@ var (
 		Value: xdg.DataHome,
 		Usage: "Document Root for HTTPClient file scheme" + generateEnvDoc("docroot"),
 	}
-
+	MetricsEnabledFlag = Flag{
+		Name:  "metrics",
+		Value: false,
+		Usage: "Enable metrics collection and reporting" + generateEnvDoc("metrics"),
+	}
+	MetricsEnabledExpensiveFlag = Flag{
+		Name:  "metrics.expensive",
+		Value: false,
+		Usage: "Enable expensive metrics collection and reporting" + generateEnvDoc("metrics.expensive"),
+	}
+	MetricsHTTPFlag = Flag{
+		Name:  "metrics.addr",
+		Value: metrics_config.DefaultConfig.HTTP,
+		Usage: "Enable stand-alone metrics HTTP server listening interface" + generateEnvDoc("metrics.addr"),
+	}
+	MetricsPortFlag = Flag{
+		Name:  "metrics.port",
+		Value: metrics_config.DefaultConfig.Port,
+		Usage: "Metrics HTTP server listening port" + generateEnvDoc("metrics.port"),
+	}
 	// ****************************************
 	// ** 								     **
 	// ** 	      PY FLAGS    				 **

core/state/state_object.go

@@ -25,6 +25,8 @@ import (
 
 	"github.com/dominant-strategies/go-quai/common"
 	"github.com/dominant-strategies/go-quai/crypto"
+
+	"github.com/dominant-strategies/go-quai/metrics_config"
 	"github.com/dominant-strategies/go-quai/rlp"
 )
 
@@ -205,11 +207,19 @@ func (s *stateObject) GetCommittedState(db Database, key common.Hash) common.Has
 	}
 	// If no live objects are available, attempt to use snapshots
 	var (
-		enc   []byte
-		err   error
-		meter *time.Duration
+		enc       []byte
+		err       error
+		readStart = time.Now()
 	)
-	readStart := time.Now()
+	if metrics_config.MetricsEnabled() {
+		// If the snap is 'under construction', the first lookup may fail. If that
+		// happens, we don't want to double-count the time elapsed. Thus this
+		// dance with the metering.
+		defer func() {
+			stateMetrics.WithLabelValues("StorageReads").Add(float64(time.Since(readStart)))
+		}()
+	}
+
 	if s.db.snap != nil {
 		// If the object was destructed in *this* block (and potentially resurrected),
 		// the storage has been cleared out, and we should *not* consult the previous
@@ -224,10 +234,10 @@ func (s *stateObject) GetCommittedState(db Database, key common.Hash) common.Has
 	}
 	// If snapshot unavailable or reading from it failed, load from the database
 	if s.db.snap == nil || err != nil {
-		if meter != nil {
+		if stateMetrics.WithLabelValues("StorageReads") != nil {
 			// If we already spent time checking the snapshot, account for it
 			// and reset the readStart
-			*meter += time.Since(readStart)
+			stateMetrics.WithLabelValues("StorageReads").Add(float64(time.Since(readStart)))
 			readStart = time.Now()
 		}
 		if enc, err = s.getTrie(db).TryGet(key.Bytes()); err != nil {
@@ -316,6 +326,10 @@ func (s *stateObject) updateTrie(db Database) Trie {
 	if len(s.pendingStorage) == 0 {
 		return s.trie
 	}
+	// Track the amount of time wasted on updating the storage trie
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("StorageUpdates").Add(float64(time.Since(start))) }(time.Now())
+	}
 	// The snapshot storage map for the object
 	var storage map[common.Hash][]byte
 	// Insert all the pending updates into the trie
@@ -366,6 +380,9 @@ func (s *stateObject) updateRoot(db Database) {
 	if s.updateTrie(db) == nil {
 		return
 	}
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("StorageHashes").Add(float64(time.Since(start))) }(time.Now())
+	}
 	s.data.Root = s.trie.Hash()
 }
 
@@ -379,6 +396,9 @@ func (s *stateObject) CommitTrie(db Database) error {
 	if s.dbErr != nil {
 		return s.dbErr
 	}
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("StorageCommits").Add(float64(time.Since(start))) }(time.Now())
+	}
 	root, err := s.trie.Commit(nil)
 	if err == nil {
 		s.data.Root = root

core/state/statedb.go

@@ -30,8 +30,10 @@ import (
 	"github.com/dominant-strategies/go-quai/core/types"
 	"github.com/dominant-strategies/go-quai/crypto"
 	"github.com/dominant-strategies/go-quai/log"
+	"github.com/dominant-strategies/go-quai/metrics_config"
 	"github.com/dominant-strategies/go-quai/rlp"
 	"github.com/dominant-strategies/go-quai/trie"
+	"github.com/prometheus/client_golang/prometheus"
 )
 
 type revision struct {
@@ -55,6 +57,29 @@ func (n *proofList) Delete(key []byte) error {
 	panic("not supported")
 }
 
+var (
+	stateMetrics *prometheus.GaugeVec
+)
+
+func init() {
+	registerMetrics()
+}
+
+func registerMetrics() {
+	stateMetrics = metrics_config.NewGaugeVec("StateTimes", "Time spent doing state operations")
+	stateMetrics.WithLabelValues("AccountReads")
+	stateMetrics.WithLabelValues("AccountHashes")
+	stateMetrics.WithLabelValues("AccountUpdates")
+	stateMetrics.WithLabelValues("AccountCommits")
+	stateMetrics.WithLabelValues("StorageReads")
+	stateMetrics.WithLabelValues("StorageHashes")
+	stateMetrics.WithLabelValues("StorageUpdates")
+	stateMetrics.WithLabelValues("StorageCommits")
+	stateMetrics.WithLabelValues("SnapshotAccountReads")
+	stateMetrics.WithLabelValues("SnapshotStorageReads")
+	stateMetrics.WithLabelValues("SnapshotCommits")
+}
+
 // StateDB structs within the Quai protocol are used to store anything
 // within the merkle trie. StateDBs take care of caching and storing
 // nested states. It's the general query interface to retrieve:
@@ -451,6 +476,10 @@ func (s *StateDB) Suicide(addr common.InternalAddress) bool {
 
 // updateStateObject writes the given object to the trie.
 func (s *StateDB) updateStateObject(obj *stateObject) {
+	// Track the amount of time wasted on updating the account from the trie
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("AccountUpdates").Add(float64(time.Since(start))) }(time.Now())
+	}
 	// Encode the account and update the account trie
 	addr := obj.Address()
 
@@ -473,6 +502,10 @@ func (s *StateDB) updateStateObject(obj *stateObject) {
 
 // deleteStateObject removes the given object from the state trie.
 func (s *StateDB) deleteStateObject(obj *stateObject) {
+	// Track the amount of time wasted on deleting the account from the trie
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("AccountUpdates").Add(float64(time.Since(start))) }(time.Now())
+	}
 	// Delete the account from the trie
 	addr := obj.Address()
 	if err := s.trie.TryDelete(addr[:]); err != nil {
@@ -505,6 +538,11 @@ func (s *StateDB) getDeletedStateObject(addr common.InternalAddress) *stateObjec
 		err  error
 	)
 	if s.snap != nil {
+		if metrics_config.MetricsEnabled() {
+			defer func(start time.Time) {
+				stateMetrics.WithLabelValues("SnapshotAccountReads").Add(float64(time.Since(start)))
+			}(time.Now())
+		}
 		var acc *snapshot.Account
 		if acc, err = s.snap.Account(crypto.HashData(s.hasher, addr.Bytes())); err == nil {
 			if acc == nil {
@@ -526,6 +564,9 @@ func (s *StateDB) getDeletedStateObject(addr common.InternalAddress) *stateObjec
 	}
 	// If snapshot unavailable or reading from it failed, load from the database
 	if s.snap == nil || err != nil {
+		if metrics_config.MetricsEnabled() {
+			defer func(start time.Time) { stateMetrics.WithLabelValues("AccountReads").Add(float64(time.Since(start))) }(time.Now())
+		}
 		enc, err := s.trie.TryGet(addr.Bytes())
 		if err != nil {
 			s.setError(fmt.Errorf("getDeleteStateObject (%x) error: %v", addr.Bytes(), err))
@@ -858,6 +899,10 @@ func (s *StateDB) IntermediateRoot(deleteEmptyObjects bool) common.Hash {
 	if len(s.stateObjectsPending) > 0 {
 		s.stateObjectsPending = make(map[common.InternalAddress]struct{})
 	}
+	// Track the amount of time wasted on hashing the account trie
+	if metrics_config.MetricsEnabled() {
+		defer func(start time.Time) { stateMetrics.WithLabelValues("AccountHashes").Add(float64(time.Since(start))) }(time.Now())
+	}
 	return s.trie.Hash()
 }
 
@@ -909,6 +954,11 @@ func (s *StateDB) Commit(deleteEmptyObjects bool) (common.Hash, error) {
 		}
 	}
 	// Write the account trie changes, measuing the amount of wasted time
+	var start time.Time
+	if metrics_config.MetricsEnabled() {
+		start = time.Now()
+	}
+	// Write the account trie changes, measuing the amount of wasted time
 	// The onleaf func is called _serially_, so we can reuse the same account
 	// for unmarshalling every time.
 	var account Account
@@ -921,8 +971,14 @@ func (s *StateDB) Commit(deleteEmptyObjects bool) (common.Hash, error) {
 		}
 		return nil
 	})
+	if metrics_config.MetricsEnabled() {
+		stateMetrics.WithLabelValues("AccountCommits").Add(float64(time.Since(start)))
+	}
 	// If snapshotting is enabled, update the snapshot tree with this new version
 	if s.snap != nil {
+		if metrics_config.MetricsEnabled() {
+			defer func(start time.Time) { stateMetrics.WithLabelValues("SnapshotCommits").Add(float64(time.Since(start))) }(time.Now())
+		}
 		// Only update if there's a state transition (skip empty Clique blocks)
 		if parent := s.snap.Root(); parent != root {
 			if err := s.snaps.Update(root, parent, s.snapDestructs, s.snapAccounts, s.snapStorage); err != nil {

core/state/trie_prefetcher.go

@@ -21,6 +21,7 @@ import (
 
 	"github.com/dominant-strategies/go-quai/common"
 	"github.com/dominant-strategies/go-quai/log"
+	"github.com/dominant-strategies/go-quai/metrics_config"
 )
 
 var (
@@ -55,6 +56,18 @@ func newTriePrefetcher(db Database, root common.Hash, namespace string) *triePre
 func (p *triePrefetcher) close() {
 	for _, fetcher := range p.fetchers {
 		fetcher.abort() // safe to do multiple times
+
+		if metrics_config.MetricsEnabled() {
+			if fetcher.root == p.root {
+				for _, key := range fetcher.used {
+					delete(fetcher.seen, string(key))
+				}
+			} else {
+				for _, key := range fetcher.used {
+					delete(fetcher.seen, string(key))
+				}
+			}
+		}
 	}
 	// Clear out all fetchers (will crash on a second call, deliberate)
 	p.fetchers = nil