handle panics in logr.Marshaler.MarshalLog

The function might panic. The conclusion in
go-logr/logr#130 was that the logger should
record that.

zapr only needs to do that when it calls MarshalLog. Strings and errors are
handled by zap.

For the sake of simplicity no attempt is made to detect the reason for the
panic. As zapr cannot replace the key, it uses the same replacement value as
funcr because that stands out a bit more compared to the value used by zap.

Author: pohly

zapr.go

@@ -54,6 +54,8 @@ limitations under the License.
 package zapr
 
 import (
+	"fmt"
+
 	"github.com/go-logr/logr"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
@@ -170,11 +172,20 @@ func 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 {
-		val = marshaler.MarshalLog()
+		val = invokeMarshaler(marshaler)
 	}
 	return zap.Any(field, val)
 }
 
+func invokeMarshaler(m logr.Marshaler) (ret interface{}) {
+	defer func() {
+		if r := recover(); r != nil {
+			ret = fmt.Sprintf("<panic: %s>", r)
+		}
+	}()
+	return m.MarshalLog()
+}
+
 func (zl *zapLogger) Init(ri logr.RuntimeInfo) {
 	zl.l = zl.l.WithOptions(zap.AddCallerSkip(ri.CallDepth))
 }

zapr_test.go

@@ -47,6 +47,40 @@ type discard struct{}
 
 func (d discard) Write(p []byte) (n int, err error) { return n, nil }
 
+type marshaler struct {
+	msg string
+}
+
+func (m *marshaler) String() string {
+	return m.msg
+}
+
+func (m *marshaler) MarshalLog() interface{} {
+	return "msg=" + m.msg
+}
+
+var _ fmt.Stringer = &marshaler{}
+var _ logr.Marshaler = &marshaler{}
+
+type stringer struct {
+	msg string
+}
+
+func (s *stringer) String() string {
+	return s.msg
+}
+
+var _ fmt.Stringer = &stringer{}
+
+type stringerPanic struct {
+}
+
+func (s *stringerPanic) String() string {
+	panic("fake panic")
+}
+
+var _ fmt.Stringer = &stringerPanic{}
+
 func newZapLogger(lvl zapcore.Level, w zapcore.WriteSyncer) *zap.Logger {
 	if w == nil {
 		w = zapcore.AddSync(discard{})
@@ -164,6 +198,33 @@ func TestInfo(t *testing.T) {
 `,
 			keysValues: []interface{}{"duration", time.Duration(5 * time.Second)},
 		},
+		{
+			msg: "valid marshaler",
+			format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"valid marshaler","v":0,"obj":"msg=hello"}
+`,
+			keysValues: []interface{}{"obj", &marshaler{msg: "hello"}},
+		},
+		{
+			msg: "nil marshaler",
+			// Handled by our code: it just formats the error.
+			format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"nil marshaler","v":0,"obj":"<panic: runtime error: invalid memory address or nil pointer dereference>"}
+`,
+			keysValues: []interface{}{"obj", (*marshaler)(nil)},
+		},
+		{
+			msg: "nil stringer",
+			// Handled by zap: it detects a nil pointer.
+			format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"nil stringer","v":0,"obj":"<nil>"}
+`,
+			keysValues: []interface{}{"obj", (*stringer)(nil)},
+		},
+		{
+			msg: "panic stringer",
+			// Handled by zap: it prints the panic, but using a different key and format than funcr.
+			format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"panic stringer","v":0,"objError":"PANIC=fake panic"}
+`,
+			keysValues: []interface{}{"obj", &stringerPanic{}},
+		},
 	}
 
 	test := func(t *testing.T, logNumeric *string, enablePanics *bool, allowZapFields *bool, data testCase) {