Add histogram support for acquire duration

go.mod

@@ -3,12 +3,23 @@ module github.com/jackc/puddle/v2
 go 1.19
 
 require (
-	github.com/stretchr/testify v1.8.1
-	golang.org/x/sync v0.1.0
+	github.com/prometheus/client_golang v1.17.0
+	github.com/stretchr/testify v1.8.4
+	golang.org/x/sync v0.5.0
 )
 
 require (
+	github.com/beorn7/perks v1.0.1 // indirect
+	github.com/cespare/xxhash/v2 v2.2.0 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
+	github.com/golang/protobuf v1.5.3 // indirect
+	github.com/kr/text v0.2.0 // indirect
+	github.com/matttproud/golang_protobuf_extensions v1.0.4 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
+	github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16 // indirect
+	github.com/prometheus/common v0.44.0 // indirect
+	github.com/prometheus/procfs v0.11.1 // indirect
+	golang.org/x/sys v0.11.0 // indirect
+	google.golang.org/protobuf v1.31.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 )

go.sum

@@ -1,19 +1,45 @@
-github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
+github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
+github.com/cespare/xxhash/v2 v2.2.0 h1:DC2CZ1Ep5Y4k3ZQ899DldepgrayRUGE6BBZ/cd9Cj44=
+github.com/cespare/xxhash/v2 v2.2.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
+github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
+github.com/golang/protobuf v1.5.0/go.mod h1:FsONVRAS9T7sI+LIUmWTfcYkHO4aIWwzhcaSAoJOfIk=
+github.com/golang/protobuf v1.5.3 h1:KhyjKVUg7Usr/dYsdSqoFveMYd5ko72D+zANwlG1mmg=
+github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY=
+github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
+github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
+github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE=
+github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
+github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
+github.com/matttproud/golang_protobuf_extensions v1.0.4 h1:mmDVorXM7PCGKw94cs5zkfA9PSy5pEvNWRP0ET0TIVo=
+github.com/matttproud/golang_protobuf_extensions v1.0.4/go.mod h1:BSXmuO+STAnVfrANrmjBb36TMTDstsz7MSK+HVaYKv4=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
-github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
-github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
-github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
-github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
-github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
-github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
-golang.org/x/sync v0.1.0 h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
-golang.org/x/sync v0.1.0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
-gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
+github.com/prometheus/client_golang v1.17.0 h1:rl2sfwZMtSthVU752MqfjQozy7blglC+1SOtjMAMh+Q=
+github.com/prometheus/client_golang v1.17.0/go.mod h1:VeL+gMmOAxkS2IqfCq0ZmHSL+LjWfWDUmp1mBz9JgUY=
+github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16 h1:v7DLqVdK4VrYkVD5diGdl4sxJurKJEMnODWRJlxV9oM=
+github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16/go.mod h1:oMQmHW1/JoDwqLtg57MGgP/Fb1CJEYF2imWWhWtMkYU=
+github.com/prometheus/common v0.44.0 h1:+5BrQJwiBB9xsMygAB3TNvpQKOwlkc25LbISbrdOOfY=
+github.com/prometheus/common v0.44.0/go.mod h1:ofAIvZbQ1e/nugmZGz4/qCb9Ap1VoSTIO7x0VV9VvuY=
+github.com/prometheus/procfs v0.11.1 h1:xRC8Iq1yyca5ypa9n1EZnWZkt7dwcoRPQwX/5gwaUuI=
+github.com/prometheus/procfs v0.11.1/go.mod h1:eesXgaPo1q7lBpVMoMy0ZOFTth9hBn4W/y0/p/ScXhY=
+github.com/rogpeppe/go-internal v1.10.0 h1:TMyTOH3F/DB16zRVcYyreMH6GnZZrwQVAoYjRBZyWFQ=
+github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk=
+github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo=
+golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.5.0 h1:60k92dhOjHxJkrqnwsfl8KuaHbn/5dl0lUPUklKo3qE=
+golang.org/x/sync v0.5.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk=
+golang.org/x/sys v0.11.0 h1:eG7RXZHdqOJ1i+0lgLgCpSXAp6M3LYlAo6osgSi0xOM=
+golang.org/x/sys v0.11.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp09yW+WbY/TyQbw=
+google.golang.org/protobuf v1.26.0/go.mod h1:9q0QmTI4eRPtz6boOQmLYwt+qCgq0jsYwAQnmE0givc=
+google.golang.org/protobuf v1.31.0 h1:g0LDEJHgrBl9N9r17Ru3sqWhkIx2NB67okBHPwC7hs8=
+google.golang.org/protobuf v1.31.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
-gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
+gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk=
 gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
 gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

metrics.go

@@ -0,0 +1,87 @@
+package puddle
+
+import (
+	"strconv"
+	"sync/atomic"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+// Metrics hold puddle metrics.
+type Metrics struct {
+	acquireCount         int64
+	acquireDuration      time.Duration
+	emptyAcquireCount    int64
+	canceledAcquireCount atomic.Int64
+	// acquireDurationHistogram can be nil
+	acquireDurationHistogram *prometheus.HistogramVec
+}
+
+func NewMetrics(opts ...MetricsOption) *Metrics {
+	var m Metrics
+	for _, o := range opts {
+		o(&m)
+	}
+	return &m
+}
+
+func (m *Metrics) observeAcquireDuration(d time.Duration, isEmptyAcquire bool) {
+	m.acquireCount++
+	m.acquireDuration += d
+	if isEmptyAcquire {
+		m.emptyAcquireCount++
+	}
+
+	if m.acquireDurationHistogram != nil {
+		m.acquireDurationHistogram.
+			WithLabelValues(strconv.FormatBool(isEmptyAcquire)).
+			Observe(float64(d.Nanoseconds()))
+	}
+}
+
+func (m *Metrics) observeAcquireCancel() {
+	m.canceledAcquireCount.Add(1)
+}
+
+type MetricsOption func(m *Metrics)
+
+// WithAcquireDurationHistogram turns on recording of pool resource acquire duration.
+// Histogram metrics can be very expensive for Prometheus to retain and query.
+func WithAcquireDurationHistogram(reg prometheus.Registerer, opts ...HistogramOption) MetricsOption {
+	return func(m *Metrics) {
+		histOpts := prometheus.HistogramOpts{
+			Name:    "puddle_acquire_duration_nanoseconds",
+			Help:    "Histogram of a pool resource acquire duration (nanoseconds).",
+			Buckets: prometheus.DefBuckets,
+		}
+		for _, o := range opts {
+			o(&histOpts)
+		}
+
+		m.acquireDurationHistogram = prometheus.NewHistogramVec(histOpts, []string{"empty"})
+		reg.MustRegister(m.acquireDurationHistogram)
+	}
+}
+
+// A HistogramOption lets you add options to Histogram metrics using With* funcs.
+type HistogramOption func(*prometheus.HistogramOpts)
+
+// WithHistogramBuckets allows you to specify custom bucket ranges for histograms.
+func WithHistogramBuckets(buckets []float64) HistogramOption {
+	return func(o *prometheus.HistogramOpts) { o.Buckets = buckets }
+}
+
+// WithHistogramConstLabels allows you to add custom ConstLabels to histograms metrics.
+func WithHistogramConstLabels(labels prometheus.Labels) HistogramOption {
+	return func(o *prometheus.HistogramOpts) {
+		o.ConstLabels = labels
+	}
+}
+
+// WithHistogramSubsystem allows you to add a Subsystem to histograms metrics.
+func WithHistogramSubsystem(subsystem string) HistogramOption {
+	return func(o *prometheus.HistogramOpts) {
+		o.Subsystem = subsystem
+	}
+}

pool.go

@@ -4,11 +4,11 @@ import (
 	"context"
 	"errors"
 	"sync"
-	"sync/atomic"
 	"time"
 
-	"github.com/jackc/puddle/v2/internal/genstack"
 	"golang.org/x/sync/semaphore"
+
+	"github.com/jackc/puddle/v2/internal/genstack"
 )
 
 const (
@@ -132,15 +132,12 @@ type Pool[T any] struct {
 	allResources  resList[T]
 	idleResources *genstack.GenStack[*Resource[T]]
 
+	metrics *Metrics
+
 	constructor Constructor[T]
 	destructor  Destructor[T]
 	maxSize     int32
 
-	acquireCount         int64
-	acquireDuration      time.Duration
-	emptyAcquireCount    int64
-	canceledAcquireCount atomic.Int64
-
 	resetCount int
 
 	baseAcquireCtx       context.Context
@@ -149,6 +146,7 @@ type Pool[T any] struct {
 }
 
 type Config[T any] struct {
+	Metrics     *Metrics
 	Constructor Constructor[T]
 	Destructor  Destructor[T]
 	MaxSize     int32
@@ -160,17 +158,22 @@ func NewPool[T any](config *Config[T]) (*Pool[T], error) {
 		return nil, errors.New("MaxSize must be >= 1")
 	}
 
-	baseAcquireCtx, cancelBaseAcquireCtx := context.WithCancel(context.Background())
+	p := &Pool[T]{
+		acquireSem:    semaphore.NewWeighted(int64(config.MaxSize)),
+		idleResources: genstack.NewGenStack[*Resource[T]](),
+		maxSize:       config.MaxSize,
+		constructor:   config.Constructor,
+		destructor:    config.Destructor,
+		metrics:       config.Metrics,
+	}
+
+	p.baseAcquireCtx, p.cancelBaseAcquireCtx = context.WithCancel(context.Background())
 
-	return &Pool[T]{
-		acquireSem:           semaphore.NewWeighted(int64(config.MaxSize)),
-		idleResources:        genstack.NewGenStack[*Resource[T]](),
-		maxSize:              config.MaxSize,
-		constructor:          config.Constructor,
-		destructor:           config.Destructor,
-		baseAcquireCtx:       baseAcquireCtx,
-		cancelBaseAcquireCtx: cancelBaseAcquireCtx,
-	}, nil
+	if p.metrics == nil {
+		p.metrics = NewMetrics()
+	}
+
+	return p, nil
 }
 
 // Close destroys all resources in the pool and rejects future Acquire calls.
@@ -264,10 +267,10 @@ func (p *Pool[T]) Stat() *Stat {
 
 	s := &Stat{
 		maxResources:         p.maxSize,
-		acquireCount:         p.acquireCount,
-		emptyAcquireCount:    p.emptyAcquireCount,
-		canceledAcquireCount: p.canceledAcquireCount.Load(),
-		acquireDuration:      p.acquireDuration,
+		acquireCount:         p.metrics.acquireCount,
+		emptyAcquireCount:    p.metrics.emptyAcquireCount,
+		canceledAcquireCount: p.metrics.canceledAcquireCount.Load(),
+		acquireDuration:      p.metrics.acquireDuration,
 	}
 
 	for _, res := range p.allResources {
@@ -329,7 +332,7 @@ func (p *Pool[T]) createNewResource() *Resource[T] {
 func (p *Pool[T]) Acquire(ctx context.Context) (_ *Resource[T], err error) {
 	select {
 	case <-ctx.Done():
-		p.canceledAcquireCount.Add(1)
+		p.metrics.observeAcquireCancel()
 		return nil, ctx.Err()
 	default:
 	}
@@ -349,7 +352,7 @@ func (p *Pool[T]) acquire(ctx context.Context) (*Resource[T], error) {
 		waitedForLock = true
 		err := p.acquireSem.Acquire(ctx, 1)
 		if err != nil {
-			p.canceledAcquireCount.Add(1)
+			p.metrics.observeAcquireCancel()
 			return nil, err
 		}
 	}
@@ -363,11 +366,8 @@ func (p *Pool[T]) acquire(ctx context.Context) (*Resource[T], error) {
 
 	// If a resource is available in the pool.
 	if res := p.tryAcquireIdleResource(); res != nil {
-		if waitedForLock {
-			p.emptyAcquireCount += 1
-		}
-		p.acquireCount += 1
-		p.acquireDuration += time.Duration(nanotime() - startNano)
+		d := time.Duration(nanotime() - startNano)
+		p.metrics.observeAcquireDuration(d, waitedForLock)
 		p.mux.Unlock()
 		return res, nil
 	}
@@ -389,9 +389,8 @@ func (p *Pool[T]) acquire(ctx context.Context) (*Resource[T], error) {
 	p.mux.Lock()
 	defer p.mux.Unlock()
 
-	p.emptyAcquireCount += 1
-	p.acquireCount += 1
-	p.acquireDuration += time.Duration(nanotime() - startNano)
+	d := time.Duration(nanotime() - startNano)
+	p.metrics.observeAcquireDuration(d, true)
 
 	return res, nil
 }
@@ -444,7 +443,7 @@ func (p *Pool[T]) initResourceValue(ctx context.Context, res *Resource[T]) (*Res
 
 	select {
 	case <-ctx.Done():
-		p.canceledAcquireCount.Add(1)
+		p.metrics.observeAcquireCancel()
 		return nil, ctx.Err()
 	case err := <-constructErrChan:
 		if err != nil {
@@ -472,7 +471,7 @@ func (p *Pool[T]) TryAcquire(ctx context.Context) (*Resource[T], error) {
 
 	// If a resource is available now
 	if res := p.tryAcquireIdleResource(); res != nil {
-		p.acquireCount += 1
+		p.metrics.observeAcquireDuration(0, false)
 		return res, nil
 	}