From d3964763bb01ab855940fcf599bf88e8ba089ba5 Mon Sep 17 00:00:00 2001
From: Jack Christensen <jack@jackchristensen.com>
Date: Wed, 26 Dec 2018 15:25:14 -0600
Subject: [PATCH] Track successful acquire duration

Rename slow acquire to empty acquire to be more clear that it means the
pool was empty on acquire, not that it took some large amount of time.
---
 pool.go      | 40 +++++++++++++++++++++++++++-------------
 pool_test.go | 12 +++++++++---
 2 files changed, 36 insertions(+), 16 deletions(-)

diff --git a/pool.go b/pool.go
index 2da88a7..6a015a8 100644
--- a/pool.go
+++ b/pool.go
@@ -4,6 +4,7 @@ import (
 	"context"
 	"errors"
 	"sync"
+	"time"
 )
 
 const (
@@ -65,7 +66,8 @@ type Pool struct {
 	maxSize     int
 
 	acquireCount         int64
-	slowAcquireCount     int64
+	acquireDuration      time.Duration
+	emptyAcquireCount    int64
 	canceledAcquireCount int64
 
 	closed bool
@@ -106,7 +108,8 @@ type Stat struct {
 	idleResources         int
 	maxResources          int
 	acquireCount          int64
-	slowAcquireCount      int64
+	acquireDuration       time.Duration
+	emptyAcquireCount     int64
 	canceledAcquireCount  int64
 }
 
@@ -141,10 +144,17 @@ func (s *Stat) AcquireCount() int64 {
 	return s.acquireCount
 }
 
-// SlowAcquireCount returns the number of successful acquires from the pool
-// that waited for a resource to be released or constructed.
-func (s *Stat) SlowAcquireCount() int64 {
-	return s.slowAcquireCount
+// AcquireDuration returns the total duration of all successful acquires from
+// the pool.
+func (s *Stat) AcquireDuration() time.Duration {
+	return s.acquireDuration
+}
+
+// EmptyAcquireCount returns the number of successful acquires from the pool
+// that waited for a resource to be released or constructed because the pool was
+// empty.
+func (s *Stat) EmptyAcquireCount() int64 {
+	return s.emptyAcquireCount
 }
 
 // CanceledAcquireCount returns the number of acquires from the pool
@@ -159,8 +169,9 @@ func (p *Pool) Stat() *Stat {
 	s := &Stat{
 		maxResources:         p.maxSize,
 		acquireCount:         p.acquireCount,
-		slowAcquireCount:     p.slowAcquireCount,
+		emptyAcquireCount:    p.emptyAcquireCount,
 		canceledAcquireCount: p.canceledAcquireCount,
+		acquireDuration:      p.acquireDuration,
 	}
 
 	for _, res := range p.allResources {
@@ -183,6 +194,7 @@ func (p *Pool) Stat() *Stat {
 // maximum capacity it will block until a resource is available. ctx can be used
 // to cancel the Acquire.
 func (p *Pool) Acquire(ctx context.Context) (*Resource, error) {
+	startTime := time.Now()
 	p.cond.L.Lock()
 	if doneChan := ctx.Done(); doneChan != nil {
 		select {
@@ -194,7 +206,7 @@ func (p *Pool) Acquire(ctx context.Context) (*Resource, error) {
 		}
 	}
 
-	slowAcquire := false
+	emptyAcquire := false
 
 	for {
 		if p.closed {
@@ -207,15 +219,16 @@ func (p *Pool) Acquire(ctx context.Context) (*Resource, error) {
 			res := p.idleResources[len(p.idleResources)-1]
 			p.idleResources = p.idleResources[:len(p.idleResources)-1]
 			res.status = resourceStatusAcquired
-			p.acquireCount += 1
-			if slowAcquire {
-				p.slowAcquireCount += 1
+			if emptyAcquire {
+				p.emptyAcquireCount += 1
 			}
+			p.acquireCount += 1
+			p.acquireDuration += time.Now().Sub(startTime)
 			p.cond.L.Unlock()
 			return res, nil
 		}
 
-		slowAcquire = true
+		emptyAcquire = true
 
 		// If there is room to create a resource do so
 		if len(p.allResources) < p.maxSize {
@@ -244,8 +257,9 @@ func (p *Pool) Acquire(ctx context.Context) (*Resource, error) {
 
 			res.value = value
 			res.status = resourceStatusAcquired
+			p.emptyAcquireCount += 1
 			p.acquireCount += 1
-			p.slowAcquireCount += 1
+			p.acquireDuration += time.Now().Sub(startTime)
 			p.cond.L.Unlock()
 			return res, nil
 		}
diff --git a/pool_test.go b/pool_test.go
index d9a7425..493856a 100644
--- a/pool_test.go
+++ b/pool_test.go
@@ -321,7 +321,9 @@ func TestPoolStatSuccessfulAcquireCounters(t *testing.T) {
 
 	stat := pool.Stat()
 	assert.Equal(t, int64(1), stat.AcquireCount())
-	assert.Equal(t, int64(1), stat.SlowAcquireCount())
+	assert.Equal(t, int64(1), stat.EmptyAcquireCount())
+	assert.True(t, stat.AcquireDuration() > 0, "expected stat.AcquireDuration() > 0 but %v", stat.AcquireDuration())
+	lastAcquireDuration := stat.AcquireDuration()
 
 	res, err = pool.Acquire(context.Background())
 	require.NoError(t, err)
@@ -329,7 +331,9 @@ func TestPoolStatSuccessfulAcquireCounters(t *testing.T) {
 
 	stat = pool.Stat()
 	assert.Equal(t, int64(2), stat.AcquireCount())
-	assert.Equal(t, int64(1), stat.SlowAcquireCount())
+	assert.Equal(t, int64(1), stat.EmptyAcquireCount())
+	assert.True(t, stat.AcquireDuration() > lastAcquireDuration)
+	lastAcquireDuration = stat.AcquireDuration()
 
 	wg := &sync.WaitGroup{}
 	for i := 0; i < 2; i++ {
@@ -347,7 +351,9 @@ func TestPoolStatSuccessfulAcquireCounters(t *testing.T) {
 
 	stat = pool.Stat()
 	assert.Equal(t, int64(4), stat.AcquireCount())
-	assert.Equal(t, int64(2), stat.SlowAcquireCount())
+	assert.Equal(t, int64(2), stat.EmptyAcquireCount())
+	assert.True(t, stat.AcquireDuration() > lastAcquireDuration)
+	lastAcquireDuration = stat.AcquireDuration()
 }
 
 func TestPoolStatCanceledAcquireBeforeStart(t *testing.T) {