diff --git a/field.go b/field.go index bbb745db5..33654ebb0 100644 --- a/field.go +++ b/field.go @@ -418,132 +418,263 @@ func Inline(val zapcore.ObjectMarshaler) Field { // them. To minimize surprises, []byte values are treated as binary blobs, byte // values are treated as uint8, and runes are always treated as integers. func Any(key string, value interface{}) Field { + // To work around go compiler assigning unreasonably large space on stack + // (4kb, one `Field` per arm of the switch statement) which can trigger + // performance degradation if `Any` is used in a brand new goroutine. + var f func() Field switch val := value.(type) { case zapcore.ObjectMarshaler: - return Object(key, val) + f = func() Field { + return Object(key, val) + } case zapcore.ArrayMarshaler: - return Array(key, val) + f = func() Field { + return Array(key, val) + } case bool: - return Bool(key, val) + f = func() Field { + return Bool(key, val) + } case *bool: - return Boolp(key, val) + f = func() Field { + return Boolp(key, val) + } case []bool: - return Bools(key, val) + f = func() Field { + return Bools(key, val) + } case complex128: - return Complex128(key, val) + f = func() Field { + return Complex128(key, val) + } case *complex128: - return Complex128p(key, val) + f = func() Field { + return Complex128p(key, val) + } case []complex128: - return Complex128s(key, val) + f = func() Field { + return Complex128s(key, val) + } case complex64: - return Complex64(key, val) + f = func() Field { + return Complex64(key, val) + } case *complex64: - return Complex64p(key, val) + f = func() Field { + return Complex64p(key, val) + } case []complex64: - return Complex64s(key, val) + f = func() Field { + return Complex64s(key, val) + } case float64: - return Float64(key, val) + f = func() Field { + return Float64(key, val) + } case *float64: - return Float64p(key, val) + f = func() Field { + return Float64p(key, val) + } case []float64: - return Float64s(key, val) + f = func() Field { + return Float64s(key, val) + } case float32: - return Float32(key, val) + f = func() Field { + return Float32(key, val) + } case *float32: - return Float32p(key, val) + f = func() Field { + return Float32p(key, val) + } case []float32: - return Float32s(key, val) + f = func() Field { + return Float32s(key, val) + } case int: - return Int(key, val) + f = func() Field { + return Int(key, val) + } case *int: - return Intp(key, val) + f = func() Field { + return Intp(key, val) + } case []int: - return Ints(key, val) + f = func() Field { + return Ints(key, val) + } case int64: - return Int64(key, val) + f = func() Field { + return Int64(key, val) + } case *int64: - return Int64p(key, val) + f = func() Field { + return Int64p(key, val) + } case []int64: - return Int64s(key, val) + f = func() Field { + return Int64s(key, val) + } case int32: - return Int32(key, val) + f = func() Field { + return Int32(key, val) + } case *int32: - return Int32p(key, val) + f = func() Field { + return Int32p(key, val) + } case []int32: - return Int32s(key, val) + f = func() Field { + return Int32s(key, val) + } case int16: - return Int16(key, val) + f = func() Field { + return Int16(key, val) + } case *int16: - return Int16p(key, val) + f = func() Field { + return Int16p(key, val) + } case []int16: - return Int16s(key, val) + f = func() Field { + return Int16s(key, val) + } case int8: - return Int8(key, val) + f = func() Field { + return Int8(key, val) + } case *int8: - return Int8p(key, val) + f = func() Field { + return Int8p(key, val) + } case []int8: - return Int8s(key, val) + f = func() Field { + return Int8s(key, val) + } case string: - return String(key, val) + f = func() Field { + return String(key, val) + } case *string: - return Stringp(key, val) + f = func() Field { + return Stringp(key, val) + } case []string: - return Strings(key, val) + f = func() Field { + return Strings(key, val) + } case uint: - return Uint(key, val) + f = func() Field { + return Uint(key, val) + } case *uint: - return Uintp(key, val) + f = func() Field { + return Uintp(key, val) + } case []uint: - return Uints(key, val) + f = func() Field { + return Uints(key, val) + } case uint64: - return Uint64(key, val) + f = func() Field { + return Uint64(key, val) + } case *uint64: - return Uint64p(key, val) + f = func() Field { + return Uint64p(key, val) + } case []uint64: - return Uint64s(key, val) + f = func() Field { + return Uint64s(key, val) + } case uint32: - return Uint32(key, val) + f = func() Field { + return Uint32(key, val) + } case *uint32: - return Uint32p(key, val) + f = func() Field { + return Uint32p(key, val) + } case []uint32: - return Uint32s(key, val) + f = func() Field { + return Uint32s(key, val) + } case uint16: - return Uint16(key, val) + f = func() Field { + return Uint16(key, val) + } case *uint16: - return Uint16p(key, val) + f = func() Field { + return Uint16p(key, val) + } case []uint16: - return Uint16s(key, val) + f = func() Field { + return Uint16s(key, val) + } case uint8: - return Uint8(key, val) + f = func() Field { + return Uint8(key, val) + } case *uint8: - return Uint8p(key, val) + f = func() Field { + return Uint8p(key, val) + } case []byte: - return Binary(key, val) + f = func() Field { + return Binary(key, val) + } case uintptr: - return Uintptr(key, val) + f = func() Field { + return Uintptr(key, val) + } case *uintptr: - return Uintptrp(key, val) + f = func() Field { + return Uintptrp(key, val) + } case []uintptr: - return Uintptrs(key, val) + f = func() Field { + return Uintptrs(key, val) + } case time.Time: - return Time(key, val) + f = func() Field { + return Time(key, val) + } case *time.Time: - return Timep(key, val) + f = func() Field { + return Timep(key, val) + } case []time.Time: - return Times(key, val) + f = func() Field { + return Times(key, val) + } case time.Duration: - return Duration(key, val) + f = func() Field { + return Duration(key, val) + } case *time.Duration: - return Durationp(key, val) + f = func() Field { + return Durationp(key, val) + } case []time.Duration: - return Durations(key, val) + f = func() Field { + return Durations(key, val) + } case error: - return NamedError(key, val) + f = func() Field { + return NamedError(key, val) + } case []error: - return Errors(key, val) + f = func() Field { + return Errors(key, val) + } case fmt.Stringer: - return Stringer(key, val) + f = func() Field { + return Stringer(key, val) + } default: - return Reflect(key, val) + f = func() Field { + return Reflect(key, val) + } } + return f() } diff --git a/logger_bench_test.go b/logger_bench_test.go index 41e661577..f68792736 100644 --- a/logger_bench_test.go +++ b/logger_bench_test.go @@ -22,6 +22,8 @@ package zap import ( "errors" + "runtime" + "sync" "testing" "time" @@ -238,3 +240,108 @@ func Benchmark100Fields(b *testing.B) { logger.With(first...).Info("Child loggers with lots of context.", second...) } } + +func dummy(wg *sync.WaitGroup, s string, i int) string { + if i == 0 { + wg.Wait() + return "1" + s + } + return dummy(wg, s, i-1) +} + +func stackGrower(n int) *sync.WaitGroup { + wg := sync.WaitGroup{} + wg.Add(1) + + go dummy(&wg, "hi", n) + return &wg +} + +func BenchmarkAny(b *testing.B) { + logger := New( + zapcore.NewCore( + zapcore.NewJSONEncoder(NewProductionConfig().EncoderConfig), + &ztest.Discarder{}, + DebugLevel, + ), + ) + + b.Run("str-no-logger", func(b *testing.B) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + f := String("some-string-longer-than-16", "yet-another-long-string") + runtime.KeepAlive(f) + } + }) + b.Run("any-no-logger", func(b *testing.B) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + f := Any("some-string-longer-than-16", "yet-another-long-string") + runtime.KeepAlive(f) + } + }) + b.Run("str-with-logger", func(b *testing.B) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + logger.Info("", String("some-string-longer-than-16", "yet-another-long-string")) + } + }) + b.Run("any-with-logger", func(b *testing.B) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + logger.Info("", String("some-string-longer-than-16", "yet-another-long-string")) + } + }) + b.Run("str-in-go", func(b *testing.B) { + wg := sync.WaitGroup{} + wg.Add(b.N) + b.ResetTimer() + for i := 0; i < b.N; i++ { + go func() { + logger.Info("", String("some-string-longer-than-16", "yet-another-long-string")) + wg.Done() + }() + } + wg.Wait() + }) + b.Run("any-in-go", func(b *testing.B) { + wg := sync.WaitGroup{} + wg.Add(b.N) + b.ResetTimer() + for i := 0; i < b.N; i++ { + go func() { + logger.Info("", Any("some-string-longer-than-16", "yet-another-long-string")) + wg.Done() + }() + } + wg.Wait() + }) + b.Run("any-in-go-with-stack", func(b *testing.B) { + wg := sync.WaitGroup{} + wg.Add(b.N) + defer stackGrower(2000).Done() + b.ResetTimer() + for i := 0; i < b.N; i++ { + go func() { + logger.Info("", Any("some-string-longer-than-16", "yet-another-long-string")) + wg.Done() + }() + } + wg.Wait() + b.StopTimer() + }) + b.Run("str-in-go-with-stack", func(b *testing.B) { + wg := sync.WaitGroup{} + wg.Add(b.N) + defer stackGrower(2000).Done() + b.ResetTimer() + for i := 0; i < b.N; i++ { + go func() { + logger.Info("", String("some-string-longer-than-16", "yet-another-long-string")) + wg.Done() + }() + } + wg.Wait() + b.StopTimer() + }) +}