diff --git a/examples/go.mod b/examples/go.mod index a260ac36..8e4ce287 100644 --- a/examples/go.mod +++ b/examples/go.mod @@ -5,7 +5,7 @@ go 1.22.0 toolchain go1.23.0 require ( - github.com/go-logr/logr v1.4.1 + github.com/go-logr/logr v1.4.3 github.com/go-logr/zapr v1.2.3 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b go.uber.org/goleak v1.1.12 diff --git a/examples/go.sum b/examples/go.sum index 6256519d..f38450f4 100644 --- a/examples/go.sum +++ b/examples/go.sum @@ -4,8 +4,8 @@ github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= -github.com/go-logr/logr v1.4.1 h1:pKouT5E8xu9zeFC39JXRDukb6JFQPXM5p5I91188VAQ= -github.com/go-logr/logr v1.4.1/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= +github.com/go-logr/logr v1.4.3 h1:CjnDlHq8ikf6E492q6eKboGOC0T8CDaOvkHCIg8idEI= +github.com/go-logr/logr v1.4.3/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-logr/zapr v1.2.3/go.mod h1:eIauM6P8qSvTw5o2ez6UEAfGjQKrxQTl5EoK+Qa2oG4= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b h1:VKtxabqXZkF25pY9ekfRL6a582T4P37/31XEstQ5p58= diff --git a/go.mod b/go.mod index ced285f9..669662c9 100644 --- a/go.mod +++ b/go.mod @@ -2,4 +2,4 @@ module k8s.io/klog/v2 go 1.21 -require github.com/go-logr/logr v1.4.1 +require github.com/go-logr/logr v1.4.3 diff --git a/go.sum b/go.sum index 0934eaae..2bdbbf64 100644 --- a/go.sum +++ b/go.sum @@ -1,2 +1,4 @@ github.com/go-logr/logr v1.4.1 h1:pKouT5E8xu9zeFC39JXRDukb6JFQPXM5p5I91188VAQ= github.com/go-logr/logr v1.4.1/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= +github.com/go-logr/logr v1.4.3 h1:CjnDlHq8ikf6E492q6eKboGOC0T8CDaOvkHCIg8idEI= +github.com/go-logr/logr v1.4.3/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= diff --git a/imports.go b/imports.go index 602c3ed9..132b54ea 100644 --- a/imports.go +++ b/imports.go @@ -18,20 +18,28 @@ package klog import ( "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" ) // The reason for providing these aliases is to allow code to work with logr // without directly importing it. -// Logger in this package is exactly the same as logr.Logger. +// Logger in this package is exactly the same as [logr.Logger]. type Logger = logr.Logger -// LogSink in this package is exactly the same as logr.LogSink. +// LogSink in this package is exactly the same as [logr.LogSink]. type LogSink = logr.LogSink -// Runtimeinfo in this package is exactly the same as logr.RuntimeInfo. +// Runtimeinfo in this package is exactly the same as [logr.RuntimeInfo]. type RuntimeInfo = logr.RuntimeInfo +// Marshaler in this package is exactly the same as [logr.Marshaler]. +type Marshaler = logr.Marshaler + +// PseudoStruct in this package is exactly the same as [funcr.PseudoStruct]. +// Use it as a value to render some key/value pairs like a struct. +type PseudoStruct = funcr.PseudoStruct + var ( // New is an alias for logr.New. New = logr.New diff --git a/internal/serialize/keyvalues.go b/internal/serialize/keyvalues.go index 9c3858ec..89f7e4c9 100644 --- a/internal/serialize/keyvalues.go +++ b/internal/serialize/keyvalues.go @@ -246,6 +246,18 @@ func ErrorToString(err error) (ret string) { return } +// ErrorDetailerToDetails gets the error details, +// handing panics if they occur. +func ErrorDetailerToDetails(details func() any) (ret any) { + defer func() { + if err := recover(); err != nil { + ret = fmt.Sprintf("", err) + } + }() + ret = details() + return +} + func writeTextWriterValue(b *bytes.Buffer, v textWriter) { b.WriteByte('=') defer func() { @@ -299,3 +311,17 @@ func writeStringValue(b *bytes.Buffer, v string) { b.WriteString("\n >") } } + +func (f Formatter) writePseudoStruct(b *bytes.Buffer, keysAndValues []interface{}) { + b.WriteString("={") + for i := 0; i < len(keysAndValues); i += 2 { + var value interface{} + if i+1 < len(keysAndValues) { + value = keysAndValues[i+1] + } else { + value = missingValue + } + f.FormatKVs(b, []any{keysAndValues[i], value}) + } + b.WriteString(" }") +} diff --git a/internal/serialize/keyvalues_no_slog.go b/internal/serialize/keyvalues_no_slog.go index b8c7e443..07ee564d 100644 --- a/internal/serialize/keyvalues_no_slog.go +++ b/internal/serialize/keyvalues_no_slog.go @@ -24,8 +24,13 @@ import ( "fmt" "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" ) +type errorDetailer interface { + ErrorDetails() any +} + // KVFormat serializes one key/value pair into the provided buffer. // A space gets inserted before the pair. func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { @@ -61,6 +66,11 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { writeStringValue(b, v) case error: writeStringValue(b, ErrorToString(v)) + // It might provide additional details. + if v, ok := v.(errorDetailer); ok { + value := ErrorDetailerToDetails(v.ErrorDetails) + f.FormatKVs(b, []any{key + "Details", value}) + } case logr.Marshaler: value := MarshalerToValue(v) // A marshaler that returns a string is useful for @@ -76,6 +86,8 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { switch value := value.(type) { case string: writeStringValue(b, value) + case funcr.PseudoStruct: + f.writePseudoStruct(b, []interface{}(v)) default: f.formatAny(b, value) } @@ -93,6 +105,8 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { // convert the value to string before logging it. b.WriteByte('=') b.WriteString(fmt.Sprintf("%+q", v)) + case funcr.PseudoStruct: + f.writePseudoStruct(b, []interface{}(v)) default: f.formatAny(b, v) } diff --git a/internal/serialize/keyvalues_slog.go b/internal/serialize/keyvalues_slog.go index 8e008436..414defc0 100644 --- a/internal/serialize/keyvalues_slog.go +++ b/internal/serialize/keyvalues_slog.go @@ -26,13 +26,18 @@ import ( "strconv" "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" ) +type errorDetailer interface { + ErrorDetails() any +} + // KVFormat serializes one key/value pair into the provided buffer. // A space gets inserted before the pair. It returns the key. func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { - // This is the version without slog support. Must be kept in sync with - // the version in keyvalues_slog.go. + // This is the version with slog support. Must be kept in sync with + // the version in keyvalues_no_slog.go. b.WriteByte(' ') // Keys are assumed to be well-formed according to @@ -71,6 +76,11 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { writeStringValue(b, v) case error: writeStringValue(b, ErrorToString(v)) + // It might provide additional details. + if v, ok := v.(errorDetailer); ok { + value := ErrorDetailerToDetails(v.ErrorDetails) + f.FormatKVs(b, []any{key + "Details", value}) + } case logr.Marshaler: value := MarshalerToValue(v) // A marshaler that returns a string is useful for @@ -86,6 +96,8 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { switch value := value.(type) { case string: writeStringValue(b, value) + case funcr.PseudoStruct: + f.writePseudoStruct(b, []interface{}(value)) default: f.formatAny(b, value) } @@ -111,6 +123,8 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) string { // convert the value to string before logging it. b.WriteByte('=') b.WriteString(fmt.Sprintf("%+q", v)) + case funcr.PseudoStruct: + f.writePseudoStruct(b, []interface{}(v)) default: f.formatAny(b, v) } diff --git a/structured_error.go b/structured_error.go new file mode 100644 index 00000000..68b70723 --- /dev/null +++ b/structured_error.go @@ -0,0 +1,106 @@ +/* +Copyright The Kubernetes Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package klog + +import "slices" + +// ErrorDetailer provides additional information about an error. +// When an error value implements this additional interface, +// the result of ErrorDetails will be logged in a separate key/value +// pair. The result of Error is logged as usual. +// +// In Kubernetes, text and JSON output backends (aka klog and zapr) +// will support this with "Details" (typically "errDetails") +// as key for the additional value. +// +// Other backends might not support this, so all relevant information +// should be in the error string. +type ErrorDetailer interface { + ErrorDetails() any +} + +// ErrorWithDetails adds additional details to an error for logging. +// If the base error already has such additional details, they +// will be included in a list of details. +// +// A [PseudoStruct] can be used to log some key/value pairs as +// if they were in a struct, without having to define such a struct. +// The formatting may be nicer, too. +func ErrorWithDetails(err error, details any) error { + // This could be implemented as ErrorWithDetailsFunc(err, func() { return details }), + // but having the details visible in the error instance may be more useful for + // interactive debugging. + return &errWithDetails{err, details} +} + +type errWithDetails struct { + error + details any +} + +var _ error = &errWithDetails{} +var _ ErrorDetailer = &errWithDetails{} + +func (err *errWithDetails) ErrorDetails() any { + if base, ok := err.error.(ErrorDetailer); ok { + baseDetails := base.ErrorDetails() + if baseDetailsList, ok := baseDetails.([]any); ok { + // Flatten the list. + return append(slices.Clone(baseDetailsList), err.details) + } + // Use a pair of values in a slice which gets detected above when nesting multiple times. + return []any{baseDetails, err.details} + } + return err.details +} + +// ErrorWithDetailsFunc adds additional details to an error for logging. +// In contrast to [ErrorWithDetails], the additional details are provided +// by the given function, which will be called only when needed. This +// can be used to avoid building some potentially expensive data structure +// that will not be needed when the error does not get logged. +// +// If the base error already has such additional details, they +// will be included in a list of details. +// +// A [PseudoStruct] can be used to log some key/value pairs as +// if they were in a struct, without having to define such a struct. +// The formatting may be nicer, too. +func ErrorWithDetailsFunc(err error, details func() any) error { + return &errWithDetailsFunc{err, details} +} + +type errWithDetailsFunc struct { + error + details func() any +} + +var _ error = &errWithDetailsFunc{} +var _ ErrorDetailer = &errWithDetailsFunc{} + +func (err *errWithDetailsFunc) ErrorDetails() any { + if base, ok := err.error.(ErrorDetailer); ok { + baseDetails := base.ErrorDetails() + if baseDetailsList, ok := baseDetails.([]any); ok { + // Flatten the list. + return append(slices.Clone(baseDetailsList), err.details()) + } + // Use a pair of values in a slice which gets detected above when nesting multiple times. + return []any{baseDetails, err.details()} + } + return err.details() +} diff --git a/structured_error_test.go b/structured_error_test.go new file mode 100644 index 00000000..ab18310d --- /dev/null +++ b/structured_error_test.go @@ -0,0 +1,50 @@ +/* +Copyright The Kubernetes Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package klog + +import ( + "errors" + "reflect" + "testing" +) + +func TestErrorDetails(t *testing.T) { + base := errors.New("base") + + for name, tc := range map[string]struct { + err error + expectErrorString string + expectErrorDetails any + }{ + "simple": {ErrorWithDetails(base, 42), "base", 42}, + "pair": {ErrorWithDetails(ErrorWithDetails(base, "hello"), "world"), "base", []any{"hello", "world"}}, + "nested": {ErrorWithDetails(ErrorWithDetails(ErrorWithDetails(base, "hello"), "world"), "thanks"), "base", []any{"hello", "world", "thanks"}}, + + "simple-func": {ErrorWithDetailsFunc(base, func() any { return 42 }), "base", 42}, + "pair-func": {ErrorWithDetailsFunc(ErrorWithDetails(base, "hello"), func() any { return "world" }), "base", []any{"hello", "world"}}, + "nested-func": {ErrorWithDetailsFunc(ErrorWithDetails(ErrorWithDetails(base, "hello"), "world"), func() any { return "thanks" }), "base", []any{"hello", "world", "thanks"}}, + } { + t.Run(name, func(t *testing.T) { + if actual, expect := tc.err.Error(), tc.expectErrorString; actual != expect { + t.Errorf("expected error string %q, got %q", expect, actual) + } + if actual, expect := tc.err.(ErrorDetailer).ErrorDetails(), tc.expectErrorDetails; !reflect.DeepEqual(actual, expect) { + t.Errorf("expected error details %#v, got %#v", expect, actual) + } + }) + } +} diff --git a/test/output.go b/test/output.go index c56a46e9..49b5a133 100644 --- a/test/output.go +++ b/test/output.go @@ -33,6 +33,7 @@ import ( "time" "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" "k8s.io/klog/v2" "k8s.io/klog/v2/textlogger" @@ -410,6 +411,52 @@ I output.go:] "test" firstKey=1 secondKey=3 expectedOutput: `I output.go:] "structs" s={"Name":"worker","Kind":"pod"} `, }, + "structured error": { + text: "structured error", + err: structuredError{error: errors.New("fake error"), details: funcr.PseudoStruct{"x", 1, "y", "multi-line\nstring"}}, + expectedOutput: `E output.go:] "structured error" err="fake error" errDetails={ x=1 y=< + multi-line + string + > } +`, + }, + "structured error value": { + text: "structured error", + values: []interface{}{"someErr", structuredError{error: errors.New("fake error"), details: funcr.PseudoStruct{"x", 1, "y", "multi-line\nstring"}}}, + expectedOutput: `I output.go:] "structured error" someErr="fake error" someErrDetails={ x=1 y=< + multi-line + string + > } +`, + }, + "my structured error": { + text: "my structured error", + err: myStructuredError{error: errors.New("fake error"), details: myStructuredErrorDetails{1, "multi-line\nstring", 3.1}}, + expectedOutput: `E output.go:] "my structured error" err="fake error" errDetails={"SomeInt":1,"SomeString":"multi-line\nstring"} +`, + }, + "my structured error value": { + text: "my structured error", + values: []interface{}{"someErr", myStructuredError{error: errors.New("fake error"), details: myStructuredErrorDetails{1, "multi-line\nstring", 3.1}}}, + expectedOutput: `I output.go:] "my structured error" someErr="fake error" someErrDetails={"SomeInt":1,"SomeString":"multi-line\nstring"} +`, + }, + "my faulty ErrorDetails": { + text: "my faulty ErrorDetails", + values: []interface{}{"err", klog.ErrorWithDetailsFunc(errors.New("fake error"), func() any { panic("fake panic") })}, + expectedOutput: `I output.go:] "my faulty ErrorDetails" err="fake error" errDetails="" +`, + }, + "PseudoStruct": { + text: "keys and values", + values: []interface{}{"parent", klog.PseudoStruct{"boolsub", true, "intsub", 1, "recursive", klog.PseudoStruct{"sub", "level2"}, "multiLine", "abc\ndef"}}, + expectedOutput: `I output.go:] "keys and values" parent={ boolsub=true intsub=1 recursive={ sub="level2" } multiLine=< + abc + def + > } +`, + }, + "klog.Format": { text: "klog.Format", values: []interface{}{"s", klog.Format(struct{ Name, Kind, hidden string }{Name: "worker", Kind: "pod", hidden: "ignore"})}, @@ -1100,3 +1147,38 @@ func traceIDFromHex(str string) TraceID { } return result } + +// Structured error with additional values that are not part of the message +// returned by Error(). +type structuredError struct { + error + details klog.PseudoStruct +} + +// ErrorDetails gets called in addition to Error function to +// log additional information. +func (err structuredError) ErrorDetails() interface{} { + return err.details +} + +var _ error = structuredError{} +var _ klog.ErrorDetailer = structuredError{} + +// myStructuredError is a variant of structuredError where details are a struct. +type myStructuredError struct { + error + details myStructuredErrorDetails +} + +func (err myStructuredError) ErrorDetails() interface{} { + return err.details +} + +var _ error = myStructuredError{} +var _ klog.ErrorDetailer = myStructuredError{} + +type myStructuredErrorDetails struct { + SomeInt int + SomeString string + hiddenFloat float64 +} diff --git a/test/zapr.go b/test/zapr.go index 1e669fa5..92268127 100644 --- a/test/zapr.go +++ b/test/zapr.go @@ -282,6 +282,41 @@ I output.go:] "duplicates" trace="101112131415161718191a1b1c1d1e1f" a=1 c= {"caller":"test/output.go:","msg":"duplicates","trace":"101112131415161718191a1b1c1d1e1f","span":"0102030405060708","a":1,"b":2,"trace":"101112131415161718191a1b1c1d1e1f","span":"1112131415161718","v":0} {"caller":"test/output.go:","msg":"duplicates","trace":"101112131415161718191a1b1c1d1e1f","span":"0102030405060708","a":1,"v":0} {"caller":"test/output.go:","msg":"duplicates","trace":"101112131415161718191a1b1c1d1e1f","span":"0102030405060708","a":1,"c":3,"trace":"101112131415161718191a1b1c1d1e1f","span":"2122232425262728","d":4,"v":0} +`, + // Without support for funcr.PseudoStruct, zapr falls back to rendering a list. + `I output.go:] "keys and values" parent={ boolsub=true intsub=1 recursive={ sub="level2" } multiLine=< + abc + def + > } +`: `{"caller":"test/output.go:","msg":"keys and values","v":0,"parent":["boolsub",true,"intsub",1,"recursive",["sub","level2"],"multiLine","abc\ndef"]} +`, + + // Errors are rendered without details by zapr. + // This is okay, they were meant to be optional. + `I output.go:] "structured error" someErr="fake error" someErrDetails={ x=1 y=< + multi-line + string + > } +`: `{"caller":"test/output.go:","msg":"structured error","v":0,"someErr":"fake error"} +`, + + `I output.go:] "my structured error" someErr="fake error" someErrDetails={"SomeInt":1,"SomeString":"multi-line\nstring"} +`: `{"caller":"test/output.go:","msg":"my structured error","v":0,"someErr":"fake error"} +`, + + `E output.go:] "structured error" err="fake error" errDetails={ x=1 y=< + multi-line + string + > } +`: `{"caller":"test/output.go:","msg":"structured error","err":"fake error"} +`, + + `E output.go:] "my structured error" err="fake error" errDetails={"SomeInt":1,"SomeString":"multi-line\nstring"} +`: `{"caller":"test/output.go:","msg":"my structured error","err":"fake error"} +`, + + `I output.go:] "my faulty ErrorDetails" err="fake error" errDetails="" +`: `{"caller":"test/output.go:","msg":"my faulty ErrorDetails","v":0,"err":"fake error"} `, } }