collectors: add startup time metrics

collectors/prometheus.go

@@ -6,6 +6,7 @@ import (
 	"net/http"
 	"os"
 	"path/filepath"
+	"time"
 
 	"github.com/btcsuite/btcd/btcutil"
 	"github.com/lightninglabs/lndclient"
@@ -70,6 +71,9 @@ type MonitoringConfig struct {
 
 	// DisableHtlc disables collection of HTLCs metrics
 	DisableHtlc bool
+
+	// ProgramStartTime stores a best-effort estimate of when lnd/lndmon was started.
+	ProgramStartTime time.Time
 }
 
 func DefaultConfig() *PrometheusConfig {
@@ -104,6 +108,7 @@ func NewPrometheusExporter(cfg *PrometheusConfig, lnd *lndclient.LndServices,
 		NewWalletCollector(lnd, errChan),
 		NewPeerCollector(lnd.Client, errChan),
 		NewInfoCollector(lnd.Client, errChan),
+		NewStateCollector(lnd, errChan, monitoringCfg.ProgramStartTime),
 	}
 
 	if !monitoringCfg.DisableHtlc {

collectors/state_collector.go

@@ -0,0 +1,131 @@
+package collectors
+
+import (
+	"context"
+	"fmt"
+	"sync"
+	"time"
+
+	"github.com/lightninglabs/lndclient"
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+// StateCollector is a collector that keeps track of LND's state.
+type StateCollector struct {
+	lnd *lndclient.LndServices
+
+	// timeToStartDesc is a gauge to track time from unlocked to started of LND.
+	timeToStartDesc *prometheus.Desc
+
+	// timeToUnlockDesc is a gauge to track the time to unlock of LND.
+	timeToUnlockDesc *prometheus.Desc
+
+	// programStartTime records a best-effort timestamp of when lndmon was started.
+	programStartTime time.Time
+
+	// unlockTime records a best-effort timestamp of when LND was unlocked.
+	unlockTime time.Time
+
+	// endTime records when LND makes a transition from UNLOCKED to
+	// SERVER_ACTIVE.
+	// If lndmon starts after LND has already reached SERVER_ACTIVE, no
+	// startup time metric will be emitted.
+	endTime time.Time
+
+	// mutex is a lock for preventing concurrent writes to unlockTime or
+	// endTime.
+	mutex sync.RWMutex
+
+	// errChan is a channel that we send any errors that we encounter into.
+	// This channel should be buffered so that it does not block sends.
+	errChan chan<- error
+}
+
+// NewStateCollector returns a new instance of the StateCollector.
+func NewStateCollector(lnd *lndclient.LndServices,
+	errChan chan<- error, programStartTime time.Time) *StateCollector {
+
+	sc := &StateCollector{
+		lnd: lnd,
+		timeToStartDesc: prometheus.NewDesc(
+			"lnd_time_to_start_millisecs",
+			"time to start in milliseconds",
+			nil, nil,
+		),
+		timeToUnlockDesc: prometheus.NewDesc(
+			"lnd_time_to_unlock_millisecs",
+			"time to unlocked in milliseconds",
+			nil, nil,
+		),
+		programStartTime: programStartTime,
+		unlockTime:       time.Now(),
+		errChan:          errChan,
+	}
+
+	go sc.monitorStateChanges()
+	return sc
+}
+
+// monitorStateChanges checks the state every second to catch fast transitions.
+func (s *StateCollector) monitorStateChanges() {
+	var serverActiveReached bool
+
+	stateUpdates, errChan, err := s.lnd.State.SubscribeState(context.Background())
+	if err != nil {
+		s.errChan <- fmt.Errorf("StateCollector SubscribeState failed with: %v", err)
+		return
+	}
+
+	for {
+		select {
+		case state := <-stateUpdates:
+			s.mutex.Lock()
+			if state == lndclient.WalletStateServerActive && !s.unlockTime.IsZero() {
+				s.endTime = time.Now()
+				serverActiveReached = true
+			}
+			s.mutex.Unlock()
+
+			if serverActiveReached {
+				return
+			}
+
+		case err := <-errChan:
+			s.errChan <- fmt.Errorf("StateCollector state update failed with: %v", err)
+			return
+		}
+	}
+}
+
+// Describe sends the super-set of all possible descriptors of metrics
+// collected by this Collector to the provided channel and returns once the
+// last descriptor has been sent.
+//
+// NOTE: Part of the prometheus.Collector interface.
+func (s *StateCollector) Describe(ch chan<- *prometheus.Desc) {
+	ch <- s.timeToStartDesc
+	ch <- s.timeToUnlockDesc
+}
+
+// Collect is called by the Prometheus registry when collecting metrics.
+//
+// NOTE: Part of the prometheus.Collector interface.
+func (s *StateCollector) Collect(ch chan<- prometheus.Metric) {
+	// Lock for read
+	s.mutex.RLock()
+	defer s.mutex.RUnlock()
+
+	// We have set unlockTime and endTime.
+	// Calculate the differences and emit a metric.
+	if !s.unlockTime.IsZero() && !s.endTime.IsZero() {
+		timeToUnlockInMSecs := s.unlockTime.Sub(s.programStartTime).Milliseconds()
+		timeToStartInMSecs := s.endTime.Sub(s.unlockTime).Milliseconds()
+		ch <- prometheus.MustNewConstMetric(
+			s.timeToStartDesc, prometheus.GaugeValue, float64(timeToStartInMSecs),
+		)
+
+		ch <- prometheus.MustNewConstMetric(
+			s.timeToUnlockDesc, prometheus.GaugeValue, float64(timeToUnlockInMSecs),
+		)
+	}
+}

go.mod

@@ -5,8 +5,8 @@ require (
 	github.com/btcsuite/btclog v0.0.0-20170628155309-84c8d2346e9f
 	github.com/jessevdk/go-flags v1.5.0
 	github.com/jrick/logrotate v1.0.0
-	github.com/lightninglabs/lndclient v0.17.0-4
-	github.com/lightningnetwork/lnd v0.17.3-beta
+	github.com/lightninglabs/lndclient v0.17.4-4
+	github.com/lightningnetwork/lnd v0.17.4-beta
 	github.com/prometheus/client_golang v1.18.0
 	github.com/stretchr/testify v1.8.4
 )
@@ -16,11 +16,11 @@ require (
 	github.com/aead/siphash v1.0.1 // indirect
 	github.com/andybalholm/brotli v1.0.3 // indirect
 	github.com/beorn7/perks v1.0.1 // indirect
-	github.com/btcsuite/btcd v0.23.5-0.20231215221805-96c9fd8078fd // indirect
+	github.com/btcsuite/btcd v0.24.1-0.20240123000108-62e6af035ec5 // indirect
 	github.com/btcsuite/btcd/btcec/v2 v2.3.2 // indirect
 	github.com/btcsuite/btcd/btcutil/psbt v1.1.8 // indirect
 	github.com/btcsuite/btcd/chaincfg/chainhash v1.1.0 // indirect
-	github.com/btcsuite/btcwallet v0.16.10-0.20231129183218-5df09dd43358 // indirect
+	github.com/btcsuite/btcwallet v0.16.10-0.20240127010340-16b422a2e8bf // indirect
 	github.com/btcsuite/btcwallet/wallet/txauthor v1.3.2 // indirect
 	github.com/btcsuite/btcwallet/wallet/txrules v1.2.0 // indirect
 	github.com/btcsuite/btcwallet/wallet/txsizes v1.2.3 // indirect
@@ -42,26 +42,28 @@ require (
 	github.com/dustin/go-humanize v1.0.0 // indirect
 	github.com/fergusstrange/embedded-postgres v1.10.0 // indirect
 	github.com/go-errors/errors v1.0.1 // indirect
+	github.com/go-logr/logr v1.3.0 // indirect
+	github.com/go-logr/stdr v1.2.2 // indirect
 	github.com/gogo/protobuf v1.3.2 // indirect
 	github.com/golang-jwt/jwt/v4 v4.4.2 // indirect
 	github.com/golang/protobuf v1.5.3 // indirect
 	github.com/golang/snappy v0.0.4 // indirect
 	github.com/google/btree v1.0.1 // indirect
-	github.com/google/uuid v1.3.0 // indirect
+	github.com/google/uuid v1.3.1 // indirect
 	github.com/gorilla/websocket v1.5.0 // indirect
 	github.com/grpc-ecosystem/go-grpc-middleware v1.3.0 // indirect
 	github.com/grpc-ecosystem/go-grpc-prometheus v1.2.0 // indirect
 	github.com/grpc-ecosystem/grpc-gateway v1.16.0 // indirect
 	github.com/grpc-ecosystem/grpc-gateway/v2 v2.5.0 // indirect
 	github.com/jackc/chunkreader/v2 v2.0.1 // indirect
-	github.com/jackc/pgconn v1.14.0 // indirect
+	github.com/jackc/pgconn v1.14.3 // indirect
 	github.com/jackc/pgerrcode v0.0.0-20220416144525-469b46aa5efa // indirect
 	github.com/jackc/pgio v1.0.0 // indirect
 	github.com/jackc/pgpassfile v1.0.0 // indirect
-	github.com/jackc/pgproto3/v2 v2.3.2 // indirect
+	github.com/jackc/pgproto3/v2 v2.3.3 // indirect
 	github.com/jackc/pgservicefile v0.0.0-20221227161230-091c0ba34f0a // indirect
 	github.com/jackc/pgtype v1.14.0 // indirect
-	github.com/jackc/pgx/v4 v4.18.1 // indirect
+	github.com/jackc/pgx/v4 v4.18.2 // indirect
 	github.com/jonboulle/clockwork v0.2.2 // indirect
 	github.com/json-iterator/go v1.1.12 // indirect
 	github.com/juju/loggo v0.0.0-20210728185423-eebad3a902c4 // indirect
@@ -114,28 +116,31 @@ require (
 	go.etcd.io/etcd/pkg/v3 v3.5.7 // indirect
 	go.etcd.io/etcd/raft/v3 v3.5.7 // indirect
 	go.etcd.io/etcd/server/v3 v3.5.7 // indirect
-	go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc v0.25.0 // indirect
-	go.opentelemetry.io/otel v1.0.1 // indirect
+	go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc v0.46.0 // indirect
+	go.opentelemetry.io/otel v1.20.0 // indirect
 	go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.0.1 // indirect
 	go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.0.1 // indirect
+	go.opentelemetry.io/otel/metric v1.20.0 // indirect
 	go.opentelemetry.io/otel/sdk v1.0.1 // indirect
-	go.opentelemetry.io/otel/trace v1.0.1 // indirect
+	go.opentelemetry.io/otel/trace v1.20.0 // indirect
 	go.opentelemetry.io/proto/otlp v0.9.0 // indirect
 	go.uber.org/atomic v1.7.0 // indirect
 	go.uber.org/multierr v1.6.0 // indirect
 	go.uber.org/zap v1.17.0 // indirect
-	golang.org/x/crypto v0.14.0 // indirect
+	golang.org/x/crypto v0.21.0 // indirect
 	golang.org/x/exp v0.0.0-20230315142452-642cacee5cc0 // indirect
 	golang.org/x/mod v0.10.0 // indirect
-	golang.org/x/net v0.17.0 // indirect
-	golang.org/x/sys v0.15.0 // indirect
-	golang.org/x/term v0.13.0 // indirect
-	golang.org/x/text v0.13.0 // indirect
+	golang.org/x/net v0.23.0 // indirect
+	golang.org/x/sys v0.18.0 // indirect
+	golang.org/x/term v0.18.0 // indirect
+	golang.org/x/text v0.14.0 // indirect
 	golang.org/x/time v0.0.0-20220224211638-0e9765cccd65 // indirect
 	golang.org/x/tools v0.9.1 // indirect
-	google.golang.org/genproto v0.0.0-20230410155749-daa745c078e1 // indirect
-	google.golang.org/grpc v1.56.3 // indirect
-	google.golang.org/protobuf v1.31.0 // indirect
+	google.golang.org/genproto v0.0.0-20230822172742-b8732ec3820d // indirect
+	google.golang.org/genproto/googleapis/api v0.0.0-20230822172742-b8732ec3820d // indirect
+	google.golang.org/genproto/googleapis/rpc v0.0.0-20230822172742-b8732ec3820d // indirect
+	google.golang.org/grpc v1.59.0 // indirect
+	google.golang.org/protobuf v1.33.0 // indirect
 	gopkg.in/errgo.v1 v1.0.1 // indirect
 	gopkg.in/macaroon-bakery.v2 v2.0.1 // indirect
 	gopkg.in/macaroon.v2 v2.1.0 // indirect