From bade9ed839430d28856d5b72db4fbf52fde1adfa Mon Sep 17 00:00:00 2001 From: Charlie Vieth Date: Fri, 11 Jan 2019 17:36:43 -0500 Subject: [PATCH] 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 | 39 +++++++++++++++++++++------------------ stats_test.go | 51 +++++++++++++++++++++++++++++++++++++++++++-------- tags.go | 11 ++++++++--- tags_test.go | 27 ++++++++++++++++++--------- 4 files changed, 90 insertions(+), 38 deletions(-) diff --git a/stats.go b/stats.go index ec08427..a056557 100644 --- a/stats.go +++ b/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,11 +519,11 @@ 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 { @@ -532,11 +531,11 @@ func (s subScope) NewGauge(name string) Gauge { } 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 { @@ -544,11 +543,15 @@ func (s subScope) NewTimer(name string) Timer { } 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 { diff --git a/stats_test.go b/stats_test.go index 27c0e67..02d5e13 100644 --- a/stats_test.go +++ b/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) + } +} diff --git a/tags.go b/tags.go index 95645c3..45ce71e 100644 --- a/tags.go +++ b/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...) diff --git a/tags_test.go b/tags_test.go index b64e228..0cbf305 100644 --- a/tags_test.go +++ b/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) } }