RFC: special types: structured error

README.md

@@ -105,3 +105,11 @@ The zapr `logr.LogSink` implementation also implements `logr.SlogHandler`. That
 enables `slogr.NewSlogHandler` to provide a `slog.Handler` which just passes
 parameters through to zapr. zapr handles special slog values (Group,
 LogValuer), regardless of which front-end API is used.
+
+The value logged for errors is the string returned by `error.Error`.
+If the error also implements `slog.LogValuer`, then it is treated as a
+"structured error" and the value returned by `slog.LogValuer.LogValue` is
+logged *in addition* to the error string, using a key that is the original
+key plus a "Details" suffix. For example, `"err", err` will be logged as if
+`"err", err.Error(), "errDetails", err.LogValue()` has been passed. This
+ensures that the "err" key is always associated with a string.

slogzapr.go

@@ -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
@@ -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
@@ -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(),
 		})
@@ -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 {
@@ -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
 }
 

zapr.go

@@ -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.
@@ -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
 		}
@@ -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
 	}
 
@@ -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))...)
 	}
 }
 
@@ -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)
@@ -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.

zapr_noslog.go

@@ -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)
+}

zapr_noslog_test.go

@@ -61,3 +61,7 @@ func slogValuer(value interface{}) interface{} {
 
 func logWithSlog(_ logr.Logger, _ string, _, _ []interface{}) {
 }
+
+func slogStructuredError() error {
+	return nil
+}

zapr_slog.go

@@ -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.
@@ -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
+	}))
+}

zapr_slog_test.go

@@ -77,3 +77,21 @@ func logWithSlog(l logr.Logger, msg string, withKeysValues, keysValues []interfa
 	}
 	logger.Info(msg, keysValues...)
 }
+
+func slogStructuredError() error {
+	return structuredError{}
+}
+
+type structuredError struct {
+}
+
+var _ error = structuredError{}
+var _ slog.LogValuer = structuredError{}
+
+func (err structuredError) Error() string {
+	return "hello world"
+}
+
+func (err structuredError) LogValue() slog.Value {
+	return slog.GroupValue(slog.Int("answer", 42), slog.String("thanks", "fish"))
+}

zapr_test.go

@@ -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) {