Skip to content

Commit

Permalink
support "structured error"
Browse files Browse the repository at this point in the history
A "structured error" is an error which implements error and slog.LogValuer.
When encountering such an error, it gets logged normally and then another field
gets added with the result of LogValue().

The name of the extra field is the original field name plus a configurable
suffix, with "Details" as default.

The extra details are logged as if they had been passed as a value to
zapr. slog.Value.Resolve is used to protect against errors and recursion while
calling LogValue, but does not protect against recursion that can occur when
LogValue returns the original error: then zapIt->zapError->zapIt->... repeats
until the program gets killed.

A simple guard against this (not expanding error again while formatting an
error) is too simplistic and would prevent nice rendering of a wrapped error
that might get returned by MarshalLog. zapIt would have to track the exact
error instance and detect when it gets the same value again.
  • Loading branch information
pohly committed Nov 21, 2023
1 parent 78b8af5 commit d9d92da
Show file tree
Hide file tree
Showing 7 changed files with 105 additions and 22 deletions.
31 changes: 20 additions & 11 deletions slogzapr.go
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@ func (zl *zapLogger) Handle(_ context.Context, record slog.Record) error {
// Inline all attributes.
fields = append(fields, zap.Inline(zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error {
record.Attrs(func(attr slog.Attr) bool {
encodeSlog(enc, attr)
zl.encodeSlog(enc, attr)
return true
})
return nil
Expand All @@ -70,7 +70,7 @@ func (zl *zapLogger) Handle(_ context.Context, record slog.Record) error {
return nil
}

func encodeSlog(enc zapcore.ObjectEncoder, attr slog.Attr) {
func (zl *zapLogger) encodeSlog(enc zapcore.ObjectEncoder, attr slog.Attr) {
if attr.Equal(slog.Attr{}) {
// Ignore empty attribute.
return
Expand Down Expand Up @@ -102,8 +102,14 @@ func encodeSlog(enc zapcore.ObjectEncoder, attr slog.Attr) {
case slog.KindString:
enc.AddString(attr.Key, attr.Value.String())
case slog.KindLogValuer:
// Structured error?
if err, ok := attr.Value.Any().(error); ok {
zl.zapError(attr.Key, err).AddTo(enc)
return
}

// This includes klog.KObj.
encodeSlog(enc, slog.Attr{
zl.encodeSlog(enc, slog.Attr{
Key: attr.Key,
Value: attr.Value.Resolve(),
})
Expand All @@ -124,32 +130,35 @@ func encodeSlog(enc zapcore.ObjectEncoder, attr slog.Attr) {
if attr.Key == "" {
// Inline group.
for _, attr := range attrs {
encodeSlog(enc, attr)
zl.encodeSlog(enc, attr)
}
return
}
if len(attrs) == 0 {
// Ignore empty group.
return
}
_ = enc.AddObject(attr.Key, marshalAttrs(attrs))
_ = enc.AddObject(attr.Key, marshalAttrs{zl: zl, attrs: attrs})
default:
// We have to go through reflection in zap.Any to get support
// for e.g. fmt.Stringer.
zap.Any(attr.Key, attr.Value.Any()).AddTo(enc)
}
}

type marshalAttrs []slog.Attr
type marshalAttrs struct {
zl *zapLogger
attrs []slog.Attr
}

func (attrs marshalAttrs) MarshalLogObject(enc zapcore.ObjectEncoder) error {
for _, attr := range attrs {
encodeSlog(enc, attr)
func (m marshalAttrs) MarshalLogObject(enc zapcore.ObjectEncoder) error {
for _, attr := range m.attrs {
m.zl.encodeSlog(enc, attr)
}
return nil
}

var _ zapcore.ObjectMarshaler = marshalAttrs(nil)
var _ zapcore.ObjectMarshaler = marshalAttrs{}

func pcToCallerEntry(pc uintptr) zapcore.EntryCaller {
if pc == 0 {
Expand All @@ -172,7 +181,7 @@ func pcToCallerEntry(pc uintptr) zapcore.EntryCaller {

func (zl *zapLogger) WithAttrs(attrs []slog.Attr) slogr.SlogSink {
newLogger := *zl
newLogger.l = newLogger.l.With(zap.Inline(marshalAttrs(attrs)))
newLogger.l = newLogger.l.With(zap.Inline(marshalAttrs{zl: zl, attrs: attrs}))
return &newLogger
}

Expand Down
24 changes: 19 additions & 5 deletions zapr.go
Original file line number Diff line number Diff line change
Expand Up @@ -81,6 +81,10 @@ type zapLogger struct {
// Logger.Error calls.
errorKey string

// errorKeyDetailsSuffix gets appended to the field name
// when logging additional details obtained via MarshalLog.
errorKeyDetailsSuffix string

// allowZapFields enables logging of strongly-typed Zap
// fields. It is off by default because it breaks
// implementation agnosticism.
Expand Down Expand Up @@ -136,15 +140,15 @@ func (zl *zapLogger) handleFields(lvl int, args []interface{}, additional ...zap
continue
}
if zl.panicMessages {
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("strongly-typed Zap Field passed to logr", zapIt("zap field", args[i]))
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("strongly-typed Zap Field passed to logr", zl.zapIt("zap field", args[i]))
}
break
}

// make sure this isn't a mismatched key
if i == len(args)-1 {
if zl.panicMessages {
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("odd number of arguments passed as key-value pairs for logging", zapIt("ignored key", args[i]))
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("odd number of arguments passed as key-value pairs for logging", zl.zapIt("ignored key", args[i]))
}
break
}
Expand All @@ -156,12 +160,12 @@ func (zl *zapLogger) handleFields(lvl int, args []interface{}, additional ...zap
if !isString {
// if the key isn't a string, DPanic and stop logging
if zl.panicMessages {
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("non-string key argument passed to logging, ignoring all later arguments", zapIt("invalid key", key))
zl.l.WithOptions(zap.AddCallerSkip(1)).DPanic("non-string key argument passed to logging, ignoring all later arguments", zl.zapIt("invalid key", key))
}
break
}

fields = append(fields, zapIt(keyStr, val))
fields = append(fields, zl.zapIt(keyStr, val))
i += 2
}

Expand Down Expand Up @@ -204,7 +208,7 @@ func (zl *zapLogger) Info(lvl int, msg string, keysAndVals ...interface{}) {

func (zl *zapLogger) Error(err error, msg string, keysAndVals ...interface{}) {
if checkedEntry := zl.l.Check(zap.ErrorLevel, msg); checkedEntry != nil {
checkedEntry.Write(zl.handleFields(noLevel, keysAndVals, zap.NamedError(zl.errorKey, err))...)
checkedEntry.Write(zl.handleFields(noLevel, keysAndVals, zl.zapError(zl.errorKey, err))...)
}
}

Expand Down Expand Up @@ -252,6 +256,7 @@ func NewLoggerWithOptions(l *zap.Logger, opts ...Option) logr.Logger {
l: log,
}
zl.errorKey = "error"
zl.errorKeyDetailsSuffix = "Details"
zl.panicMessages = true
for _, option := range opts {
option(zl)
Expand Down Expand Up @@ -281,6 +286,15 @@ func ErrorKey(key string) Option {
}
}

// ErrorKeyDetailsSuffix replaces the default "Details" suffix that gets
// appended to the field name for an error when logging the error details
// obtained through MarshalLog.
func ErrorKeyDetailsSuffix(key string) Option {
return func(zl *zapLogger) {
zl.errorKeyDetailsSuffix = key
}
}

// AllowZapFields controls whether strongly-typed Zap fields may
// be passed instead of a key/value pair. This is disabled by
// default because it breaks implementation agnosticism.
Expand Down
6 changes: 5 additions & 1 deletion zapr_noslog.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,11 +24,15 @@ import (
"go.uber.org/zap"
)

func zapIt(field string, val interface{}) zap.Field {
func (zl *zapLogger) zapIt(field string, val interface{}) zap.Field {
// Handle types that implement logr.Marshaler: log the replacement
// object instead of the original one.
if marshaler, ok := val.(logr.Marshaler); ok {
field, val = invokeMarshaler(field, marshaler)
}
return zap.Any(field, val)
}

func (zl *zapLogger) zapError(field string, err error) zap.Field {
return zap.NamedError(field, err)
}
4 changes: 4 additions & 0 deletions zapr_noslog_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -61,3 +61,7 @@ func slogValuer(value interface{}) interface{} {

func logWithSlog(_ logr.Logger, _ string, _, _ []interface{}) {
}

func slogStructuredError() error {
return nil
}
35 changes: 30 additions & 5 deletions zapr_slog.go
Original file line number Diff line number Diff line change
Expand Up @@ -27,8 +27,10 @@ import (
"go.uber.org/zap/zapcore"
)

func zapIt(field string, val interface{}) zap.Field {
func (zl *zapLogger) zapIt(field string, val interface{}) zap.Field {
switch valTyped := val.(type) {
case error:
return zl.zapError(field, valTyped)
case logr.Marshaler:
// Handle types that implement logr.Marshaler: log the replacement
// object instead of the original one.
Expand All @@ -39,10 +41,33 @@ func zapIt(field string, val interface{}) zap.Field {
val = slog.AnyValue(val).Resolve()
}
if slogValue, ok := val.(slog.Value); ok {
return zap.Inline(zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error {
encodeSlog(enc, slog.Attr{Key: field, Value: slogValue})
return nil
}))
return zl.zapInline(field, slogValue)
}
return zap.Any(field, val)
}

func (zl *zapLogger) zapError(field string, err error) zap.Field {
if err == nil {
return zap.Skip()
}
return zap.Inline(zapcore.ObjectMarshalerFunc(func(encoder zapcore.ObjectEncoder) error {
// Always log as a normal error first.
zap.NamedError(field, err).AddTo(encoder)

// Extra details are optional, but might be available if the error also
// implements slog.LogValuer.
if valuer, ok := err.(slog.LogValuer); ok {
value := slog.AnyValue(valuer)
value = value.Resolve()
zl.zapInline(field+zl.errorKeyDetailsSuffix, value).AddTo(encoder)
}
return nil
}))
}

func (zl *zapLogger) zapInline(key string, value slog.Value) zap.Field {
return zap.Inline(zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error {
zl.encodeSlog(enc, slog.Attr{Key: key, Value: value})
return nil
}))
}
20 changes: 20 additions & 0 deletions zapr_slog_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ limitations under the License.
package zapr_test

import (
"errors"
"log/slog"

"github.com/go-logr/logr"
Expand Down Expand Up @@ -77,3 +78,22 @@ func logWithSlog(l logr.Logger, msg string, withKeysValues, keysValues []interfa
}
logger.Info(msg, keysValues...)
}

func slogStructuredError() error {
return structuredError{
error: errors.New("hello world"),
Value: slog.GroupValue(slog.Int("answer", 42), slog.String("thanks", "fish")),
}
}

type structuredError struct {
error
slog.Value
}

var _ error = structuredError{}
var _ slog.LogValuer = structuredError{}

func (err structuredError) LogValue() slog.Value {
return err.Value
}
7 changes: 7 additions & 0 deletions zapr_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -270,6 +270,13 @@ func TestInfo(t *testing.T) {
keysValues: []interface{}{slogGroup("obj", slogInt("int", 1), slogString("string", "hello"))},
needSlog: true,
},
{
msg: "structured error",
formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"structured error","v":0,"myerr":"hello world","myerrDetails":{"answer":42,"thanks":"fish"}}
`,
keysValues: []interface{}{"myerr", slogStructuredError()},
needSlog: true,
},
}

test := func(t *testing.T, logNumeric *string, enablePanics *bool, allowZapFields *bool, useSlog bool, data testCase) {
Expand Down

0 comments on commit d9d92da

Please sign in to comment.