support "structured error"

A "structured error" is an error which implements Error and MarshalLog.  When
encountering such an error, it gets logged normally and then another
"errDetails" field gets added with the result of MarshalLog.

The extra details are logged as if they had been passed as a value to
zapr. Beware that there is no protection against recursion here: if MarshalLog
returns the original value, infinite recursion occurs and 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.

Author: pohly

Diff for: 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,35 +160,63 @@ 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
 	}
 
 	return append(fields, additional...)
 }
 
-func zapIt(field string, val interface{}) zap.Field {
+func (zl *zapLogger) zapIt(field string, val interface{}) zap.Field {
+	if err, ok := val.(error); ok {
+		return zl.zapError(field, err)
+	}
+
 	// 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)
 	}
-	if keysAndValues, ok := val.(logr.KeysAndValues); ok {
+	switch val := val.(type) {
+	case logr.KeysAndValues:
 		return zap.Object(field, zapcore.ObjectMarshalerFunc(func(encoder zapcore.ObjectEncoder) error {
-			for _, keyAndValue := range keysAndValues {
+			for _, keyAndValue := range val {
 				encoder.AddReflected(keyAndValue.Key, keyAndValue.Value)
 			}
 			return nil
 		}))
 	}
+
 	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) (retErr 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 MarshalLog.
+		if logMarshaler, ok := err.(logr.Marshaler); ok {
+			func() {
+				if r := recover(); r != nil {
+					retErr = fmt.Errorf("PANIC=%v", r)
+				}
+				zl.zapIt(field+zl.errorKeyDetailsSuffix, logMarshaler.MarshalLog()).AddTo(encoder)
+			}()
+		}
+		return
+	}))
+}
+
 func invokeMarshaler(field string, m logr.Marshaler) (f string, ret interface{}) {
 	defer func() {
 		if r := recover(); r != nil {
@@ -221,10 +253,22 @@ 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))...)
 	}
 }
 
+// errorToString converts an error to a string,
+// handling panics if they occur.
+func errorToString(err error) (ret string) {
+	defer func() {
+		if err := recover(); err != nil {
+			ret = fmt.Sprintf("<panic: %s>", err)
+		}
+	}()
+	ret = err.Error()
+	return
+}
+
 func (zl *zapLogger) WithValues(keysAndValues ...interface{}) logr.LogSink {
 	newLogger := *zl
 	newLogger.l = zl.l.With(zl.handleFields(noLevel, keysAndValues)...)
@@ -269,6 +313,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)
@@ -298,6 +343,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.