From 14dcf38e7dc7de4dc9a48bb7b4f05ee550425268 Mon Sep 17 00:00:00 2001 From: Eugene Date: Wed, 6 May 2020 04:44:34 +0200 Subject: [PATCH] Make AppendKey in json inlinable (#226) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This change increase performance by inlining this frequently called function Benchmark: | name | old time/op | new time/op | delta | params | |---|---|---|---|---| | LogEmpty-8 | 14.1ns ±10% | 15.6ns ±13% | +10.43% | (p=0.003 n=10+10) | | Disabled-8 | 1.27ns ± 0% | 1.35ns ± 1% | +6.54% | (p=0.000 n=9+10) | | Info-8 | 39.8ns ± 5% | 37.9ns ± 2% | -4.55% | (p=0.000 n=10+10) | | ContextFields-8 | 42.2ns ± 4% | 39.7ns ± 3% | -6.04% | (p=0.000 n=10+10) | | ContextAppend-8 | 15.3ns ± 0% | 14.5ns ± 0% | -5.23% | (p=0.000 n=9+10) | | LogFields-8 | 179ns ± 0% | 176ns ± 1% | -1.23% | (p=0.000 n=10+10) | | LogArrayObject-8 | 526ns ± 1% | 491ns ± 1% | -6.65% | (p=0.000 n=9+10) | | LogFieldType/Bools-8 | 34.5ns ± 2% | 33.3ns ± 4% | -3.63% | (p=0.000 n=9+10) | | LogFieldType/Int-8 | 29.7ns ± 4% | 28.3ns ± 6% | -4.71% | (p=0.003 n=10+10) | | LogFieldType/Str-8 | 29.6ns ± 3% | 27.1ns ± 2% | -8.19% | (p=0.000 n=10+10) | | LogFieldType/Time-8 | 119ns ± 0% | 118ns ± 0% | -0.84% | (p=0.000 n=9+9) | | LogFieldType/Interfaces-8 | 504ns ± 1% | 516ns ± 1% | +2.46% | (p=0.000 n=10+10) | | LogFieldType/Object-8 | 73.7ns ± 2% | 71.6ns ± 1% | -2.94% | (p=0.000 n=10+10) | | LogFieldType/Bool-8 | 28.9ns ± 6% | 25.9ns ± 3% | -10.35% | (p=0.000 n=9+10) | | LogFieldType/Strs-8 | 53.7ns ± 2% | 51.6ns ± 1% | -3.95% | (p=0.000 n=9+10) | | LogFieldType/Err-8 | 39.2ns ± 2% | 38.1ns ± 4% | -2.66% | (p=0.006 n=10+10) | | LogFieldType/Interface-8 | 147ns ± 1% | 145ns ± 1% | -1.22% | (p=0.001 n=10+10) | | LogFieldType/Interface(Object)-8 | 78.8ns ± 1% | 76.9ns ± 1% | -2.43% | (p=0.000 n=10+10) | | LogFieldType/Interface(Objects)-8 | 516ns ± 0% | 507ns ± 1% | -1.66% | (p=0.000 n=8+10) | | LogFieldType/Ints-8 | 52.4ns ± 1% | 48.1ns ± 1% | -8.28% | (p=0.000 n=10+10) | | LogFieldType/Float-8 | 39.8ns ± 1% | 38.4ns ± 2% | -3.33% | (p=0.000 n=10+9) | | LogFieldType/Times-8 | 887ns ± 0% | 887ns ± 0% | ~ | (p=0.164 n=8+10) | | LogFieldType/Dur-8 | 41.1ns ± 2% | 40.2ns ± 6% | -2.10% | (p=0.014 n=10+10) | | LogFieldType/Durs-8 | 266ns ± 0% | 262ns ± 0% | -1.35% | (p=0.000 n=7+10) | | LogFieldType/Floats-8 | 166ns ± 0% | 165ns ± 1% | ~ | (p=0.238 n=10+10) | | LogFieldType/Errs-8 | 126ns ± 1% | 120ns ± 2% | -4.61% | (p=0.000 n=10+10) | | ContextFieldType/Bool-8 | 140ns ± 2% | 140ns ± 2% | ~ | (p=0.701 n=10+9) | | ContextFieldType/Err-8 | 150ns ± 3% | 150ns ± 2% | ~ | (p=0.932 n=10+10) | | ContextFieldType/Interfaces-8 | 631ns ± 1% | 628ns ± 1% | ~ | (p=0.108 n=10+10) | | ContextFieldType/Floats-8 | 263ns ± 1% | 257ns ± 1% | -2.05% | (p=0.000 n=10+10) | | ContextFieldType/Errs-8 | 205ns ± 2% | 204ns ± 2% | ~ | (p=0.499 n=10+9) | | ContextFieldType/Dur-8 | 146ns ± 3% | 149ns ± 2% | +1.86% | (p=0.011 n=9+10) | | ContextFieldType/Durs-8 | 372ns ± 1% | 367ns ± 1% | -1.24% | (p=0.000 n=10+10) | | ContextFieldType/Bools-8 | 145ns ± 2% | 144ns ± 3% | ~ | (p=0.447 n=10+10) | | ContextFieldType/Ints-8 | 157ns ± 3% | 157ns ± 2% | ~ | (p=0.976 n=9+9) | | ContextFieldType/Float-8 | 147ns ± 3% | 148ns ± 4% | ~ | (p=0.385 n=9+10) | | ContextFieldType/Strs-8 | 158ns ± 3% | 157ns ± 2% | ~ | (p=0.666 n=10+10) | | ContextFieldType/Time-8 | 143ns ± 2% | 141ns ± 3% | -1.75% | (p=0.035 n=10+10) | | ContextFieldType/Times-8 | 159ns ± 4% | 159ns ± 2% | ~ | (p=0.978 n=10+10) | | ContextFieldType/Interface(Object)-8 | 252ns ± 2% | 251ns ± 2% | ~ | (p=0.415 n=10+10) | | ContextFieldType/Timestamp-8 | 167ns ± 2% | 167ns ± 3% | ~ | (p=0.662 n=10+10) | | ContextFieldType/Int-8 | 142ns ± 4% | 140ns ± 2% | -2.04% | (p=0.026 n=10+10) | | ContextFieldType/Str-8 | 142ns ± 1% | 141ns ± 3% | -1.00% | (p=0.016 n=9+10) | | ContextFieldType/Interface-8 | 253ns ± 1% | 249ns ± 3% | ~ | (p=0.055 n=9+10) | | ContextFieldType/Interface(Objects)-8 | 632ns ± 1% | 624ns ± 1% | -1.20% | (p=0.000 n=10+9) | | ContextFieldType/Object-8 | 194ns ± 2% | 192ns ± 2% | ~ | (p=0.083 n=10+10) | | Hooks/Nop/Single-8 | 16.5ns ± 6% | 15.5ns ± 5% | -5.95% | (p=0.001 n=10+10) | | Hooks/Nop/Multi-8 | 18.5ns ± 6% | 17.8ns ± 4% | -3.66% | (p=0.009 n=10+9) | | Hooks/Simple-8 | 31.0ns ± 2% | 28.1ns ± 2% | -9.24% | (p=0.000 n=8+9) | | Samplers/BasicSampler_1-8 | 0.65ns ± 1% | 0.63ns ± 1% | -1.78% | (p=0.000 n=10+9) | | Samplers/BasicSampler_5-8 | 30.0ns ± 1% | 32.2ns ± 0% | +7.29% | (p=0.000 n=10+9) | | Samplers/RandomSampler-8 | 92.8ns ± 1% | 90.8ns ± 1% | -2.25% | (p=0.000 n=10+10) | | Samplers/BurstSampler-8 | 34.5ns ± 1% | 36.6ns ± 1% | +5.95% | (p=0.000 n=9+9) | | Samplers/BurstSamplerNext-8 | 46.3ns ± 0% | 46.1ns ± 0% | -0.41% | (p=0.001 n=9+7) | | ConsoleWriter-8 | 5.90µs ± 0% | 5.84µs ± 1% | -0.91% | (p=0.000 n=10+10) | --- internal/json/base.go | 7 +++---- internal/json/types.go | 7 +++---- log.go | 6 +++++- 3 files changed, 11 insertions(+), 9 deletions(-) diff --git a/internal/json/base.go b/internal/json/base.go index d6f8839e..62248e71 100644 --- a/internal/json/base.go +++ b/internal/json/base.go @@ -4,9 +4,8 @@ type Encoder struct{} // AppendKey appends a new key to the output JSON. func (e Encoder) AppendKey(dst []byte, key string) []byte { - if len(dst) > 1 && dst[len(dst)-1] != '{' { + if dst[len(dst)-1] != '{' { dst = append(dst, ',') } - dst = e.AppendString(dst, key) - return append(dst, ':') -} \ No newline at end of file + return append(e.AppendString(dst, key), ':') +} diff --git a/internal/json/types.go b/internal/json/types.go index bc8bc095..d1862426 100644 --- a/internal/json/types.go +++ b/internal/json/types.go @@ -379,11 +379,10 @@ func (Encoder) AppendObjectData(dst []byte, o []byte) []byte { // to separate with existing content OR // 3. existing content has already other fields if o[0] == '{' { - if len(dst) == 0 { - o = o[1:] - } else { - o[0] = ',' + if len(dst) > 1 { + dst = append(dst, ',') } + o = o[1:] } else if len(dst) > 1 { dst = append(dst, ',') } diff --git a/log.go b/log.go index b1e7ac13..cbf68850 100644 --- a/log.go +++ b/log.go @@ -234,6 +234,10 @@ func (l Logger) With() Context { l.context = make([]byte, 0, 500) if context != nil { l.context = append(l.context, context...) + } else { + // This is needed for AppendKey to not check len of input + // thus making it inlinable + l.context = enc.AppendBeginMarker(l.context) } return Context{l} } @@ -415,7 +419,7 @@ func (l *Logger) newEvent(level Level, done func(string)) *Event { if level != NoLevel { e.Str(LevelFieldName, LevelFieldMarshalFunc(level)) } - if l.context != nil && len(l.context) > 0 { + if l.context != nil && len(l.context) > 1 { e.buf = enc.AppendObjectData(e.buf, l.context) } return e