From af7b868f177dc6c41787a86be104a3155ffe2192 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 28 Jan 2022 20:32:29 -0800 Subject: [PATCH 1/2] Add stringer, error, marshaler to benchmark --- benchmark/benchmark_test.go | 54 +++++++++++++++++++++++++++++++++++++ 1 file changed, 54 insertions(+) diff --git a/benchmark/benchmark_test.go b/benchmark/benchmark_test.go index a165cf4..cd111bc 100644 --- a/benchmark/benchmark_test.go +++ b/benchmark/benchmark_test.go @@ -102,6 +102,45 @@ func doWithCallDepth(b *testing.B, log logr.Logger) { } } +type Tstringer struct{ s string } + +func (t Tstringer) String() string { + return t.s +} + +//go:noinline +func doStringerValue(b *testing.B, log logr.Logger) { + for i := 0; i < b.N; i++ { + log.Info("this is", "a", Tstringer{"stringer"}) + } +} + +type Terror struct{ s string } + +func (t Terror) Error() string { + return t.s +} + +//go:noinline +func doErrorValue(b *testing.B, log logr.Logger) { + for i := 0; i < b.N; i++ { + log.Info("this is", "an", Terror{"error"}) + } +} + +type Tmarshaler struct{ s string } + +func (t Tmarshaler) MarshalLog() interface{} { + return t.s +} + +//go:noinline +func doMarshalerValue(b *testing.B, log logr.Logger) { + for i := 0; i < b.N; i++ { + log.Info("this is", "a", Tmarshaler{"marshaler"}) + } +} + func BenchmarkDiscardLogInfoOneArg(b *testing.B) { var log logr.Logger = logr.Discard() doInfoOneArg(b, log) @@ -219,3 +258,18 @@ func BenchmarkFuncrWithCallDepth(b *testing.B) { var log logr.Logger = funcr.New(noopKV, funcr.Options{}) doWithCallDepth(b, log) } + +func BenchmarkFuncrJSONLogInfoStringerValue(b *testing.B) { + var log logr.Logger = funcr.NewJSON(noopJSON, funcr.Options{}) + doStringerValue(b, log) +} + +func BenchmarkFuncrJSONLogInfoErrorValue(b *testing.B) { + var log logr.Logger = funcr.NewJSON(noopJSON, funcr.Options{}) + doErrorValue(b, log) +} + +func BenchmarkFuncrJSONLogInfoMarshalerValue(b *testing.B) { + var log logr.Logger = funcr.NewJSON(noopJSON, funcr.Options{}) + doMarshalerValue(b, log) +} From 945d619423e9f2330c72cb63523671c8513ce85f Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Wed, 19 Jan 2022 13:49:55 -0800 Subject: [PATCH 2/2] funcr: Handle panic in Stringer, Marshaler, error Produce a maybe-useful error rather than panic when we are in the middle of logging a value (similar to fmt.Printf). --- funcr/funcr.go | 33 ++++++++++++++++++-- funcr/funcr_test.go | 76 +++++++++++++++++++++++++++++++++++++++++---- 2 files changed, 100 insertions(+), 9 deletions(-) diff --git a/funcr/funcr.go b/funcr/funcr.go index 166e245..7accdb0 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -351,15 +351,15 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s if v, ok := value.(logr.Marshaler); ok { // Replace the value with what the type wants to get logged. // That then gets handled below via reflection. - value = v.MarshalLog() + value = invokeMarshaler(v) } // Handle types that want to format themselves. switch v := value.(type) { case fmt.Stringer: - value = v.String() + value = invokeStringer(v) case error: - value = v.Error() + value = invokeError(v) } // Handling the most common types without reflect is a small perf win. @@ -597,6 +597,33 @@ func isEmpty(v reflect.Value) bool { return false } +func invokeMarshaler(m logr.Marshaler) (ret interface{}) { + defer func() { + if r := recover(); r != nil { + ret = fmt.Sprintf("", r) + } + }() + return m.MarshalLog() +} + +func invokeStringer(s fmt.Stringer) (ret string) { + defer func() { + if r := recover(); r != nil { + ret = fmt.Sprintf("", r) + } + }() + return s.String() +} + +func invokeError(e error) (ret string) { + defer func() { + if r := recover(); r != nil { + ret = fmt.Sprintf("", r) + } + }() + return e.Error() +} + // Caller represents the original call site for a log line, after considering // logr.Logger.WithCallDepth and logr.Logger.WithCallStackHelper. The File and // Line fields will always be provided, while the Func field is optional. diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index a6da5b6..8693810 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -52,7 +52,7 @@ func (p pointErr) MarshalText() ([]byte, error) { } // Logging this should result in the MarshalLog() value. -type Tmarshaler string +type Tmarshaler struct{ val string } func (t Tmarshaler) MarshalLog() interface{} { return struct{ Inner string }{"I am a logr.Marshaler"} @@ -66,8 +66,15 @@ func (t Tmarshaler) Error() string { return "Error(): you should not see this" } +// Logging this should result in a panic. +type Tmarshalerpanic struct{ val string } + +func (t Tmarshalerpanic) MarshalLog() interface{} { + panic("Tmarshalerpanic") +} + // Logging this should result in the String() value. -type Tstringer string +type Tstringer struct{ val string } func (t Tstringer) String() string { return "I am a fmt.Stringer" @@ -77,6 +84,27 @@ func (t Tstringer) Error() string { return "Error(): you should not see this" } +// Logging this should result in a panic. +type Tstringerpanic struct{ val string } + +func (t Tstringerpanic) String() string { + panic("Tstringerpanic") +} + +// Logging this should result in the Error() value. +type Terror struct{ val string } + +func (t Terror) Error() string { + return "I am an error" +} + +// Logging this should result in a panic. +type Terrorpanic struct{ val string } + +func (t Terrorpanic) Error() string { + panic("Terrorpanic") +} + type TjsontagsString struct { String1 string `json:"string1"` // renamed String2 string `json:"-"` // ignored @@ -351,16 +379,52 @@ func TestPretty(t *testing.T) { }, }, { - val: Tmarshaler("foobar"), + val: Tmarshaler{"foobar"}, exp: `{"Inner":"I am a logr.Marshaler"}`, }, { - val: Tstringer("foobar"), + val: &Tmarshaler{"foobar"}, + exp: `{"Inner":"I am a logr.Marshaler"}`, + }, + { + val: (*Tmarshaler)(nil), + exp: `""`, + }, + { + val: Tmarshalerpanic{"foobar"}, + exp: `""`, + }, + { + val: Tstringer{"foobar"}, + exp: `"I am a fmt.Stringer"`, + }, + { + val: &Tstringer{"foobar"}, exp: `"I am a fmt.Stringer"`, }, { - val: fmt.Errorf("error"), - exp: `"error"`, + val: (*Tstringer)(nil), + exp: `""`, + }, + { + val: Tstringerpanic{"foobar"}, + exp: `""`, + }, + { + val: Terror{"foobar"}, + exp: `"I am an error"`, + }, + { + val: &Terror{"foobar"}, + exp: `"I am an error"`, + }, + { + val: (*Terror)(nil), + exp: `""`, + }, + { + val: Terrorpanic{"foobar"}, + exp: `""`, }, { val: TjsontagsString{