From 60bf1db8e19761d798ae3434c99759e18e8d814d Mon Sep 17 00:00:00 2001 From: Roland Bracewell Shoemaker Date: Tue, 23 Aug 2016 10:58:16 -0700 Subject: [PATCH] Profile the nonce service (#2135) Adds `NonceService` metrics output. --- nonce/nonce.go | 16 +++++++++++++++- nonce/nonce_test.go | 17 +++++++++-------- wfe/wfe.go | 4 +++- 3 files changed, 27 insertions(+), 10 deletions(-) diff --git a/nonce/nonce.go b/nonce/nonce.go index 90655ca4d..63268a179 100644 --- a/nonce/nonce.go +++ b/nonce/nonce.go @@ -8,6 +8,9 @@ import ( "errors" "math/big" "sync" + "time" + + "github.com/letsencrypt/boulder/metrics" ) // MaxUsed defines the maximum number of Nonces we're willing to hold in @@ -25,10 +28,11 @@ type NonceService struct { used map[int64]bool gcm cipher.AEAD maxUsed int + stats metrics.Scope } // NewNonceService constructs a NonceService with defaults -func NewNonceService() (*NonceService, error) { +func NewNonceService(parent metrics.Scope) (*NonceService, error) { key := make([]byte, 16) if _, err := rand.Read(key); err != nil { return nil, err @@ -49,6 +53,7 @@ func NewNonceService() (*NonceService, error) { used: make(map[int64]bool, MaxUsed), gcm: gcm, maxUsed: MaxUsed, + stats: parent.NewScope("NonceService"), }, nil } @@ -107,18 +112,21 @@ func (ns *NonceService) Nonce() (string, error) { ns.latest++ latest := ns.latest ns.mu.Unlock() + defer ns.stats.Inc("Generated", 1) return ns.encrypt(latest) } // minUsed returns the lowest key in the used map. Requires that a lock be held // by caller. func (ns *NonceService) minUsed() int64 { + s := time.Now() min := ns.latest for t := range ns.used { if t < min { min = t } } + ns.stats.TimingDuration("LinearScan.Latency", time.Since(s)) return min } @@ -127,28 +135,34 @@ func (ns *NonceService) minUsed() int64 { func (ns *NonceService) Valid(nonce string) bool { c, err := ns.decrypt(nonce) if err != nil { + ns.stats.Inc("Invalid.Decrypt", 1) return false } ns.mu.Lock() defer ns.mu.Unlock() if c > ns.latest { + ns.stats.Inc("Invalid.TooHigh", 1) return false } if c <= ns.earliest { + ns.stats.Inc("Invalid.TooLow", 1) return false } if ns.used[c] { + ns.stats.Inc("Invalid.AlreadyUsed", 1) return false } ns.used[c] = true if len(ns.used) > ns.maxUsed { + ns.stats.Inc("LinearScan.Full", 1) ns.earliest = ns.minUsed() delete(ns.used, ns.earliest) } + ns.stats.Inc("Valid", 1) return true } diff --git a/nonce/nonce_test.go b/nonce/nonce_test.go index 9d407e280..6b4d37999 100644 --- a/nonce/nonce_test.go +++ b/nonce/nonce_test.go @@ -4,11 +4,12 @@ import ( "fmt" "testing" + "github.com/letsencrypt/boulder/metrics" "github.com/letsencrypt/boulder/test" ) func TestValidNonce(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") n, err := ns.Nonce() test.AssertNotError(t, err, "Could not create nonce") @@ -16,7 +17,7 @@ func TestValidNonce(t *testing.T) { } func TestAlreadyUsed(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") n, err := ns.Nonce() test.AssertNotError(t, err, "Could not create nonce") @@ -25,7 +26,7 @@ func TestAlreadyUsed(t *testing.T) { } func TestRejectMalformed(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") n, err := ns.Nonce() test.AssertNotError(t, err, "Could not create nonce") @@ -33,15 +34,15 @@ func TestRejectMalformed(t *testing.T) { } func TestRejectShort(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") test.Assert(t, !ns.Valid("aGkK"), "Accepted an invalid nonce") } func TestRejectUnknown(t *testing.T) { - ns1, err := NewNonceService() + ns1, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") - ns2, err := NewNonceService() + ns2, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") n, err := ns1.Nonce() @@ -50,7 +51,7 @@ func TestRejectUnknown(t *testing.T) { } func TestRejectTooLate(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") ns.latest = 2 @@ -61,7 +62,7 @@ func TestRejectTooLate(t *testing.T) { } func TestRejectTooEarly(t *testing.T) { - ns, err := NewNonceService() + ns, err := NewNonceService(metrics.NewNoopScope()) test.AssertNotError(t, err, "Could not create nonce service") ns.maxUsed = 2 diff --git a/wfe/wfe.go b/wfe/wfe.go index b926c83cf..8b153ebce 100644 --- a/wfe/wfe.go +++ b/wfe/wfe.go @@ -23,6 +23,7 @@ import ( "github.com/letsencrypt/boulder/core" "github.com/letsencrypt/boulder/goodkey" blog "github.com/letsencrypt/boulder/log" + "github.com/letsencrypt/boulder/metrics" "github.com/letsencrypt/boulder/nonce" "github.com/letsencrypt/boulder/probs" "github.com/letsencrypt/boulder/revocation" @@ -95,7 +96,8 @@ func NewWebFrontEndImpl( keyPolicy goodkey.KeyPolicy, logger blog.Logger, ) (WebFrontEndImpl, error) { - nonceService, err := nonce.NewNonceService() + scope := metrics.NewStatsdScope(stats, "WFE") + nonceService, err := nonce.NewNonceService(scope) if err != nil { return WebFrontEndImpl{}, err }