state: benchmarks for the new and old state

blockchain/blockchain.go

@@ -3,6 +3,7 @@ package blockchain
 import (
 	"errors"
 	"fmt"
+	"time"
 
 	"github.com/Masterminds/semver/v3"
 	"github.com/NethermindEth/juno/core"
@@ -12,6 +13,7 @@ import (
 	"github.com/NethermindEth/juno/core/trie2/triedb"
 	"github.com/NethermindEth/juno/db"
 	"github.com/NethermindEth/juno/feed"
+	"github.com/NethermindEth/juno/performance"
 	"github.com/NethermindEth/juno/utils"
 	"github.com/ethereum/go-ethereum/common"
 )
@@ -110,6 +112,12 @@ func New(database db.KeyValueStore, network *utils.Network, stateVersion bool) *
 		panic(err)
 	}
 
+	reporter, err := performance.NewPerformanceReporter(stateVersion, 5000)
+	if err != nil {
+		panic(err)
+	}
+	performance.SetGlobalReporter(reporter)
+
 	cachedFilters := NewAggregatedBloomCache(AggregatedBloomFilterCacheSize)
 	fallback := func(key EventFiltersCacheKey) (core.AggregatedBloomFilter, error) {
 		return core.GetAggregatedBloomFilter(database, key.fromBlock, key.toBlock)
@@ -272,9 +280,18 @@ func (b *Blockchain) Store(block *core.Block, blockCommitments *core.BlockCommit
 	// old state
 	// TODO(maksymmalick): remove this once we have a new state implementation
 	if !b.StateFactory.UseNewState {
+		start := time.Now()
+		defer func() {
+			addDuration(&allStoreTime, time.Since(start))
+			incCounter(&allStore)
+		}()
 		return b.deprecatedStore(block, blockCommitments, stateUpdate, newClasses)
 	}
-
+	start := time.Now()
+	defer func() {
+		addDuration(&allStoreTime, time.Since(start))
+		incCounter(&allStore)
+	}()
 	return b.store(block, blockCommitments, stateUpdate, newClasses)
 }
 
@@ -285,14 +302,22 @@ func (b *Blockchain) deprecatedStore(
 	newClasses map[felt.Felt]core.Class,
 ) error {
 	err := b.database.Update(func(txn db.IndexedBatch) error {
+		storeStartTime := time.Now()
 		if err := verifyBlock(txn, block); err != nil {
 			return err
 		}
 
 		state := core.NewState(txn)
+
+		start := time.Now()
 		if err := state.Update(block.Number, stateUpdate, newClasses, false, true); err != nil {
 			return err
 		}
+		addDuration(&allUpdateTime, time.Since(start))
+
+		// Update performance reporter with block number
+		performance.UpdateBlockNumber(block.Number)
+
 		if err := core.WriteBlockHeader(txn, block.Header); err != nil {
 			return err
 		}
@@ -316,6 +341,9 @@ func (b *Blockchain) deprecatedStore(
 			return err
 		}
 
+		defer func() {
+			addDuration(&innerStoreTime, time.Since(storeStartTime))
+		}()
 		return core.WriteChainHeight(txn, block.Number)
 	})
 	if err != nil {
@@ -334,6 +362,7 @@ func (b *Blockchain) store(
 	stateUpdate *core.StateUpdate,
 	newClasses map[felt.Felt]core.Class,
 ) error {
+	storeStartTime := time.Now()
 	// TODO(weiihann): handle unexpected shutdown
 	if err := verifyBlock(b.database, block); err != nil {
 		return err
@@ -342,10 +371,14 @@ func (b *Blockchain) store(
 	if err != nil {
 		return err
 	}
+	start := time.Now()
+	batch := b.database.NewBatch()
 	if err := state.Update(block.Number, stateUpdate, newClasses, false, true); err != nil {
 		return err
 	}
-	batch := b.database.NewBatch()
+	addDuration(&allUpdateTime, time.Since(start))
+
+	performance.UpdateBlockNumber(block.Number)
 	if err := core.WriteBlockHeader(batch, block.Header); err != nil {
 		return err
 	}
@@ -370,11 +403,16 @@ func (b *Blockchain) store(
 	if err := core.WriteChainHeight(batch, block.Number); err != nil {
 		return err
 	}
+	addDuration(&innerStoreTime, time.Since(storeStartTime))
 
 	if err := b.runningFilter.Insert(block.EventsBloom, block.Number); err != nil {
 		return err
 	}
 
+	start = time.Now()
+	defer func() {
+		addDuration(&allBatchStoreTime, time.Since(start))
+	}()
 	return batch.Write()
 }
 

blockchain/metrics.go

@@ -0,0 +1,86 @@
+package blockchain
+
+import (
+	"sync/atomic"
+	"time"
+
+	"github.com/NethermindEth/juno/performance"
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+var (
+	allStore          uint64
+	allStoreTime      int64
+	allUpdateTime     int64
+	innerStoreTime    int64
+	allBatchStoreTime int64
+)
+
+func incCounter(c *uint64) {
+	atomic.AddUint64(c, 1)
+}
+
+func addDuration(c *int64, d time.Duration) {
+	atomic.AddInt64(c, d.Nanoseconds())
+	// Also add to performance reporter
+	performance.AddDuration(getBlockchainMetricName(c), d.Nanoseconds())
+}
+
+func getBlockchainMetricName(c *int64) string {
+	switch c {
+	case &allStoreTime:
+		return "allStoreTime"
+	case &allUpdateTime:
+		return "allUpdateTime"
+	case &innerStoreTime:
+		return "innerStoreTime"
+	case &allBatchStoreTime:
+		return "allBatchStoreTime"
+	default:
+		return "unknown"
+	}
+}
+
+type BlockchainMetricsCollector struct{}
+
+func (c *BlockchainMetricsCollector) Describe(ch chan<- *prometheus.Desc) {
+	// One-time descriptions
+	descs := []*prometheus.Desc{
+		prometheus.NewDesc("x_blockchain_all_store", "All store", nil, nil),
+		prometheus.NewDesc("x_blockchain_all_store_time_ns", "Total time spent storing (ns)", nil, nil),
+		prometheus.NewDesc("x_blockchain_all_update_time_ns", "Total time spent updating (ns)", nil, nil),
+		prometheus.NewDesc("x_blockchain_all_batch_store_time_ns", "Total time spent batch store (ns)", nil, nil),
+		prometheus.NewDesc("x_blockchain_inner_store_time_ns", "Total time spent inner store (ns)", nil, nil),
+	}
+	for _, d := range descs {
+		ch <- d
+	}
+}
+
+func (c *BlockchainMetricsCollector) Collect(ch chan<- prometheus.Metric) {
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_blockchain_all_store", "All store", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadUint64(&allStore)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_blockchain_all_store_time_ns", "Total time spent storing (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStoreTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_blockchain_all_update_time_ns", "Total time spent updating (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allUpdateTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_blockchain_all_batch_store_time_ns", "Total time spent batch store (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allBatchStoreTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_blockchain_deprecated_inner_store_time_ns", "Total time spent deprecated inner store (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&innerStoreTime)),
+	)
+}

core/metrics.go

@@ -0,0 +1,175 @@
+package core
+
+import (
+	"sync/atomic"
+	"time"
+
+	"github.com/NethermindEth/juno/performance"
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+var (
+	allVerifyComm                           uint64
+	allVerifyCommTime                       int64
+	allRegisterClassesTime                  int64
+	allUpdateClassTrieTime                  int64
+	allStateCommitClassesTrieCommitTime     int64
+	allRegisterDeployedContractsTime        int64
+	allStateCommitKeysSortTime              int64
+	allStateCommitContractStorageCommitTime int64
+	allStateCommitContractTrieUpdateTime    int64
+	allUpdateContractsTime                  int64
+	allStateCommitContractTrieCommitTime    int64
+	allReplaceContractsTime                 int64
+	allUpdateContractNoncesTime             int64
+	allUpdateContractsStorageTime           int64
+	allCheckContractsDeployedTime           int64
+)
+
+func incCounter(c *uint64) {
+	atomic.AddUint64(c, 1)
+}
+
+func addDuration(c *int64, d time.Duration) {
+	atomic.AddInt64(c, d.Nanoseconds())
+	// Also add to performance reporter
+	performance.AddDuration(getMetricName(c), d.Nanoseconds())
+}
+
+func getMetricName(c *int64) string {
+	switch c {
+	case &allVerifyCommTime:
+		return "allVerifyCommTime"
+	case &allRegisterClassesTime:
+		return "allRegisterClassesTime"
+	case &allUpdateClassTrieTime:
+		return "allUpdateClassTrieTime"
+	case &allStateCommitClassesTrieCommitTime:
+		return "allStateCommitClassesTrieCommitTime"
+	case &allRegisterDeployedContractsTime:
+		return "allRegisterDeployedContractsTime"
+	case &allStateCommitKeysSortTime:
+		return "allStateCommitKeysSortTime"
+	case &allStateCommitContractStorageCommitTime:
+		return "allStateCommitContractStorageCommitTime"
+	case &allStateCommitContractTrieUpdateTime:
+		return "allStateCommitContractTrieUpdateTime"
+	case &allUpdateContractsTime:
+		return "allUpdateContractsTime"
+	case &allStateCommitContractTrieCommitTime:
+		return "allStateCommitContractTrieCommitTime"
+	case &allReplaceContractsTime:
+		return "allReplaceContractsTime"
+	case &allUpdateContractNoncesTime:
+		return "allUpdateContractNoncesTime"
+	case &allUpdateContractsStorageTime:
+		return "allUpdateContractsStorageTime"
+	case &allCheckContractsDeployedTime:
+		return "allCheckContractsDeployedTime"
+	default:
+		return "unknown"
+	}
+}
+
+type StateMetricsCollector struct{}
+
+func (c *StateMetricsCollector) Describe(ch chan<- *prometheus.Desc) {
+	descs := []*prometheus.Desc{
+		prometheus.NewDesc("x_deprecated_state_all_verify_comm", "All verify comm", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_verify_comm_time_ns", "Total time spent verifying comm (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_register_classes_time_ns", "Total time spent registering classes (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_update_class_trie_time_ns", "Total time spent updating class trie (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_classes_trie_commit_time_ns", "Total time spent committing classes trie (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_register_deployed_contracts_time_ns", "Total time spent registering deployed contracts (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_keys_sort_time_ns", "Total time spent sorting keys (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_storage_commit_time_ns", "Total time spent committing contract storage (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_trie_update_time_ns", "Total time spent updating contract trie (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_update_contracts_time_ns", "Total time spent updating contracts (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_trie_commit_time_ns", "Total time spent committing contract trie (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_replace_contracts_time_ns", "Total time spent replacing contracts (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_update_contract_nonces_time_ns", "Total time spent updating contract nonces (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_update_contracts_storage_time_ns", "Total time spent updating contract storage (ns)", nil, nil),
+		prometheus.NewDesc("x_deprecated_state_all_check_contracts_deployed_time_ns", "Total time spent checking contracts deployed (ns)", nil, nil),
+	}
+	for _, d := range descs {
+		ch <- d
+	}
+}
+
+func (c *StateMetricsCollector) Collect(ch chan<- prometheus.Metric) {
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_verify_comm", "All verify comm", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadUint64(&allVerifyComm)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_verify_comm_time_ns", "Total time spent verifying comm (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allVerifyCommTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_register_classes_time_ns", "Total time spent registering classes (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allRegisterClassesTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_update_class_trie_time_ns", "Total time spent updating class trie (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allUpdateClassTrieTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_classes_trie_commit_time_ns", "Total time spent committing classes trie (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStateCommitClassesTrieCommitTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_register_deployed_contracts_time_ns", "Total time spent registering deployed contracts (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allRegisterDeployedContractsTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_keys_sort_time_ns", "Total time spent sorting keys (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStateCommitKeysSortTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_storage_commit_time_ns", "Total time spent committing contract storage (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStateCommitContractStorageCommitTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_trie_update_time_ns", "Total time spent updating contract trie (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStateCommitContractTrieUpdateTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_update_contracts_time_ns", "Total time spent updating contracts (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allUpdateContractsTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_state_commit_contract_trie_commit_time_ns", "Total time spent committing contract trie (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allStateCommitContractTrieCommitTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_replace_contracts_time_ns", "Total time spent replacing contracts (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allReplaceContractsTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_update_contract_nonces_time_ns", "Total time spent updating contract nonces (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allUpdateContractNoncesTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_update_contracts_storage_time_ns", "Total time spent updating contract storage (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allUpdateContractsStorageTime)),
+	)
+	ch <- prometheus.MustNewConstMetric(
+		prometheus.NewDesc("x_deprecated_state_all_check_contracts_deployed_time_ns", "Total time spent checking contracts deployed (ns)", nil, nil),
+		prometheus.CounterValue,
+		float64(atomic.LoadInt64(&allCheckContractsDeployedTime)),
+	)
+}