Make AppendKey in json inlinable (#226)

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

@@ -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, ':')
-}
+	return append(e.AppendString(dst, key), ':')
+}

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, ',')
 	}

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