Add zap.Object to log arbitrary objects (#38)

* Add zap.Object to log arbitrary objects

Introduce zap.Object, which uses encoding-appropriate reflection to log
truly arbitrary objects. This introduces an API that's not fast by
default, but it makes the zbark wrapper much cleaner.

* Share iface field between Marshalers and Objects

field.go

@@ -36,6 +36,7 @@ const (
 	int64Type
 	stringType
 	marshalerType
+	objectType
 )
 
 // A Field is a deferred marshaling operation used to add a key-value pair to
@@ -46,7 +47,7 @@ type Field struct {
 	fieldType fieldType
 	ival      int64
 	str       string
-	marshaler LogMarshaler
+	obj       interface{}
 }
 
 // Bool constructs a Field with the given key and value.
@@ -120,13 +121,23 @@ func Duration(key string, val time.Duration) Field {
 // provides a flexible, but still type-safe and efficient, way to add
 // user-defined types to the logging context.
 func Marshaler(key string, val LogMarshaler) Field {
-	return Field{key: key, fieldType: marshalerType, marshaler: val}
+	return Field{key: key, fieldType: marshalerType, obj: val}
+}
+
+// Object constructs a field with the given key and an arbitrary object. It uses
+// an encoding-appropriate, reflection-based function to serialize nearly any
+// object into the logging context, but it's relatively slow and allocation-heavy.
+//
+// If encoding fails (e.g., trying to serialize a map[int]string to JSON), Object
+// includes the error message in the final log output.
+func Object(key string, val interface{}) Field {
+	return Field{key: key, fieldType: objectType, obj: val}
 }
 
 // Nest takes a key and a variadic number of Fields and creates a nested
 // namespace.
 func Nest(key string, fields ...Field) Field {
-	return Field{key: key, fieldType: marshalerType, marshaler: multiFields(fields)}
+	return Field{key: key, fieldType: marshalerType, obj: multiFields(fields)}
 }
 
 func (f Field) addTo(kv KeyValue) error {
@@ -142,7 +153,9 @@ func (f Field) addTo(kv KeyValue) error {
 	case stringType:
 		kv.AddString(f.key, f.str)
 	case marshalerType:
-		return kv.AddMarshaler(f.key, f.marshaler)
+		return kv.AddMarshaler(f.key, f.obj.(LogMarshaler))
+	case objectType:
+		kv.AddObject(f.key, f.obj)
 	default:
 		panic(fmt.Sprintf("unknown field type found: %v", f))
 	}

field_test.go

@@ -126,6 +126,11 @@ func TestMarshalerField(t *testing.T) {
 	assertCanBeReused(t, Marshaler("foo", fakeUser{"phil"}))
 }
 
+func TestObjectField(t *testing.T) {
+	assertFieldJSON(t, `"foo":[5,6]`, Object("foo", []int{5, 6}))
+	assertCanBeReused(t, Object("foo", []int{5, 6}))
+}
+
 func TestNestField(t *testing.T) {
 	assertFieldJSON(t, `"foo":{"name":"phil","age":42}`,
 		Nest("foo", String("name", "phil"), Int("age", 42)),

json_encoder.go

@@ -21,6 +21,7 @@
 package zap
 
 import (
+	"encoding/json"
 	"fmt"
 	"io"
 	"strconv"
@@ -106,16 +107,6 @@ func (enc *jsonEncoder) AddFloat64(key string, val float64) {
 	enc.bytes = strconv.AppendFloat(enc.bytes, val, 'g', -1, 64)
 }
 
-// UnsafeAddBytes adds a string key and an arbitrary byte slice to the encoder's
-// fields. The key is JSON-escaped, but the value isn't; if the value is not
-// itself valid JSON, it will make the entire fields buffer unparsable.
-//
-// Use this method with great care - it's unsafe!
-func (enc *jsonEncoder) UnsafeAddBytes(key string, val []byte) {
-	enc.addKey(key)
-	enc.bytes = append(enc.bytes, val...)
-}
-
 // Nest allows the caller to populate a nested object under the provided key.
 func (enc *jsonEncoder) Nest(key string, f func(KeyValue) error) error {
 	enc.addKey(key)
@@ -126,12 +117,25 @@ func (enc *jsonEncoder) Nest(key string, f func(KeyValue) error) error {
 }
 
 // AddMarshaler adds a LogMarshaler to the encoder's fields.
+//
+// TODO: Encode the error into the message instead of returning.
 func (enc *jsonEncoder) AddMarshaler(key string, obj LogMarshaler) error {
 	return enc.Nest(key, func(kv KeyValue) error {
 		return obj.MarshalLog(kv)
 	})
 }
 
+// AddObject uses reflection to add an arbitrary object to the logging context.
+func (enc *jsonEncoder) AddObject(key string, obj interface{}) {
+	marshaled, err := json.Marshal(obj)
+	if err != nil {
+		enc.AddString(key, err.Error())
+		return
+	}
+	enc.addKey(key)
+	enc.bytes = append(enc.bytes, marshaled...)
+}
+
 // Clone copies the current encoder, including any data already encoded.
 func (enc *jsonEncoder) Clone() encoder {
 	clone := newJSONEncoder()

json_encoder_test.go

@@ -104,14 +104,6 @@ func TestJSONAddFloat64(t *testing.T) {
 	})
 }
 
-func TestJSONUnsafeAddBytes(t *testing.T) {
-	withJSONEncoder(func(enc *jsonEncoder) {
-		// Keys should be escaped.
-		enc.UnsafeAddBytes(`baz\`, []byte(`{"inner":42}`))
-		assertJSON(t, `"foo":"bar","baz\\":{"inner":42}`, enc)
-	})
-}
-
 func TestJSONWriteMessage(t *testing.T) {
 	withJSONEncoder(func(enc *jsonEncoder) {
 		sink := bytes.NewBuffer(nil)
@@ -164,6 +156,18 @@ func TestJSONAddMarshaler(t *testing.T) {
 	})
 }
 
+func TestJSONAddObject(t *testing.T) {
+	withJSONEncoder(func(enc *jsonEncoder) {
+		enc.AddObject("nested", map[string]string{"loggable": "yes"})
+		assertJSON(t, `"foo":"bar","nested":{"loggable":"yes"}`, enc)
+	})
+
+	withJSONEncoder(func(enc *jsonEncoder) {
+		enc.AddObject("nested", map[int]string{42: "yes"})
+		assertJSON(t, `"foo":"bar","nested":"json: unsupported type: map[int]string"`, enc)
+	})
+}
+
 func TestJSONClone(t *testing.T) {
 	// The parent encoder is created with plenty of excess capacity.
 	parent := &jsonEncoder{bytes: make([]byte, 0, 128)}

keyvalue.go

@@ -31,6 +31,9 @@ type KeyValue interface {
 	AddInt(string, int)
 	AddInt64(string, int64)
 	AddMarshaler(string, LogMarshaler) error
+	// AddObject uses reflection to serialize arbitrary objects, so it's slow and
+	// allocation-heavy. Consider implementing the LogMarshaler interface instead.
+	AddObject(string, interface{})
 	AddString(string, string)
 	Nest(string, func(KeyValue) error) error
 }

logger.go

@@ -122,16 +122,6 @@ func (jl *jsonLogger) With(fields ...Field) Logger {
 	return clone
 }
 
-// WithUnsafeJSON adds a key and a slice of arbitrary bytes to the logging
-// context. It's highly unsafe, and intended only for use by the zbark wrappers.
-//
-// For details, see jsonEncoder.UnsafeAddBytes.
-func (jl *jsonLogger) WithUnsafeJSON(key string, val []byte) Logger {
-	clone := jl.With().(*jsonLogger)
-	clone.enc.(*jsonEncoder).UnsafeAddBytes(key, val)
-	return clone
-}
-
 func (jl *jsonLogger) StubTime() {
 	jl.alwaysEpoch = true
 }

logger_bench_test.go

@@ -29,22 +29,22 @@ import (
 )
 
 type user struct {
-	name      string
-	email     string
-	createdAt time.Time
+	Name      string
+	Email     string
+	CreatedAt time.Time
 }
 
 func (u user) MarshalLog(kv zap.KeyValue) error {
-	kv.AddString("name", u.name)
-	kv.AddString("email", u.email)
-	kv.AddInt64("created_at", u.createdAt.UnixNano())
+	kv.AddString("name", u.Name)
+	kv.AddString("email", u.Email)
+	kv.AddInt64("created_at", u.CreatedAt.UnixNano())
 	return nil
 }
 
 var _jane = user{
-	name:      "Jane Doe",
-	email:     "jane@test.com",
-	createdAt: time.Date(1980, 1, 1, 12, 0, 0, 0, time.UTC),
+	Name:      "Jane Doe",
+	Email:     "jane@test.com",
+	CreatedAt: time.Date(1980, 1, 1, 12, 0, 0, 0, time.UTC),
 }
 
 func withBenchedLogger(b *testing.B, f func(zap.Logger)) {
@@ -128,13 +128,14 @@ func BenchmarkStackField(b *testing.B) {
 func BenchmarkMarshalerField(b *testing.B) {
 	// Expect an extra allocation here, since casting the user struct to the
 	// zap.Marshaler interface costs an alloc.
-	u := user{
-		name:      "Jane Example",
-		email:     "jane@example.com",
-		createdAt: time.Unix(0, 0),
-	}
 	withBenchedLogger(b, func(log zap.Logger) {
-		log.Info("Arbitrary zap.LogMarshaler.", zap.Marshaler("user", u))
+		log.Info("Arbitrary zap.LogMarshaler.", zap.Marshaler("user", _jane))
+	})
+}
+
+func BenchmarkObjectField(b *testing.B) {
+	withBenchedLogger(b, func(log zap.Logger) {
+		log.Info("Reflection-based serialization.", zap.Object("user", _jane))
 	})
 }
 

logger_test.go

@@ -131,13 +131,6 @@ func TestJSONLoggerWith(t *testing.T) {
 	})
 }
 
-func TestJSONLoggerWithUnsafeJSON(t *testing.T) {
-	withJSONLogger(t, nil, func(jl *jsonLogger, output func() []string) {
-		jl.WithUnsafeJSON(`foo\`, []byte(`{"inner":42}`)).Debug("")
-		assertFields(t, jl, output, `{"foo\\":{"inner":42}}`)
-	})
-}
-
 func TestJSONLoggerDebug(t *testing.T) {
 	withJSONLogger(t, nil, func(jl *jsonLogger, output func() []string) {
 		jl.Debug("foo")

zbark/bark.go

@@ -21,7 +21,6 @@
 package zbark
 
 import (
-	"encoding/json"
 	"fmt"
 	"time"
 
@@ -30,26 +29,17 @@ import (
 	"github.com/uber-common/bark"
 )
 
-type unsafeJSONLogger interface {
-	zap.Logger
-	WithUnsafeJSON(string, []byte) zap.Logger
-}
-
 // Barkify wraps zap's JSON logger to make it compatible with the bark.Logger
-// interface. If passed a non-JSON zap.Logger, it panics.
+// interface.
 func Barkify(l zap.Logger) bark.Logger {
-	jsonLogger, ok := l.(unsafeJSONLogger)
-	if !ok {
-		panic("Barkify only works with zap's JSON logger.")
-	}
 	return &logger{
-		zl:     jsonLogger,
+		zl:     l,
 		fields: make(bark.Fields),
 	}
 }
 
 type logger struct {
-	zl     unsafeJSONLogger
+	zl     zap.Logger
 	fields bark.Fields
 }
 
@@ -132,9 +122,8 @@ func (l *logger) addBarkFields(fs bark.Fields) bark.Fields {
 	return newFields
 }
 
-func (l *logger) addZapFields(fs bark.Fields) unsafeJSONLogger {
+func (l *logger) addZapFields(fs bark.Fields) zap.Logger {
 	zfs := make([]zap.Field, 0, len(fs))
-	zl := l.zl
 	for key, val := range fs {
 		switch v := val.(type) {
 		case bool:
@@ -160,19 +149,8 @@ func (l *logger) addZapFields(fs bark.Fields) unsafeJSONLogger {
 		case fmt.Stringer:
 			zfs = append(zfs, zap.Stringer(key, v))
 		default:
-			jsonBytes, err := json.Marshal(v)
-			if err != nil {
-				// Even if JSON serialization fails, make sure we log something
-				// and include the error message.
-				zfs = append(zfs, zap.String(key, err.Error()))
-			} else {
-				zl = zl.WithUnsafeJSON(key, jsonBytes).(unsafeJSONLogger)
-			}
+			zfs = append(zfs, zap.Object(key, v))
 		}
-
-	}
-	if len(zfs) > 0 {
-		zl = zl.With(zfs...).(unsafeJSONLogger)
 	}
-	return zl
+	return l.zl.With(zfs...)
 }