diff --git a/array.go b/array.go index 7052eb1ff..5e52f3d96 100644 --- a/array.go +++ b/array.go @@ -21,11 +21,16 @@ package zap import ( + "sync" "time" "go.uber.org/zap/zapcore" ) +var _errArrayElemPool = sync.Pool{New: func() interface{} { + return &errArrayElem{} +}} + // Array constructs a field with the given key and ArrayMarshaler. It provides // a flexible, but still type-safe and efficient, way to add array-like types // to the logging context. The struct's MarshalLogArray method is called lazily. @@ -311,7 +316,25 @@ func (errs errArray) MarshalLogArray(arr zapcore.ArrayEncoder) error { if errs[i] == nil { continue } - arr.AppendString(errs[i].Error()) + // To represent each error as an object with an "error" attribute and + // potentially an "errorVerbose" attribute, we need to wrap it in a + // type that implements LogObjectMarshaler. To prevent this from + // allocating, pool the wrapper type. + elem := _errArrayElemPool.Get().(*errArrayElem) + elem.error = errs[i] + arr.AppendObject(elem) + elem.error = nil + _errArrayElemPool.Put(elem) } return nil } + +type errArrayElem struct { + error +} + +func (e *errArrayElem) MarshalLogObject(enc zapcore.ObjectEncoder) error { + // Re-use the error field's logic, which supports non-standard error types. + Error(e.error).AddTo(enc) + return nil +} diff --git a/array_test.go b/array_test.go index 4b0d3ec44..0c7dc41be 100644 --- a/array_test.go +++ b/array_test.go @@ -25,8 +25,11 @@ import ( "testing" "time" - "github.com/stretchr/testify/assert" "go.uber.org/zap/zapcore" + + richErrors "github.com/pkg/errors" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" ) func BenchmarkBoolsArrayMarshaler(b *testing.B) { @@ -94,7 +97,11 @@ func TestArrayWrappers(t *testing.T) { {"uint16s", Uint16s("", []uint16{1, 2}), []interface{}{uint16(1), uint16(2)}}, {"uint8s", Uint8s("", []uint8{1, 2}), []interface{}{uint8(1), uint8(2)}}, {"uintptrs", Uintptrs("", []uintptr{1, 2}), []interface{}{uintptr(1), uintptr(2)}}, - {"errors", Errors("", []error{nil, errors.New("foo"), nil, errors.New("bar")}), []interface{}{"foo", "bar"}}, + { + "errors", + Errors("", []error{nil, errors.New("foo"), nil, errors.New("bar")}), + []interface{}{map[string]interface{}{"error": "foo"}, map[string]interface{}{"error": "bar"}}, + }, } for _, tt := range tests { @@ -105,3 +112,23 @@ func TestArrayWrappers(t *testing.T) { assert.Equal(t, 1, len(enc.Fields), "%s: found extra keys in map: %v", tt.desc, enc.Fields) } } + +func TestErrorsArraysHandleRichErrors(t *testing.T) { + errs := []error{richErrors.New("egad")} + + enc := zapcore.NewMapObjectEncoder() + Errors("k", errs).AddTo(enc) + assert.Equal(t, 1, len(enc.Fields), "Expected only top-level field.") + + val := enc.Fields["k"] + arr, ok := val.([]interface{}) + require.True(t, ok, "Expected top-level field to be an array.") + require.Equal(t, 1, len(arr), "Expected only one error object in array.") + + serialized := arr[0] + errMap, ok := serialized.(map[string]interface{}) + require.True(t, ok, "Expected serialized error to be a map, got %T.", serialized) + assert.Equal(t, "egad", errMap["error"], "Unexpected standard error string.") + assert.Contains(t, errMap["errorVerbose"], "egad", "Verbose error string should be a superset of standard error.") + assert.Contains(t, errMap["errorVerbose"], "TestErrorsArraysHandleRichErrors", "Verbose error string should contain a stacktrace.") +} diff --git a/field.go b/field.go index d0af48615..27be5c726 100644 --- a/field.go +++ b/field.go @@ -171,19 +171,23 @@ func Time(key string, val time.Time) zapcore.Field { return zapcore.Field{Key: key, Type: zapcore.TimeType, Integer: val.UnixNano()} } -// Error constructs a field that lazily stores err.Error() under the key -// "error". If passed a nil error, the field is a no-op. This is purely a -// convenience for a common error-logging idiom; use String("someFieldName", -// err.Error()) to customize the key. -// -// Errors which also implement fmt.Formatter (like those produced by -// github.com/pkg/errors) will also have their verbose representation stored -// under "errorVerbose". +// Error is shorthand for the common idiom NamedError("error", err). func Error(err error) zapcore.Field { + return NamedError("error", err) +} + +// NamedError constructs a field that lazily stores err.Error() under the +// provided key. Errors which also implement fmt.Formatter (like those produced +// by github.com/pkg/errors) will also have their verbose representation stored +// under key+"Verbose". If passed a nil error, the field is a no-op. +// +// For the common case in which the key is simply "error", the Error function +// is shorter and less repetitive. +func NamedError(key string, err error) zapcore.Field { if err == nil { return Skip() } - return zapcore.Field{Key: "error", Type: zapcore.ErrorType, Interface: err} + return zapcore.Field{Key: key, Type: zapcore.ErrorType, Interface: err} } // Stack constructs a field that stores a stacktrace of the current goroutine @@ -303,7 +307,7 @@ func Any(key string, value interface{}) zapcore.Field { case []time.Duration: return Durations(key, val) case error: - return String(key, val.Error()) + return NamedError(key, val) case []error: return Errors(key, val) case fmt.Stringer: diff --git a/field_test.go b/field_test.go index 16503041e..6de2bd431 100644 --- a/field_test.go +++ b/field_test.go @@ -100,12 +100,14 @@ func TestFieldConstructors(t *testing.T) { {"Reflect", zapcore.Field{Key: "k", Type: zapcore.ReflectType, Interface: ints}, Reflect("k", ints)}, {"Error", Skip(), Error(nil)}, {"Error", zapcore.Field{Key: "error", Type: zapcore.ErrorType, Interface: fail}, Error(fail)}, + {"NamedError", Skip(), NamedError("foo", nil)}, + {"NamedError", zapcore.Field{Key: "foo", Type: zapcore.ErrorType, Interface: fail}, NamedError("foo", fail)}, {"Stringer", zapcore.Field{Key: "k", Type: zapcore.StringerType, Interface: addr}, Stringer("k", addr)}, {"Object", zapcore.Field{Key: "k", Type: zapcore.ObjectMarshalerType, Interface: name}, Object("k", name)}, {"Any:ObjectMarshaler", Any("k", name), Object("k", name)}, {"Any:ArrayMarshaler", Any("k", bools([]bool{true})), Array("k", bools([]bool{true}))}, {"Any:Stringer", Any("k", addr), Stringer("k", addr)}, - {"Any:Error", Any("k", errors.New("v")), String("k", "v")}, + {"Any:Error", Any("k", errors.New("v")), NamedError("k", errors.New("v"))}, {"Any:Errors", Any("k", []error{errors.New("v")}), Errors("k", []error{errors.New("v")})}, {"Any:Bool", Any("k", true), Bool("k", true)}, {"Any:Bools", Any("k", []bool{true}), Bools("k", []bool{true})}, diff --git a/logger_bench_test.go b/logger_bench_test.go index df9814e94..1cc504abf 100644 --- a/logger_bench_test.go +++ b/logger_bench_test.go @@ -125,6 +125,18 @@ func BenchmarkErrorField(b *testing.B) { }) } +func BenchmarkErrorsField(b *testing.B) { + errs := []error{ + errors.New("egad"), + errors.New("oh no"), + errors.New("dear me"), + errors.New("such fail"), + } + withBenchedLogger(b, func(log *Logger) { + log.Info("Errors.", Errors("errors", errs)) + }) +} + func BenchmarkStackField(b *testing.B) { withBenchedLogger(b, func(log *Logger) { log.Info("Error.", Stack("stacktrace"))