Add metric and logs

cmd/cdk-erigon/main.go

@@ -18,8 +18,8 @@ import (
 	"github.com/ledgerwatch/erigon/params"
 	erigonapp "github.com/ledgerwatch/erigon/turbo/app"
 	erigoncli "github.com/ledgerwatch/erigon/turbo/cli"
-	"github.com/ledgerwatch/erigon/turbo/node"
 	"github.com/ledgerwatch/erigon/turbo/logging"
+	"github.com/ledgerwatch/erigon/turbo/node"
 )
 
 func main() {
@@ -63,7 +63,7 @@ func runErigon(cliCtx *cli.Context) error {
 	ethCfg := node.NewEthConfigUrfave(cliCtx, nodeCfg)
 
 	// Init for X Layer
-	initRunForXLayer(ethCfg)
+	initRunForXLayer(cliCtx, ethCfg)
 
 	ethNode, err := node.New(nodeCfg, ethCfg)
 	if err != nil {

cmd/cdk-erigon/run_xlayer.go

@@ -1,14 +1,22 @@
 package main
 
 import (
+	"github.com/ledgerwatch/erigon/cmd/utils"
 	"github.com/ledgerwatch/erigon/eth/ethconfig"
 	"github.com/ledgerwatch/erigon/zk/apollo"
+	"github.com/ledgerwatch/erigon/zk/metrics"
 	"github.com/ledgerwatch/log/v3"
+	"github.com/urfave/cli/v2"
 )
 
-func initRunForXLayer(ethCfg *ethconfig.Config) {
+func initRunForXLayer(cliCtx *cli.Context, ethCfg *ethconfig.Config) {
 	apolloClient := apollo.NewClient(ethCfg)
 	if apolloClient.LoadConfig() {
 		log.Info("Apollo config loaded")
 	}
+
+	// Init metrics
+	if cliCtx.Bool(utils.MetricsEnabledFlag.Name) {
+		metrics.Init()
+	}
 }

metrics/exp/exp.go

@@ -6,24 +6,24 @@ import (
 	"fmt"
 	"net/http"
 
-	metrics2 "github.com/VictoriaMetrics/metrics"
+	"github.com/VictoriaMetrics/metrics"
 	"github.com/ledgerwatch/log/v3"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
 )
 
 // Setup starts a dedicated metrics server at the given address.
 // This function enables metrics reporting separate from pprof.
 func Setup(address string) {
-	http.HandleFunc("/debug/metrics/prometheus", func(w http.ResponseWriter, r *http.Request) {
+	// For X Layer
+	mux := http.NewServeMux()
+	mux.Handle("/debug/metrics/prometheus", promhttp.Handler())
+	mux.Handle("/debug/metrics", http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		w.Header().Set("Access-Control-Allow-Origin", "*")
-		metrics2.WritePrometheus(w, true)
-	})
-	//m.Handle("/debug/metrics", ExpHandler(metrics.DefaultRegistry))
-	//m.Handle("/debug/metrics/prometheus2", promhttp.HandlerFor(prometheus2.DefaultGatherer, promhttp.HandlerOpts{
-	//	EnableOpenMetrics: true,
-	//}))
-	log.Info("Starting metrics server", "addr", fmt.Sprintf("http://%s/debug/metrics/prometheus", address))
+		metrics.WritePrometheus(w, true)
+	}))
+	log.Info("Starting metrics server", "addr", fmt.Sprintf("http://%v/debug/metrics/prometheus or http://%v/debug/metrics", address, address))
 	go func() {
-		if err := http.ListenAndServe(address, nil); err != nil { // nolint:gosec
+		if err := http.ListenAndServe(address, mux); err != nil { // nolint:gosec
 			log.Error("Failure in running metrics server", "err", err)
 		}
 	}()

test/config/test.erigon.rpc.config.yaml

@@ -22,7 +22,7 @@ zkevm.l1-highest-block-type: latest
 zkevm.rpc-ratelimit: 300
 zkevm.datastream-version: 2
 
-log.console.verbosity: 4
+log.console.verbosity: info
 
 #zkevm.executor-urls: erigon-stateless-executor:50071
 zkevm.executor-urls: ""
@@ -46,7 +46,25 @@ http.addr: 0.0.0.0
 http.port: 8545
 http.vhosts: any
 http.corsdomain: any
+http.timeouts.read: "10s"
+http.timeouts.write: "10s"
+http.timeouts.idle: "10s"
 ws: true
+
+zkevm.apollo-enabled: false
+zkevm.apollo-ip-addr: ""
+zkevm.apollo-app-id: ""
+zkevm.apollo-namespace-name: ""
+
+zkevm.nacos-urls: ""
+zkevm.nacos-namespace-id: ""
+zkevm.nacos-application-name: ""
+zkevm.nacos-external-listen-addr: ""
+
+metrics: true
+metrics.addr: "0.0.0.0"
+metrics.port: 9095
+
 db.read.concurrency: 20000
 txpool.globalslots: 100000
 networkid: 195
@@ -59,4 +77,5 @@ http.methodratelimit: "{\"methods\":[\"eth_syncing\"],\"count\":10,\"bucket\":1}
 
 pprof: true
 pprof.port: 6060
-pprof.addr: 127.0.0.1
+pprof.addr: 127.0.0.1
+

test/config/test.erigon.seq.config.yaml

@@ -22,7 +22,7 @@ zkevm.l1-query-delay: 6000
 zkevm.rpc-ratelimit: 300
 zkevm.datastream-version: 2
 
-log.console.verbosity: 4
+log.console.verbosity: info
 
 #zkevm.executor-urls: erigon-stateless-executor:50071
 zkevm.executor-urls: ""
@@ -38,16 +38,17 @@ zkevm.data-stream-port: 6900
 zkevm.default-gas-price: 1000000000
 zkevm.max-gas-price: 0
 zkevm.gas-price-factor: 0.000001
-#zkevm.gasless: true
+zkevm.gasless: true
 
 externalcl: true
 http.api: [eth, debug, net, trace, web3, erigon, txpool, zkevm]
 http.addr: 0.0.0.0
 http.port: 8545
 http.vhosts: any
 http.corsdomain: any
-http.timeouts.read: "60s"
-http.timeouts.write: "60s"
+http.timeouts.read: "10s"
+http.timeouts.write: "10s"
+http.timeouts.idle: "10s"
 rpc.batch.concurrency: 2
 rpc.batch.limit: 20
 ws: true
@@ -62,6 +63,10 @@ zkevm.nacos-namespace-id: ""
 zkevm.nacos-application-name: ""
 zkevm.nacos-external-listen-addr: ""
 
+metrics: true
+metrics.addr: "0.0.0.0"
+metrics.port: 9095
+
 db.read.concurrency: 20000
 txpool.globalslots: 100000
 txpool.globalbasefeeslots: 100000
@@ -73,7 +78,7 @@ txpool.enablefreegasbynonce : true
 txpool.freegascountperaddr : 100
 
 gpo.type: "follower"
-gpo.update-period: "2s"
+gpo.update-period: "60s"
 gpo.factor: 0.01
 gpo.kafka-url: "0.0.0.0"
 gpo.topic: "explorer"

test/config/test.poolmanager.toml

@@ -8,7 +8,7 @@ Host = "0.0.0.0"
 Port = 8545
 ReadTimeout = "60s"
 WriteTimeout = "60s"
-MaxRequestsPerIPAndSecond = 500
+MaxRequestsPerIPAndSecond = 50000
 EnableHttpLog = true
 BatchRequestsEnabled = false
 BatchRequestsLimit = 20

test/docker-compose.yml

@@ -117,6 +117,7 @@ services:
     ports:
       - 8123:8545
       - 6900:6900
+      - 9092:9095
     volumes:
       - ./config/test.erigon.seq.config.yaml:/usr/src/app/config.yaml
       - ./config/dynamic-mynetwork-allocs.json:/usr/src/app/dynamic-mynetwork-allocs.json
@@ -133,6 +134,7 @@ services:
     ports:
       - 8124:8545
       - 6901:6900
+      - 9091:9095
     volumes:
       - ./config/test.erigon.rpc.config.yaml:/usr/src/app/config.yaml
       - ./config/dynamic-mynetwork-allocs.json:/usr/src/app/dynamic-mynetwork-allocs.json

test/e2e/smoke_test.go

@@ -361,6 +361,19 @@ func TestGasPrice(t *testing.T) {
 	require.Greater(t, gasPrice2, gasPrice1)
 }
 
+func TestMetrics(t *testing.T) {
+	result, err := operations.GetMetricsPrometheus()
+	require.NoError(t, err)
+	require.Equal(t, strings.Contains(result, "sequencer_batch_execute_time"), true)
+	require.Equal(t, strings.Contains(result, "sequencer_pool_tx_count"), true)
+
+	result, err = operations.GetMetrics()
+	require.NoError(t, err)
+	require.Equal(t, strings.Contains(result, "zkevm_getBatchWitness"), true)
+	require.Equal(t, strings.Contains(result, "eth_sendRawTransaction"), true)
+	require.Equal(t, strings.Contains(result, "eth_getTransactionCount"), true)
+}
+
 func transToken(t *testing.T, ctx context.Context, client *ethclient.Client, amount *uint256.Int, toAddress string) string {
 	auth, err := operations.GetAuth(operations.DefaultL2AdminPrivateKey, operations.DefaultL2ChainID)
 	nonce, err := client.PendingNonceAt(ctx, auth.From)

test/operations/manager.go

@@ -26,6 +26,9 @@ const (
 	DefaultL2NetworkURL        = "http://localhost:8124"
 	DefaultL2ChainID    uint64 = 195
 
+	DefaultL2MetricsPrometheusURL = "http://127.0.0.1:9092/debug/metrics/prometheus"
+	DefaultL2MetricsURL           = "http://127.0.0.1:9092/debug/metrics"
+
 	BridgeAddr = "0x1089Af36bD72553008FAd0A1240B4D5641208494"
 
 	DefaultTimeoutTxToBeMined = 1 * time.Minute

test/operations/rpc_client.go

@@ -3,8 +3,11 @@ package operations
 import (
 	"encoding/json"
 	"fmt"
+	"io/ioutil"
 	"math/big"
+	"net/http"
 	"strconv"
+	"time"
 
 	"github.com/gateway-fm/cdk-erigon-lib/common"
 	types "github.com/ledgerwatch/erigon/zk/rpcdaemon"
@@ -223,3 +226,37 @@ func GetMinGasPrice() (uint64, error) {
 
 	return transHexToUint64(response.Result)
 }
+
+func GetMetricsPrometheus() (string, error) {
+	client := http.Client{
+		Timeout: 10 * time.Second,
+	}
+	resp, err := client.Get(DefaultL2MetricsPrometheusURL)
+	if err != nil {
+		fmt.Println("Error:", err)
+		return "", err
+	}
+	defer resp.Body.Close()
+	body, err := ioutil.ReadAll(resp.Body)
+	if err != nil {
+		return "", err
+	}
+	return string(body), nil
+}
+
+func GetMetrics() (string, error) {
+	client := http.Client{
+		Timeout: 10 * time.Second,
+	}
+	resp, err := client.Get(DefaultL2MetricsURL)
+	if err != nil {
+		fmt.Println("Error:", err)
+		return "", err
+	}
+	defer resp.Body.Close()
+	body, err := ioutil.ReadAll(resp.Body)
+	if err != nil {
+		return "", err
+	}
+	return string(body), nil
+}

zk/metrics/metrics_xlayer.go

@@ -0,0 +1,56 @@
+package metrics
+
+import (
+	"fmt"
+	"time"
+
+	"github.com/ledgerwatch/log/v3"
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+type BatchFinalizeType string
+
+const (
+	BatchTimeOut         BatchFinalizeType = "EmptyBatchTimeOut"
+	BatchCounterOverflow BatchFinalizeType = "BatchCounterOverflow"
+	BatchLimboRecovery   BatchFinalizeType = "LimboRecovery"
+)
+
+var (
+	SeqPrefix            = "sequencer_"
+	BatchExecuteTimeName = SeqPrefix + "batch_execute_time"
+	PoolTxCountName      = SeqPrefix + "pool_tx_count"
+)
+
+func Init() {
+	prometheus.MustRegister(BatchExecuteTimeGauge)
+	prometheus.MustRegister(PoolTxCount)
+}
+
+var BatchExecuteTimeGauge = prometheus.NewGaugeVec(
+	prometheus.GaugeOpts{
+		Name: BatchExecuteTimeName,
+		Help: "[SEQUENCER] batch execution time in second",
+	},
+	[]string{"closingReason"},
+)
+
+var PoolTxCount = prometheus.NewGaugeVec(
+	prometheus.GaugeOpts{
+		Name: PoolTxCountName,
+		Help: "[SEQUENCER] tx count of each pool in tx pool",
+	},
+	[]string{"poolName"},
+)
+
+func BatchExecuteTime(closingReason string, duration time.Duration) {
+	log.Info(fmt.Sprintf("[BatchExecuteTime] ClosingReason: %v, Duration: %.2fs", closingReason, duration.Seconds()))
+	BatchExecuteTimeGauge.WithLabelValues(closingReason).Set(duration.Seconds())
+}
+
+func AddPoolTxCount(pending, baseFee, queued int) {
+	log.Info(fmt.Sprintf("[PoolTxCount] pending: %v, basefee: %v, queued: %v", pending, baseFee, queued))
+	PoolTxCount.WithLabelValues("pending").Set(float64(pending))
+	PoolTxCount.WithLabelValues("basefee").Set(float64(baseFee))
+	PoolTxCount.WithLabelValues("queued").Set(float64(queued))
+}

zk/metrics/statistics_xlayer.go

@@ -0,0 +1,37 @@
+package metrics
+
+import (
+	"time"
+)
+
+type logTag string
+
+const (
+	BlockCounter                  logTag = "BlockCounter"
+	TxCounter                     logTag = "TxCounter"
+	GetTx                         logTag = "GetTx"
+	GetTxPauseCounter             logTag = "GetTxPauseCounter"
+	GetTxPauseTiming              logTag = "GetTxPauseTiming"
+	BatchCloseReason              logTag = "BatchCloseReason"
+	ReprocessingTxCounter         logTag = "ReProcessingTxCounter"
+	FailTxCounter                 logTag = "FailTxCounter"
+	FailTxResourceOverCounter     logTag = "FailTxResourceOverCounter"
+	BatchGas                      logTag = "BatchGas"
+	ProcessingTxTiming            logTag = "ProcessingTxTiming"
+	ProcessingInvalidTxCounter    logTag = "ProcessingInvalidTxCounter"
+	FinalizeBatchNumber           logTag = "FinalizeBatchNumber"
+	BatchCommitDBTiming           logTag = "BatchCommitDBTiming"
+	PbStateTiming                 logTag = "PbStateTiming"
+	ZkIncIntermediateHashesTiming logTag = "ZkIncIntermediateHashesTiming"
+	FinaliseBlockWriteTiming      logTag = "FinaliseBlockWriteTiming"
+)
+
+type Statistics interface {
+	CumulativeCounting(tag logTag)
+	CumulativeValue(tag logTag, value int64)
+	CumulativeTiming(tag logTag, duration time.Duration)
+	SetTag(tag logTag, value string)
+	GetTag(tag logTag) string
+	GetStatistics(tag logTag) int64
+	Summary() string
+}