Collect DB latency metrics

db/event_listener.go

@@ -1,15 +1,17 @@
 package db
 
+import "time"
+
 type EventListener interface {
-	OnIO(write bool)
+	OnIO(write bool, duration time.Duration)
 }
 
 type SelectiveListener struct {
-	OnIOCb func(write bool)
+	OnIOCb func(write bool, duration time.Duration)
 }
 
-func (l *SelectiveListener) OnIO(write bool) {
+func (l *SelectiveListener) OnIO(write bool, duration time.Duration) {
 	if l.OnIOCb != nil {
-		l.OnIOCb(write)
+		l.OnIOCb(write, duration)
 	}
 }

db/pebble/db_test.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"sync"
 	"testing"
+	"time"
 
 	"github.com/NethermindEth/juno/db"
 	"github.com/NethermindEth/juno/db/pebble"
@@ -21,7 +22,7 @@ type eventListener struct {
 	ReadCount  int
 }
 
-func (l *eventListener) OnIO(write bool) {
+func (l *eventListener) OnIO(write bool, _ time.Duration) {
 	if write {
 		l.WriteCount++
 	} else {

db/pebble/transaction.go

@@ -4,6 +4,7 @@ import (
 	"errors"
 	"io"
 	"sync"
+	"time"
 
 	"github.com/NethermindEth/juno/db"
 	"github.com/NethermindEth/juno/utils"
@@ -53,29 +54,32 @@ func (t *Transaction) Commit() error {
 
 // Set : see db.Transaction.Set
 func (t *Transaction) Set(key, val []byte) error {
+	start := time.Now()
 	if t.batch == nil {
 		return errors.New("read only transaction")
 	}
 	if len(key) == 0 {
 		return errors.New("empty key")
 	}
 
-	t.listener.OnIO(true)
+	defer func() { t.listener.OnIO(true, time.Since(start)) }()
 	return t.batch.Set(key, val, pebble.Sync)
 }
 
 // Delete : see db.Transaction.Delete
 func (t *Transaction) Delete(key []byte) error {
+	start := time.Now()
 	if t.batch == nil {
 		return errors.New("read only transaction")
 	}
 
-	t.listener.OnIO(true)
+	defer func() { t.listener.OnIO(true, time.Since(start)) }()
 	return t.batch.Delete(key, pebble.Sync)
 }
 
 // Get : see db.Transaction.Get
 func (t *Transaction) Get(key []byte, cb func([]byte) error) error {
+	start := time.Now()
 	var val []byte
 	var closer io.Closer
 
@@ -88,7 +92,7 @@ func (t *Transaction) Get(key []byte, cb func([]byte) error) error {
 		return ErrDiscardedTransaction
 	}
 
-	t.listener.OnIO(false)
+	defer func() { t.listener.OnIO(false, time.Since(start)) }()
 	if err != nil {
 		if errors.Is(err, pebble.ErrNotFound) {
 			return db.ErrKeyNotFound

node/metrics.go

@@ -1,6 +1,7 @@
 package node
 
 import (
+	"math"
 	"time"
 
 	"github.com/NethermindEth/juno/blockchain"
@@ -11,22 +12,41 @@ import (
 )
 
 func makeDBMetrics() db.EventListener {
-	readCounter := prometheus.NewCounter(prometheus.CounterOpts{
+	latencyBuckets := []float64{
+		25,
+		50,
+		75,
+		100,
+		250,
+		500,
+		1000, // 1ms
+		2000,
+		3000,
+		4000,
+		5000,
+		10000,
+		50000,
+		500000,
+		math.Inf(0),
+	}
+	readLatencyHistogram := prometheus.NewHistogram(prometheus.HistogramOpts{
 		Namespace: "db",
-		Name:      "read",
+		Name:      "read_latency",
+		Buckets:   latencyBuckets,
 	})
-	writeCounter := prometheus.NewCounter(prometheus.CounterOpts{
+	writeLatencyHistogram := prometheus.NewHistogram(prometheus.HistogramOpts{
 		Namespace: "db",
-		Name:      "write",
+		Name:      "write_latency",
+		Buckets:   latencyBuckets,
 	})
-	prometheus.MustRegister(readCounter, writeCounter)
 
+	prometheus.MustRegister(readLatencyHistogram, writeLatencyHistogram)
 	return &db.SelectiveListener{
-		OnIOCb: func(write bool) {
+		OnIOCb: func(write bool, duration time.Duration) {
 			if write {
-				writeCounter.Inc()
+				writeLatencyHistogram.Observe(float64(duration.Microseconds()))
 			} else {
-				readCounter.Inc()
+				readLatencyHistogram.Observe(float64(duration.Microseconds()))
 			}
 		},
 	}