Scope: remove fmt.Sprintf() string concatenation and improve tag merge (

#61)

* tags: save an alloc by creating the full stat key in serializeTags

Instead of serializing the tags then appending them to the stat name,
combine those operations so that there is only one alloc instead of two
if tags are present.

Benchmark Comparison: (Note: BenchmarkSerializeTags now does a little
more work, but NewCounterWithTags is improved)

benchmark                               old ns/op     new ns/op     delta
BenchmarkStore_MutexContention-8        120           114           -5.00%
BenchmarkStore_NewCounterWithTags-8     512           465           -9.18%
BenchmarkSerializeTags-8                426           441           +3.52%

benchmark                               old allocs     new allocs     delta
BenchmarkStore_MutexContention-8        0              0              +0.00%
BenchmarkStore_NewCounterWithTags-8     4              3              -25.00%
BenchmarkSerializeTags-8                3              3              +0.00%

benchmark                               old bytes     new bytes     delta
BenchmarkStore_MutexContention-8        2             2             +0.00%
BenchmarkStore_NewCounterWithTags-8     336           272           -19.05%
BenchmarkSerializeTags-8                256           272           +6.25%

* stats: benchmark Scope functions and methods

Benchmark results:

goos: darwin
goarch: amd64
pkg: github.com/lyft/gostats
BenchmarkStore_ScopeWithTags-8   	 1000000	      1404 ns/op	     576 B/op	       6 allocs/op
BenchmarkStore_ScopeNoTags-8     	 1000000	      1092 ns/op	     672 B/op	       8 allocs/op

* stats: Scope: remove fmt.Sprintf() string concatenation and improve tag merge

Improve the performance of Scope* methods by not using fmt.Sprintf() to
concatenate strings and re-using the parent's tags when the child scope
has none (tags are never modified - they are only used to generate the
stat key name).

Benchmark Results:

benchmark                          old ns/op     new ns/op     delta
BenchmarkStore_ScopeWithTags-8     1417          1268          -10.52%
BenchmarkStore_ScopeNoTags-8       1100          527           -52.09%

benchmark                          old allocs     new allocs     delta
BenchmarkStore_ScopeWithTags-8     6              4              -33.33%
BenchmarkStore_ScopeNoTags-8       8              4              -50.00%

benchmark                          old bytes     new bytes     delta
BenchmarkStore_ScopeWithTags-8     576           544           -5.56%
BenchmarkStore_ScopeNoTags-8       672           304           -54.76%

* stats: don't use pointer to nullSink in benchmarks

* stats: use impossibly long flush interval (because it doesn't matter)

* stats_test: remove unneeded global variables

stats.go

@@ -2,7 +2,6 @@ package stats
 
 import (
 	"expvar"
-	"fmt"
 	"strconv"
 	"sync"
 	"sync/atomic"
@@ -204,12 +203,6 @@ func NewDefaultStore() Store {
 	return newStore
 }
 
-type subScope struct {
-	registry *statStore
-	name     string
-	tags     map[string]string
-}
-
 type counter struct {
 	currentValue  uint64
 	lastSentValue uint64
@@ -388,7 +381,7 @@ func (s *statStore) NewCounter(name string) Counter {
 }
 
 func (s *statStore) NewCounterWithTags(name string, tags map[string]string) Counter {
-	name += serializeTags(tags)
+	name = serializeTags(name, tags)
 
 	s.countersMtx.RLock()
 	c, ok := s.counters[name]
@@ -432,7 +425,7 @@ func (s *statStore) NewGauge(name string) Gauge {
 }
 
 func (s *statStore) NewGaugeWithTags(name string, tags map[string]string) Gauge {
-	name += serializeTags(tags)
+	name = serializeTags(name, tags)
 
 	s.gaugesMtx.RLock()
 	g, ok := s.gauges[name]
@@ -472,7 +465,7 @@ func (s *statStore) NewTimer(name string) Timer {
 }
 
 func (s *statStore) NewTimerWithTags(name string, tags map[string]string) Timer {
-	name += serializeTags(tags)
+	name = serializeTags(name, tags)
 
 	s.timersMtx.RLock()
 	t, ok := s.timers[name]
@@ -503,12 +496,18 @@ func (s *statStore) NewPerInstanceTimer(name string, tags map[string]string) Tim
 	return s.NewTimerWithTags(name, tags)
 }
 
+type subScope struct {
+	registry *statStore
+	name     string
+	tags     map[string]string
+}
+
 func (s subScope) Scope(name string) Scope {
 	return s.ScopeWithTags(name, nil)
 }
 
 func (s subScope) ScopeWithTags(name string, tags map[string]string) Scope {
-	return &subScope{registry: s.registry, name: fmt.Sprintf("%s.%s", s.name, name), tags: s.mergeTags(tags)}
+	return &subScope{registry: s.registry, name: joinScopes(s.name, name), tags: s.mergeTags(tags)}
 }
 
 func (s subScope) Store() Store {
@@ -520,35 +519,39 @@ func (s subScope) NewCounter(name string) Counter {
 }
 
 func (s subScope) NewCounterWithTags(name string, tags map[string]string) Counter {
-	return s.registry.NewCounterWithTags(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewCounterWithTags(joinScopes(s.name, name), s.mergeTags(tags))
 }
 
 func (s subScope) NewPerInstanceCounter(name string, tags map[string]string) Counter {
-	return s.registry.NewPerInstanceCounter(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewPerInstanceCounter(joinScopes(s.name, name), s.mergeTags(tags))
 }
 
 func (s subScope) NewGauge(name string) Gauge {
 	return s.NewGaugeWithTags(name, nil)
 }
 
 func (s subScope) NewGaugeWithTags(name string, tags map[string]string) Gauge {
-	return s.registry.NewGaugeWithTags(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewGaugeWithTags(joinScopes(s.name, name), s.mergeTags(tags))
 }
 
 func (s subScope) NewPerInstanceGauge(name string, tags map[string]string) Gauge {
-	return s.registry.NewPerInstanceGauge(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewPerInstanceGauge(joinScopes(s.name, name), s.mergeTags(tags))
 }
 
 func (s subScope) NewTimer(name string) Timer {
 	return s.NewTimerWithTags(name, nil)
 }
 
 func (s subScope) NewTimerWithTags(name string, tags map[string]string) Timer {
-	return s.registry.NewTimerWithTags(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewTimerWithTags(joinScopes(s.name, name), s.mergeTags(tags))
 }
 
 func (s subScope) NewPerInstanceTimer(name string, tags map[string]string) Timer {
-	return s.registry.NewPerInstanceTimer(fmt.Sprintf("%s.%s", s.name, name), s.mergeTags(tags))
+	return s.registry.NewPerInstanceTimer(joinScopes(s.name, name), s.mergeTags(tags))
+}
+
+func joinScopes(parent, child string) string {
+	return parent + "." + child
 }
 
 // mergeTags augments tags with all scope-level tags that are not already present.
@@ -558,7 +561,7 @@ func (s subScope) mergeTags(tags map[string]string) map[string]string {
 		return tags
 	}
 	if tags == nil {
-		tags = make(map[string]string)
+		return s.tags
 	}
 	for k, v := range s.tags {
 		if _, ok := tags[k]; !ok {

stats_test.go

@@ -1,6 +1,7 @@
 package stats
 
 import (
+	"fmt"
 	"math/rand"
 	"strconv"
 	"strings"
@@ -51,27 +52,24 @@ func TestTimer(t *testing.T) {
 	}
 }
 
-var bmID = ""
-var bmVal = uint64(0)
-
 func BenchmarkStore_MutexContention(b *testing.B) {
-	s := NewStore(&nullSink{}, false)
+	s := NewStore(nullSink{}, false)
 	t := time.NewTicker(500 * time.Microsecond) // we want flush to contend with accessing metrics
 	defer t.Stop()
 	go s.Start(t)
 
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		bmID = strconv.Itoa(rand.Intn(1000))
+		bmID := strconv.Itoa(rand.Intn(1000))
 		c := s.NewCounter(bmID)
 		c.Inc()
-		bmVal = c.Value()
+		_ = c.Value()
 	}
 }
 
 func BenchmarkStore_NewCounterWithTags(b *testing.B) {
-	s := NewStore(&nullSink{}, false)
-	t := time.NewTicker(1 * time.Second) // we want flush to contend with accessing metrics
+	s := NewStore(nullSink{}, false)
+	t := time.NewTicker(time.Hour) // don't flush
 	defer t.Stop()
 	go s.Start(t)
 	tags := map[string]string{
@@ -86,3 +84,40 @@ func BenchmarkStore_NewCounterWithTags(b *testing.B) {
 		s.NewCounterWithTags("counter_name", tags)
 	}
 }
+
+func initBenchScope() (scope Scope, childTags map[string]string) {
+	s := NewStore(nullSink{}, false)
+
+	t := time.NewTicker(time.Hour) // don't flush
+	t.Stop()                       // never sends
+	go s.Start(t)
+
+	scopeTags := make(map[string]string, 5)
+	childTags = make(map[string]string, 5)
+
+	for i := 0; i < 5; i++ {
+		tag := fmt.Sprintf("%dtag", i)
+		val := fmt.Sprintf("%dval", i)
+		scopeTags[tag] = val
+		childTags["c"+tag] = "c" + val
+	}
+
+	scope = s.ScopeWithTags("scope", scopeTags)
+	return
+}
+
+func BenchmarkStore_ScopeWithTags(b *testing.B) {
+	scope, childTags := initBenchScope()
+	b.ResetTimer()
+	for i := 0; i < b.N; i++ {
+		scope.NewCounterWithTags("counter_name", childTags)
+	}
+}
+
+func BenchmarkStore_ScopeNoTags(b *testing.B) {
+	scope, _ := initBenchScope()
+	b.ResetTimer()
+	for i := 0; i < b.N; i++ {
+		scope.NewCounterWithTags("counter_name", nil)
+	}
+}

tags.go

@@ -24,15 +24,19 @@ func (t tagSet) Len() int           { return len(t) }
 func (t tagSet) Swap(i, j int)      { t[i], t[j] = t[j], t[i] }
 func (t tagSet) Less(i, j int) bool { return t[i].dimension < t[j].dimension }
 
-func serializeTags(tags map[string]string) string {
+func serializeTags(name string, tags map[string]string) string {
 	const prefix = ".__"
 	const sep = "="
 
 	if len(tags) == 0 {
-		return ""
+		return name
 	}
-	pairs := make([]tagPair, 0, len(tags))
+
+	// n stores the length of the serialized name + tags
 	n := (len(prefix) + len(sep)) * len(tags)
+	n += len(name)
+
+	pairs := make([]tagPair, 0, len(tags))
 	for k, v := range tags {
 		n += len(k) + len(v)
 		pairs = append(pairs, tagPair{
@@ -44,6 +48,7 @@ func serializeTags(tags map[string]string) string {
 
 	// CEV: this is same as strings.Builder, but works with go1.9 and earlier
 	b := make([]byte, 0, n)
+	b = append(b, name...)
 	for _, tag := range pairs {
 		b = append(b, prefix...)
 		b = append(b, tag.dimension...)

tags_test.go

@@ -5,38 +5,47 @@ import (
 )
 
 func TestSerializeTags(t *testing.T) {
+	const name = "prefix"
+	const expected = name + ".__q=r.__zzz=hello"
 	tags := map[string]string{"zzz": "hello", "q": "r"}
-	serialized := serializeTags(tags)
-	if serialized != ".__q=r.__zzz=hello" {
+	serialized := serializeTags(name, tags)
+	if serialized != expected {
 		t.Errorf("Serialized output (%s) didn't match expected output", serialized)
 	}
 }
 
 func TestSerializeWithPerInstanceFlag(t *testing.T) {
+	const name = "prefix"
+	const expected = name + ".___f=i.__foo=bar"
 	tags := map[string]string{"foo": "bar", "_f": "i"}
-	serialized := serializeTags(tags)
-	if serialized != ".___f=i.__foo=bar" {
+	serialized := serializeTags(name, tags)
+	if serialized != expected {
 		t.Errorf("Serialized output (%s) didn't match expected output", serialized)
 	}
 }
 
 func TestSerializeIllegalTags(t *testing.T) {
+	const name = "prefix"
+	const expected = name + ".__foo=b_a_r.__q=p"
 	tags := map[string]string{"foo": "b|a:r", "q": "p"}
-	serialized := serializeTags(tags)
-	if serialized != ".__foo=b_a_r.__q=p" {
+	serialized := serializeTags(name, tags)
+	if serialized != expected {
 		t.Errorf("Serialized output (%s) didn't match expected output", serialized)
 	}
 }
 
 func TestSerializeTagValuePeriod(t *testing.T) {
+	const name = "prefix"
+	const expected = name + ".__foo=blah_blah.__q=p"
 	tags := map[string]string{"foo": "blah.blah", "q": "p"}
-	serialized := serializeTags(tags)
-	if serialized != ".__foo=blah_blah.__q=p" {
+	serialized := serializeTags(name, tags)
+	if serialized != expected {
 		t.Errorf("Serialized output (%s) didn't match expected output", serialized)
 	}
 }
 
 func BenchmarkSerializeTags(b *testing.B) {
+	const name = "prefix"
 	tags := map[string]string{
 		"tag1": "val1",
 		"tag2": "val2",
@@ -46,6 +55,6 @@ func BenchmarkSerializeTags(b *testing.B) {
 	}
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		serializeTags(tags)
+		serializeTags(name, tags)
 	}
 }