From 86bf7f685b5dadf672572c1419f71919decb608b Mon Sep 17 00:00:00 2001 From: Dmytro Haidashenko Date: Wed, 2 Sep 2026 18:44:11 +0200 Subject: [PATCH 1/2] Enable beholder metrics for sqlutil --- pkg/sqlutil/beholder_metrics.go | 55 +++++++++++++++++++++ pkg/sqlutil/monitor.go | 5 +- pkg/sqlutil/pg/beholder_metrics.go | 77 ++++++++++++++++++++++++++++++ pkg/sqlutil/pg/stats.go | 35 +++++++++----- 4 files changed, 158 insertions(+), 14 deletions(-) create mode 100644 pkg/sqlutil/beholder_metrics.go create mode 100644 pkg/sqlutil/pg/beholder_metrics.go diff --git a/pkg/sqlutil/beholder_metrics.go b/pkg/sqlutil/beholder_metrics.go new file mode 100644 index 0000000000..cb26679ddc --- /dev/null +++ b/pkg/sqlutil/beholder_metrics.go @@ -0,0 +1,55 @@ +package sqlutil + +import ( + "context" + "sync" + + "go.opentelemetry.io/otel/metric" + + "github.com/smartcontractkit/chainlink-common/pkg/beholder" + "github.com/smartcontractkit/chainlink-common/pkg/logger" +) + +// sqlQueryTimeMetric records SQL query time as a percentage of timeout, duplicating [PromSQLQueryTime] +// as an OTel histogram via the Beholder meter. +type sqlQueryTimeMetric interface { + Record(ctx context.Context, pct float64) +} + +type beholderSQLQueryTimeMetric struct { + histogram metric.Float64Histogram +} + +func newSQLQueryTimeMetric(lggr logger.Logger) sqlQueryTimeMetric { + histogram, err := beholder.GetMeter().Float64Histogram( + "sql_query_timeout_percent", + metric.WithDescription("SQL query time as a percentage of timeout."), + metric.WithUnit("1"), + metric.WithExplicitBucketBoundaries(sqlQueryTimeBuckets...), + ) + if err != nil { + lggr.Errorw("Failed to create sql_query_timeout_percent beholder histogram; disabling beholder SQL query time metric", "err", err) + return noopSQLQueryTimeMetric{} + } + return &beholderSQLQueryTimeMetric{histogram: histogram} +} + +func (m *beholderSQLQueryTimeMetric) Record(ctx context.Context, pct float64) { + m.histogram.Record(ctx, pct) +} + +type noopSQLQueryTimeMetric struct{} + +func (noopSQLQueryTimeMetric) Record(context.Context, float64) {} + +var ( + sqlQueryTimeMetricOnce sync.Once + globalSQLQueryTimeMetric sqlQueryTimeMetric +) + +func getSQLQueryTimeMetric(lggr logger.Logger) sqlQueryTimeMetric { + sqlQueryTimeMetricOnce.Do(func() { + globalSQLQueryTimeMetric = newSQLQueryTimeMetric(lggr) + }) + return globalSQLQueryTimeMetric +} diff --git a/pkg/sqlutil/monitor.go b/pkg/sqlutil/monitor.go index 1660c2857d..3c9b853929 100644 --- a/pkg/sqlutil/monitor.go +++ b/pkg/sqlutil/monitor.go @@ -19,11 +19,13 @@ import ( const slowMsg = "SLOW SQL QUERY" +var sqlQueryTimeBuckets = []float64{10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120} + // PromSQLQueryTime is exported temporarily while transitioning the core ORMs. var PromSQLQueryTime = promauto.NewHistogram(prometheus.HistogramOpts{ Name: "sql_query_timeout_percent", Help: "SQL query time as a percentage of timeout.", - Buckets: []float64{10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120}, + Buckets: sqlQueryTimeBuckets, }) // MonitorHook returns a [QueryHook] that measures the timing of each query and logs about slow queries at increasing levels of severity. @@ -172,6 +174,7 @@ func (q *queryLogger) logTiming(ctx context.Context, start time.Time) { } PromSQLQueryTime.Observe(pct) + getSQLQueryTimeMetric(q.lggr).Record(ctx, pct) } // LogThresholds holds funcs for computing thresholds for timeout usage. diff --git a/pkg/sqlutil/pg/beholder_metrics.go b/pkg/sqlutil/pg/beholder_metrics.go new file mode 100644 index 0000000000..ebd38a908c --- /dev/null +++ b/pkg/sqlutil/pg/beholder_metrics.go @@ -0,0 +1,77 @@ +package pg + +import ( + "context" + "database/sql" + + "go.opentelemetry.io/otel/metric" + "go.opentelemetry.io/otel/metric/noop" + + "github.com/smartcontractkit/chainlink-common/pkg/beholder" + "github.com/smartcontractkit/chainlink-common/pkg/logger" +) + +type dbStatsBeholderMetrics struct { + connsMax metric.Int64Gauge + connsOpen metric.Int64Gauge + connsInUse metric.Int64Gauge + waitCount metric.Int64Gauge + waitDuration metric.Float64Gauge +} + +func newDBStatsBeholderMetrics(lggr logger.Logger) *dbStatsBeholderMetrics { + meter := beholder.GetMeter() + m := &dbStatsBeholderMetrics{ + connsMax: noop.Int64Gauge{}, + connsOpen: noop.Int64Gauge{}, + connsInUse: noop.Int64Gauge{}, + waitCount: noop.Int64Gauge{}, + waitDuration: noop.Float64Gauge{}, + } + + if g, err := meter.Int64Gauge("db_conns_max", + metric.WithDescription("Maximum number of open connections to the database.")); err != nil { + lggr.Errorw("Failed to create db_conns_max beholder gauge", "err", err) + } else { + m.connsMax = g + } + + if g, err := meter.Int64Gauge("db_conns_open", + metric.WithDescription("The number of established connections both in use and idle.")); err != nil { + lggr.Errorw("Failed to create db_conns_open beholder gauge", "err", err) + } else { + m.connsOpen = g + } + + if g, err := meter.Int64Gauge("db_conns_used", + metric.WithDescription("The number of connections currently in use.")); err != nil { + lggr.Errorw("Failed to create db_conns_used beholder gauge", "err", err) + } else { + m.connsInUse = g + } + + if g, err := meter.Int64Gauge("db_wait_count", + metric.WithDescription("The total number of connections waited for.")); err != nil { + lggr.Errorw("Failed to create db_wait_count beholder gauge", "err", err) + } else { + m.waitCount = g + } + + if g, err := meter.Float64Gauge("db_wait_time_seconds", + metric.WithDescription("The total time blocked waiting for a new connection."), + metric.WithUnit("s")); err != nil { + lggr.Errorw("Failed to create db_wait_time_seconds beholder gauge", "err", err) + } else { + m.waitDuration = g + } + + return m +} + +func (m *dbStatsBeholderMetrics) record(ctx context.Context, stats sql.DBStats) { + m.connsMax.Record(ctx, int64(stats.MaxOpenConnections)) + m.connsOpen.Record(ctx, int64(stats.OpenConnections)) + m.connsInUse.Record(ctx, int64(stats.InUse)) + m.waitCount.Record(ctx, stats.WaitCount) + m.waitDuration.Record(ctx, stats.WaitDuration.Seconds()) +} diff --git a/pkg/sqlutil/pg/stats.go b/pkg/sqlutil/pg/stats.go index 685304e2be..8a9ca3c1c9 100644 --- a/pkg/sqlutil/pg/stats.go +++ b/pkg/sqlutil/pg/stats.go @@ -66,21 +66,24 @@ type ( ) type StatsReporter struct { - statFn StatFn - reportFn ReportFn - interval time.Duration - cancel context.CancelFunc - lggr logger.Logger - once sync.Once - wg sync.WaitGroup + statFn StatFn + reportFn ReportFn + beholderMetrics *dbStatsBeholderMetrics + interval time.Duration + cancel context.CancelFunc + lggr logger.Logger + once sync.Once + wg sync.WaitGroup } func NewStatsReporter(fn StatFn, lggr logger.Logger, opts ...StatsReporterOpt) *StatsReporter { + namedLggr := logger.Named(lggr, "StatsReporter") r := &StatsReporter{ - statFn: fn, - reportFn: publishStats, - interval: dbStatsInternal, - lggr: logger.Named(lggr, "StatsReporter"), + statFn: fn, + reportFn: publishStats, + beholderMetrics: newDBStatsBeholderMetrics(namedLggr), + interval: dbStatsInternal, + lggr: namedLggr, } for _, opt := range opts { @@ -119,14 +122,20 @@ func (r *StatsReporter) loop(ctx context.Context) { ticker := time.NewTicker(r.interval) defer ticker.Stop() - r.reportFn(r.statFn()) + r.report(ctx) for { select { case <-ticker.C: - r.reportFn(r.statFn()) + r.report(ctx) case <-ctx.Done(): r.lggr.Debug("stat reporter loop received done. stopping...") return } } } + +func (r *StatsReporter) report(ctx context.Context) { + stats := r.statFn() + r.reportFn(stats) + r.beholderMetrics.record(ctx, stats) +} From 44e0e951e4470fb02d5033cf3855d82ea2d31fd3 Mon Sep 17 00:00:00 2001 From: Dmytro Haidashenko Date: Wed, 2 Sep 2026 19:49:33 +0200 Subject: [PATCH 2/2] force-ci