diff --git a/internal/serialize/keyvalues.go b/internal/serialize/keyvalues.go index 1dc81a15..bcdf5f8e 100644 --- a/internal/serialize/keyvalues.go +++ b/internal/serialize/keyvalues.go @@ -18,6 +18,7 @@ package serialize import ( "bytes" + "encoding/json" "fmt" "strconv" @@ -196,11 +197,11 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) { case textWriter: writeTextWriterValue(b, v) case fmt.Stringer: - writeStringValue(b, true, StringerToString(v)) + writeStringValue(b, StringerToString(v)) case string: - writeStringValue(b, true, v) + writeStringValue(b, v) case error: - writeStringValue(b, true, ErrorToString(v)) + writeStringValue(b, ErrorToString(v)) case logr.Marshaler: value := MarshalerToValue(v) // A marshaler that returns a string is useful for @@ -215,9 +216,9 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) { // value directly. switch value := value.(type) { case string: - writeStringValue(b, true, value) + writeStringValue(b, value) default: - writeStringValue(b, false, f.AnyToString(value)) + f.formatAny(b, value) } case []byte: // In https://github.com/kubernetes/klog/pull/237 it was decided @@ -234,7 +235,7 @@ func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) { b.WriteByte('=') b.WriteString(fmt.Sprintf("%+q", v)) default: - writeStringValue(b, false, f.AnyToString(v)) + f.formatAny(b, v) } } @@ -242,12 +243,25 @@ func KVFormat(b *bytes.Buffer, k, v interface{}) { Formatter{}.KVFormat(b, k, v) } -// AnyToString is the historic fallback formatter. -func (f Formatter) AnyToString(v interface{}) string { +// formatAny is the fallback formatter for a value. It supports a hook (for +// example, for YAML encoding) and itself uses JSON encoding. +func (f Formatter) formatAny(b *bytes.Buffer, v interface{}) { + b.WriteRune('=') if f.AnyToStringHook != nil { - return f.AnyToStringHook(v) + b.WriteString(f.AnyToStringHook(v)) + return + } + encoder := json.NewEncoder(b) + l := b.Len() + if err := encoder.Encode(v); err != nil { + // This shouldn't happen. We discard whatever the encoder + // wrote and instead dump an error string. + b.Truncate(l) + b.WriteString(fmt.Sprintf(`""`, err)) + return } - return fmt.Sprintf("%+v", v) + // Remove trailing newline. + b.Truncate(b.Len() - 1) } // StringerToString converts a Stringer to a string, @@ -287,7 +301,7 @@ func ErrorToString(err error) (ret string) { } func writeTextWriterValue(b *bytes.Buffer, v textWriter) { - b.WriteRune('=') + b.WriteByte('=') defer func() { if err := recover(); err != nil { fmt.Fprintf(b, `""`, err) @@ -296,18 +310,13 @@ func writeTextWriterValue(b *bytes.Buffer, v textWriter) { v.WriteText(b) } -func writeStringValue(b *bytes.Buffer, quote bool, v string) { +func writeStringValue(b *bytes.Buffer, v string) { data := []byte(v) index := bytes.IndexByte(data, '\n') if index == -1 { b.WriteByte('=') - if quote { - // Simple string, quote quotation marks and non-printable characters. - b.WriteString(strconv.Quote(v)) - return - } - // Non-string with no line breaks. - b.WriteString(v) + // Simple string, quote quotation marks and non-printable characters. + b.WriteString(strconv.Quote(v)) return } diff --git a/internal/serialize/keyvalues_test.go b/internal/serialize/keyvalues_test.go index 1bf4842b..b9e066c6 100644 --- a/internal/serialize/keyvalues_test.go +++ b/internal/serialize/keyvalues_test.go @@ -69,7 +69,7 @@ func TestKvListFormat(t *testing.T) { }{ { keysValues: []interface{}{"data", &dummyStruct{key: "test", value: "info"}}, - want: " data=map[key-data:test value-data:info]", + want: ` data={"key-data":"test","value-data":"info"}`, }, { keysValues: []interface{}{"data", &dummyStructWithStringMarshal{key: "test", value: "info"}}, @@ -89,15 +89,15 @@ func TestKvListFormat(t *testing.T) { Y string N time.Time }{X: 76, Y: "strval", N: time.Date(2006, 1, 2, 15, 4, 5, .067890e9, time.UTC)}}, - want: " pod=\"kubedns\" spec={X:76 Y:strval N:2006-01-02 15:04:05.06789 +0000 UTC}", + want: ` pod="kubedns" spec={"X":76,"Y":"strval","N":"2006-01-02T15:04:05.06789Z"}`, }, { keysValues: []interface{}{"pod", "kubedns", "values", []int{8, 6, 7, 5, 3, 0, 9}}, - want: " pod=\"kubedns\" values=[8 6 7 5 3 0 9]", + want: " pod=\"kubedns\" values=[8,6,7,5,3,0,9]", }, { keysValues: []interface{}{"pod", "kubedns", "values", []string{"deployment", "svc", "configmap"}}, - want: " pod=\"kubedns\" values=[deployment svc configmap]", + want: ` pod="kubedns" values=["deployment","svc","configmap"]`, }, { keysValues: []interface{}{"pod", "kubedns", "bytes", []byte("test case for byte array")}, @@ -123,7 +123,7 @@ No whitespace.`, }, { keysValues: []interface{}{"pod", "kubedns", "maps", map[string]int{"three": 4}}, - want: " pod=\"kubedns\" maps=map[three:4]", + want: ` pod="kubedns" maps={"three":4}`, }, { keysValues: []interface{}{"pod", klog.KRef("kube-system", "kubedns"), "status", "ready"}, @@ -163,7 +163,7 @@ No whitespace.`, Name: "mi-conf", }, })}, - want: " pods=[kube-system/kube-dns mi-conf]", + want: ` pods=[{"name":"kube-dns","namespace":"kube-system"},{"name":"mi-conf"}]`, }, { keysValues: []interface{}{"point-1", point{100, 200}, "point-2", emptyPoint}, diff --git a/k8s_references.go b/k8s_references.go index ecd3f8b6..786af74b 100644 --- a/k8s_references.go +++ b/k8s_references.go @@ -178,14 +178,14 @@ func (ks kobjSlice) process() (objs []interface{}, err string) { return objectRefs, "" } -var nilToken = []byte("") +var nilToken = []byte("null") func (ks kobjSlice) WriteText(out *bytes.Buffer) { s := reflect.ValueOf(ks.arg) switch s.Kind() { case reflect.Invalid: - // nil parameter, print as empty slice. - out.WriteString("[]") + // nil parameter, print as null. + out.Write(nilToken) return case reflect.Slice: // Okay, handle below. @@ -197,15 +197,15 @@ func (ks kobjSlice) WriteText(out *bytes.Buffer) { defer out.Write([]byte{']'}) for i := 0; i < s.Len(); i++ { if i > 0 { - out.Write([]byte{' '}) + out.Write([]byte{','}) } item := s.Index(i).Interface() if item == nil { out.Write(nilToken) } else if v, ok := item.(KMetadata); ok { - KObj(v).writeUnquoted(out) + KObj(v).WriteText(out) } else { - fmt.Fprintf(out, "", item) + fmt.Fprintf(out, `""`, item) return } } diff --git a/klog_test.go b/klog_test.go index 58eeb267..76303e06 100644 --- a/klog_test.go +++ b/klog_test.go @@ -1164,10 +1164,7 @@ second value line`}, }, { msg: `message`, - format: `I0102 15:04:05.067890 1234 klog_test.go:%d] "message" myData=< - {Data:This is some long text - with a line break.} - > + format: `I0102 15:04:05.067890 1234 klog_test.go:%d] "message" myData={"Data":"This is some long text\nwith a line break."} `, keysValues: []interface{}{"myData", myData}, }, diff --git a/ktesting/example_test.go b/ktesting/example_test.go index 9d887932..34844ef6 100644 --- a/ktesting/example_test.go +++ b/ktesting/example_test.go @@ -35,7 +35,7 @@ func ExampleUnderlier() { ), ) - logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ field int }{field: 1}) + logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ Field int }{Field: 1}) logger.WithValues("request", 42).WithValues("anotherValue", "fish").Info("hello world") logger.WithValues("request", 42, "anotherValue", "fish").Info("hello world 2", "yetAnotherValue", "thanks") logger.WithName("example").Info("with name") @@ -65,13 +65,13 @@ func ExampleUnderlier() { } // Output: - // ERROR I failed err="failure" what="something" data=### {field:1} ### + // ERROR I failed err="failure" what="something" data=### {Field:1} ### // INFO hello world request=### 42 ### anotherValue="fish" // INFO hello world 2 request=### 42 ### anotherValue="fish" yetAnotherValue="thanks" // INFO example: with name // INFO higher verbosity // - // log entry #0: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:ERROR Prefix: Message:I failed Verbosity:0 Err:failure WithKVList:[] ParameterKVList:[what something data {field:1}]} + // log entry #0: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:ERROR Prefix: Message:I failed Verbosity:0 Err:failure WithKVList:[] ParameterKVList:[what something data {Field:1}]} // log entry #1: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix: Message:hello world Verbosity:0 Err: WithKVList:[request 42 anotherValue fish] ParameterKVList:[]} // log entry #2: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix: Message:hello world 2 Verbosity:0 Err: WithKVList:[request 42 anotherValue fish] ParameterKVList:[yetAnotherValue thanks]} // log entry #3: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix:example Message:with name Verbosity:0 Err: WithKVList:[] ParameterKVList:[]} @@ -82,7 +82,7 @@ func ExampleNewLogger() { var buffer ktesting.BufferTL logger := ktesting.NewLogger(&buffer, ktesting.NewConfig()) - logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ field int }{field: 1}) + logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ Field int }{Field: 1}) logger.V(5).Info("Logged at level 5.") logger.V(6).Info("Not logged at level 6.") @@ -95,7 +95,7 @@ func ExampleNewLogger() { // Output: // >> << - // E...] I failed err="failure" what="something" data={field:1} + // E...] I failed err="failure" what="something" data={"Field":1} // I...] Logged at level 5. } diff --git a/test/output.go b/test/output.go index 7cd536fc..e3bc181b 100644 --- a/test/output.go +++ b/test/output.go @@ -275,30 +275,30 @@ I output.go:] "test" firstKey=1 secondKey=3 `, }, "KObjs": { - text: "test", + text: "KObjs", values: []interface{}{"pods", klog.KObjs([]interface{}{ &kmeta{Name: "pod-1", Namespace: "kube-system"}, &kmeta{Name: "pod-2", Namespace: "kube-system"}, })}, - expectedOutput: `I output.go:] "test" pods=[kube-system/pod-1 kube-system/pod-2] + expectedOutput: `I output.go:] "KObjs" pods=[{"name":"pod-1","namespace":"kube-system"},{"name":"pod-2","namespace":"kube-system"}] `, }, "KObjSlice okay": { - text: "test", + text: "KObjSlice", values: []interface{}{"pods", klog.KObjSlice([]interface{}{ &kmeta{Name: "pod-1", Namespace: "kube-system"}, &kmeta{Name: "pod-2", Namespace: "kube-system"}, })}, - expectedOutput: `I output.go:] "test" pods=[kube-system/pod-1 kube-system/pod-2] + expectedOutput: `I output.go:] "KObjSlice" pods=["kube-system/pod-1","kube-system/pod-2"] `, }, "KObjSlice nil arg": { text: "test", values: []interface{}{"pods", klog.KObjSlice(nil)}, - expectedOutput: `I output.go:] "test" pods=[] + expectedOutput: `I output.go:] "test" pods=null `, }, "KObjSlice int arg": { @@ -315,14 +315,14 @@ I output.go:] "test" firstKey=1 secondKey=3 &kmeta{Name: "pod-1", Namespace: "kube-system"}, nil, })}, - expectedOutput: `I output.go:] "test" pods=[kube-system/pod-1 ] + expectedOutput: `I output.go:] "test" pods=["kube-system/pod-1",null] `, }, "KObjSlice ints": { text: "test", values: []interface{}{"ints", klog.KObjSlice([]int{1, 2, 3})}, - expectedOutput: `I output.go:] "test" ints=[] + expectedOutput: `I output.go:] "test" ints=[""] `, }, "regular error types as value": { @@ -409,19 +409,36 @@ I output.go:] "test" firstKey=1 secondKey=3 "map values": { text: "maps", values: []interface{}{"s", map[string]string{"hello": "world"}, "i", map[int]int{1: 2, 3: 4}}, - expectedOutput: `I output.go:] "maps" s=map[hello:world] i=map[1:2 3:4] + expectedOutput: `I output.go:] "maps" s={"hello":"world"} i={"1":2,"3":4} `, }, "slice values": { text: "slices", values: []interface{}{"s", []string{"hello", "world"}, "i", []int{1, 2, 3}}, - expectedOutput: `I output.go:] "slices" s=[hello world] i=[1 2 3] + expectedOutput: `I output.go:] "slices" s=["hello","world"] i=[1,2,3] `, }, "struct values": { text: "structs", values: []interface{}{"s", struct{ Name, Kind, hidden string }{Name: "worker", Kind: "pod", hidden: "ignore"}}, - expectedOutput: `I output.go:] "structs" s={Name:worker Kind:pod hidden:ignore} + expectedOutput: `I output.go:] "structs" s={"Name":"worker","Kind":"pod"} +`, + }, + "klog.Format": { + text: "klog.Format", + values: []interface{}{"s", klog.Format(struct{ Name, Kind, hidden string }{Name: "worker", Kind: "pod", hidden: "ignore"})}, + expectedOutput: `I output.go:] "klog.Format" s=< + { + "Name": "worker", + "Kind": "pod" + } + > +`, + }, + "cyclic list": { + text: "cycle", + values: []interface{}{"list", newCyclicList()}, + expectedOutput: `I output.go:] "cycle" list="" `, }, } @@ -1019,3 +1036,16 @@ type myConfig struct { var _ logr.Marshaler = myConfig{} var _ fmt.Stringer = myConfig{} + +// This is a linked list. It can contain a cycle, which cannot be expressed in JSON. +type myList struct { + Value int + Next *myList +} + +func newCyclicList() *myList { + a := &myList{Value: 1} + b := &myList{Value: 2, Next: a} + a.Next = b + return a +} diff --git a/test/zapr.go b/test/zapr.go index 7d889943..7b159442 100644 --- a/test/zapr.go +++ b/test/zapr.go @@ -69,11 +69,15 @@ func ZaprOutputMappingDirect() map[string]string { `: `{"caller":"test/output.go:","msg":"test","v":0,"pod":{"name":"pod-1","namespace":"kube-system"}} `, - `I output.go:] "test" pods=[kube-system/pod-1 kube-system/pod-2] -`: `{"caller":"test/output.go:","msg":"test","v":0,"pods":[{"name":"pod-1","namespace":"kube-system"},{"name":"pod-2","namespace":"kube-system"}]} + `I output.go:] "KObjs" pods=[{"name":"pod-1","namespace":"kube-system"},{"name":"pod-2","namespace":"kube-system"}] +`: `{"caller":"test/output.go:","msg":"KObjs","v":0,"pods":[{"name":"pod-1","namespace":"kube-system"},{"name":"pod-2","namespace":"kube-system"}]} `, - `I output.go:] "test" pods=[] + `I output.go:] "KObjSlice" pods=["kube-system/pod-1","kube-system/pod-2"] +`: `{"caller":"test/output.go:","msg":"KObjSlice","v":0,"pods":[{"name":"pod-1","namespace":"kube-system"},{"name":"pod-2","namespace":"kube-system"}]} +`, + + `I output.go:] "test" pods=null `: `{"caller":"test/output.go:","msg":"test","v":0,"pods":null} `, @@ -81,11 +85,11 @@ func ZaprOutputMappingDirect() map[string]string { `: `{"caller":"test/output.go:","msg":"test","v":0,"pods":""} `, - `I output.go:] "test" ints=[] + `I output.go:] "test" ints=[""] `: `{"caller":"test/output.go:","msg":"test","v":0,"ints":""} `, - `I output.go:] "test" pods=[kube-system/pod-1 ] + `I output.go:] "test" pods=["kube-system/pod-1",null] `: `{"caller":"test/output.go:","msg":"test","v":0,"pods":[{"name":"pod-1","namespace":"kube-system"},null]} `, @@ -238,15 +242,27 @@ I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" > `: `{"caller":"test/output.go:","msg":"Format","v":0,"config":{"Kind":"config","RealField":42}} `, - `I output.go:] "maps" s=map[hello:world] i=map[1:2 3:4] + `I output.go:] "maps" s={"hello":"world"} i={"1":2,"3":4} `: `{"caller":"test/output.go:","msg":"maps","v":0,"s":{"hello":"world"},"i":{"1":2,"3":4}} `, - `I output.go:] "slices" s=[hello world] i=[1 2 3] + `I output.go:] "slices" s=["hello","world"] i=[1,2,3] `: `{"caller":"test/output.go:","msg":"slices","v":0,"s":["hello","world"],"i":[1,2,3]} `, - `I output.go:] "structs" s={Name:worker Kind:pod hidden:ignore} + `I output.go:] "structs" s={"Name":"worker","Kind":"pod"} `: `{"caller":"test/output.go:","msg":"structs","v":0,"s":{"Name":"worker","Kind":"pod"}} +`, + `I output.go:] "klog.Format" s=< + { + "Name": "worker", + "Kind": "pod" + } + > +`: `{"caller":"test/output.go:","msg":"klog.Format","v":0,"s":{"Name":"worker","Kind":"pod"}} +`, + + `I output.go:] "cycle" list="" +`: `{"caller":"test/output.go:","msg":"cycle","v":0,"listError":"json: unsupported value: encountered a cycle via *test.myList"} `, } }