From 8adbfe92f73c7b2ecc0e183b952e599bc688f81b Mon Sep 17 00:00:00 2001
From: Rob Skillington <rob.skillington@gmail.com>
Date: Wed, 9 May 2018 08:24:14 -0400
Subject: [PATCH] Emit latency metric on both success and error for
 instrumented call (#75)

---
 instrument/call.go      | 14 +++++++-------
 instrument/call_test.go |  9 +++++++++
 2 files changed, 16 insertions(+), 7 deletions(-)

diff --git a/instrument/call.go b/instrument/call.go
index 527f3b85..470b9cb2 100644
--- a/instrument/call.go
+++ b/instrument/call.go
@@ -39,7 +39,7 @@ const (
 // {{name}}.latency
 func NewCall(scope tally.Scope, name string) Call {
 	return &call{
-		error:   scope.Tagged(map[string]string{resultType: resultTypeError}).Counter(name),
+		err:     scope.Tagged(map[string]string{resultType: resultTypeError}).Counter(name),
 		success: scope.Tagged(map[string]string{resultType: resultTypeSuccess}).Counter(name),
 		timing:  scope.SubScope(name).Timer(timingSuffix),
 	}
@@ -48,20 +48,20 @@ func NewCall(scope tally.Scope, name string) Call {
 type call struct {
 	scope   tally.Scope
 	success tally.Counter
-	error   tally.Counter
+	err     tally.Counter
 	timing  tally.Timer
 }
 
 func (c *call) Exec(f ExecFn) error {
 	sw := c.timing.Start()
+	err := f()
+	sw.Stop()
 
-	if err := f(); err != nil {
-		c.error.Inc(1.0)
+	if err != nil {
+		c.err.Inc(1)
 		return err
 	}
 
-	sw.Stop()
-	c.success.Inc(1.0)
-
+	c.success.Inc(1)
 	return nil
 }
diff --git a/instrument/call_test.go b/instrument/call_test.go
index b7a3bf7e..e64dedb4 100644
--- a/instrument/call_test.go
+++ b/instrument/call_test.go
@@ -23,6 +23,7 @@ package instrument
 import (
 	"errors"
 	"testing"
+	"time"
 
 	"github.com/uber-go/tally"
 
@@ -33,7 +34,9 @@ import (
 func TestCallSuccess(t *testing.T) {
 	s := tally.NewTestScope("", nil)
 
+	sleepFor := time.Microsecond
 	err := NewCall(s, "test_call").Exec(func() error {
+		time.Sleep(time.Microsecond)
 		return nil
 	})
 	assert.Nil(t, err)
@@ -46,13 +49,17 @@ func TestCallSuccess(t *testing.T) {
 	require.NotNil(t, timers["test_call.latency+"])
 
 	assert.Equal(t, int64(1), counters["test_call+result_type=success"].Value())
+	require.Equal(t, 1, len(timers["test_call.latency+"].Values()))
+	assert.True(t, timers["test_call.latency+"].Values()[0] >= sleepFor)
 }
 
 func TestCallFail(t *testing.T) {
 	s := tally.NewTestScope("", nil)
 
+	sleepFor := time.Microsecond
 	expected := errors.New("an error")
 	err := NewCall(s, "test_call").Exec(func() error {
+		time.Sleep(sleepFor)
 		return expected
 	})
 	assert.NotNil(t, err)
@@ -66,4 +73,6 @@ func TestCallFail(t *testing.T) {
 	require.NotNil(t, timers["test_call.latency+"])
 
 	assert.Equal(t, int64(1), counters["test_call+result_type=error"].Value())
+	require.Equal(t, 1, len(timers["test_call.latency+"].Values()))
+	assert.True(t, timers["test_call.latency+"].Values()[0] >= sleepFor)
 }