Alternate, map-based sugared logger

benchmarks/zap_sugar_bench_test.go

@@ -0,0 +1,113 @@
+// Copyright (c) 2016 Uber Technologies, Inc.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a copy
+// of this software and associated documentation files (the "Software"), to deal
+// in the Software without restriction, including without limitation the rights
+// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+// copies of the Software, and to permit persons to whom the Software is
+// furnished to do so, subject to the following conditions:
+//
+// The above copyright notice and this permission notice shall be included in
+// all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+// THE SOFTWARE.
+
+package benchmarks
+
+import (
+	"testing"
+	"time"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/testutils"
+	"go.uber.org/zap/zapcore"
+)
+
+func fakeSugarFields() zap.Ctx {
+	return zap.Ctx{
+		"error":          errExample,
+		"int":            1,
+		"int64":          2,
+		"float":          3.0,
+		"string":         "four!",
+		"stringer":       zap.DebugLevel,
+		"bool":           true,
+		"time":           time.Unix(0, 0),
+		"duration":       time.Second,
+		"another string": "done!",
+	}
+}
+
+func newSugarLogger(lvl zapcore.Level, options ...zap.Option) *zap.SugaredLogger {
+	return zap.Sugar(zap.New(zapcore.WriterFacility(
+		benchEncoder(),
+		&testutils.Discarder{},
+		lvl,
+	), options...))
+}
+
+func BenchmarkZapSugarDisabledLevelsWithoutFields(b *testing.B) {
+	logger := newSugarLogger(zap.ErrorLevel)
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.Info("Should be discarded.")
+		}
+	})
+}
+
+func BenchmarkZapSugarDisabledLevelsAccumulatedContext(b *testing.B) {
+	logger := newSugarLogger(zap.ErrorLevel, zap.Fields(fakeFields()...))
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.Info("Should be discarded.")
+		}
+	})
+}
+
+func BenchmarkZapSugarDisabledLevelsAddingFields(b *testing.B) {
+	logger := newSugarLogger(zap.ErrorLevel)
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.InfoWith("Should be discarded.", fakeSugarFields())
+		}
+	})
+}
+
+func BenchmarkZapSugarAddingFields(b *testing.B) {
+	logger := newSugarLogger(zap.DebugLevel)
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.InfoWith("Go fast.", fakeSugarFields())
+		}
+	})
+}
+
+func BenchmarkZapSugarWithAccumulatedContext(b *testing.B) {
+	logger := newSugarLogger(zap.DebugLevel, zap.Fields(fakeFields()...))
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.Info("Go really fast.")
+		}
+	})
+}
+
+func BenchmarkZapSugarWithoutFields(b *testing.B) {
+	logger := newSugarLogger(zap.DebugLevel)
+	b.ResetTimer()
+	b.RunParallel(func(pb *testing.PB) {
+		for pb.Next() {
+			logger.Info("Go fast.")
+		}
+	})
+}

common_test.go

@@ -41,6 +41,10 @@ func withLogger(t testing.TB, e zapcore.LevelEnabler, opts []Option, f func(Logg
 	f(log, &logs)
 }
 
+func withSugar(t testing.TB, e zapcore.LevelEnabler, opts []Option, f func(*SugaredLogger, *observer.ObservedLogs)) {
+	withLogger(t, e, opts, func(logger Logger, logs *observer.ObservedLogs) { f(Sugar(logger), logs) })
+}
+
 func runConcurrently(goroutines, iterations int, wg *sync.WaitGroup, f func()) {
 	wg.Add(goroutines)
 	for g := 0; g < goroutines; g++ {

field.go

@@ -156,3 +156,55 @@ func Reflect(key string, val interface{}) zapcore.Field {
 func Nest(key string, fields ...zapcore.Field) zapcore.Field {
 	return zapcore.Field{Key: key, Type: zapcore.ObjectMarshalerType, Interface: zapcore.Fields(fields)}
 }
+
+// Any takes a key and an arbitrary value and chooses the best way to represent
+// them as a field, falling back to a reflection-based approach only if
+// necessary.
+func Any(key string, value interface{}) zapcore.Field {
+	switch val := value.(type) {
+	case zapcore.ObjectMarshaler:
+		return Object(key, val)
+	case zapcore.ArrayMarshaler:
+		return Array(key, val)
+	case bool:
+		return Bool(key, val)
+	case float64:
+		return Float64(key, val)
+	case float32:
+		return Float64(key, float64(val))
+	case int:
+		return Int(key, val)
+	case int64:
+		return Int64(key, val)
+	case int32:
+		return Int64(key, int64(val))
+	case int16:
+		return Int64(key, int64(val))
+	case int8:
+		return Int64(key, int64(val))
+	case uint:
+		return Uint(key, val)
+	case uint64:
+		return Uint64(key, val)
+	case uint32:
+		return Uint64(key, uint64(val))
+	case uint16:
+		return Uint64(key, uint64(val))
+	case uint8:
+		return Uint64(key, uint64(val))
+	case uintptr:
+		return Uintptr(key, val)
+	case string:
+		return String(key, val)
+	case time.Time:
+		return Time(key, val)
+	case time.Duration:
+		return Duration(key, val)
+	case error:
+		return String(key, val.Error())
+	case fmt.Stringer:
+		return Stringer(key, val)
+	default:
+		return Reflect(key, val)
+	}
+}

field_test.go

@@ -22,16 +22,14 @@ package zap
 
 import (
 	"errors"
+	"math"
 	"net"
 	"sync"
 	"testing"
 	"time"
 
-	"go.uber.org/zap/zapcore"
-
-	"math"
-
 	"github.com/stretchr/testify/assert"
+	"go.uber.org/zap/zapcore"
 )
 
 var (
@@ -99,6 +97,31 @@ func TestFieldConstructors(t *testing.T) {
 		{"Object", zapcore.Field{Key: "k", Type: zapcore.ObjectMarshalerType, Interface: name}, Object("k", name)},
 		{"Reflect", zapcore.Field{Key: "k", Type: zapcore.ReflectType, Interface: ints}, Reflect("k", ints)},
 		{"Nest", zapcore.Field{Key: "k", Type: zapcore.ObjectMarshalerType, Interface: nested}, Nest("k", nested...)},
+		{"Any:ObjectMarshaler", Any("k", name), Object("k", name)},
+		{"Any:ArrayMarshaler", Any("k", bools([]bool{true})), Array("k", bools([]bool{true}))},
+		{"Any:Bool", Any("k", true), Bool("k", true)},
+		{"Any:Float64", Any("k", 3.14), Float64("k", 3.14)},
+		// TODO (v1.0): We could use some approximately-equal logic here, but it's
+		// not worth it to test this one line. Before 1.0, we'll need to support
+		// float32s explicitly, which will make this test pass.
+		// {"Any:Float32", Any("k", float32(3.14)), Float32("k", 3.14)},
+		{"Any:Int", Any("k", 1), Int("k", 1)},
+		{"Any:Int64", Any("k", int64(1)), Int64("k", 1)},
+		{"Any:Int32", Any("k", int32(1)), Int64("k", 1)},
+		{"Any:Int16", Any("k", int16(1)), Int64("k", 1)},
+		{"Any:Int8", Any("k", int8(1)), Int64("k", 1)},
+		{"Any:Uint", Any("k", uint(1)), Uint("k", 1)},
+		{"Any:Uint64", Any("k", uint64(1)), Uint64("k", 1)},
+		{"Any:Uint32", Any("k", uint32(1)), Uint64("k", 1)},
+		{"Any:Uint16", Any("k", uint16(1)), Uint64("k", 1)},
+		{"Any:Uint8", Any("k", uint8(1)), Uint64("k", 1)},
+		{"Any:Uintptr", Any("k", uintptr(1)), Uintptr("k", 1)},
+		{"Any:String", Any("k", "v"), String("k", "v")},
+		{"Any:Error", Any("k", errors.New("v")), String("k", "v")},
+		{"Any:Time", Any("k", time.Unix(0, 0)), Time("k", time.Unix(0, 0))},
+		{"Any:Duration", Any("k", time.Second), Duration("k", time.Second)},
+		{"Any:Stringer", Any("k", addr), Stringer("k", addr)},
+		{"Any:Fallback", Any("k", struct{}{}), Reflect("k", struct{}{})},
 	}
 
 	for _, tt := range tests {

level.go

@@ -39,8 +39,8 @@ const (
 	// ErrorLevel logs are high-priority. If an application is running smoothly,
 	// it shouldn't generate any error-level logs.
 	ErrorLevel = zapcore.ErrorLevel
-	// DPanicLevel logs are particularly important errors. In development the
-	// logger panics after writing the message.
+	// DPanicLevel logs are particularly important errors. In development mode,
+	// the logger panics after writing the message.
 	DPanicLevel = zapcore.DPanicLevel
 	// PanicLevel logs a message, then panics.
 	PanicLevel = zapcore.PanicLevel