diff --git a/test/integration/logs/functional/json/output_test.go b/test/integration/logs/functional/json/output_test.go new file mode 100644 index 00000000000..c1b4287dbc4 --- /dev/null +++ b/test/integration/logs/functional/json/output_test.go @@ -0,0 +1,78 @@ +/* +Copyright 2021 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 json + +import ( + "io" + "os" + "strings" + "testing" + + "github.com/go-logr/logr" + "go.uber.org/zap/zapcore" + + "k8s.io/component-base/config" + logsjson "k8s.io/component-base/logs/json" + "k8s.io/klog/v2/test" +) + +func init() { + test.InitKlog() +} + +// TestJsonOutput tests the JSON logger, directly and as backend for klog. +func TestJSONOutput(t *testing.T) { + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + logger, _ := logsjson.NewJSONLogger(config.VerbosityLevel(v), logsjson.AddNopSync(out), nil, + &zapcore.EncoderConfig{ + MessageKey: "msg", + CallerKey: "caller", + NameKey: "logger", + EncodeDuration: zapcore.StringDurationEncoder, + EncodeCaller: zapcore.ShortCallerEncoder, + }) + return logger + } + + // If Go modules are turned off (for example, as in "make test-integration"), + // references to klog like k8s.io/klog/v2.ObjectRef.MarshalLog become + // k8s.io/kubernetes/vendor/k8s.io/klog/v2.ObjectRef.MarshalLog. + injectVendor := func(mapping map[string]string) map[string]string { + if os.Getenv("GO111MODULE") != "off" { + return mapping + } + for key, value := range mapping { + mapping[key] = strings.ReplaceAll(value, "k8s.io/klog/v2", "k8s.io/kubernetes/vendor/k8s.io/klog/v2") + } + return mapping + } + + t.Run("direct", func(t *testing.T) { + test.Output(t, test.OutputConfig{ + NewLogger: newLogger, + ExpectedOutputMapping: injectVendor(test.ZaprOutputMappingDirect()), + }) + }) + + t.Run("klog-backend", func(t *testing.T) { + test.Output(t, test.OutputConfig{ + NewLogger: newLogger, + AsBackend: true, + ExpectedOutputMapping: injectVendor(test.ZaprOutputMappingIndirect()), + }) + }) +} diff --git a/vendor/k8s.io/klog/v2/test/output.go b/vendor/k8s.io/klog/v2/test/output.go new file mode 100644 index 00000000000..bec12018d18 --- /dev/null +++ b/vendor/k8s.io/klog/v2/test/output.go @@ -0,0 +1,775 @@ +/* +Copyright 2021 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 test contains a reusable unit test for logging output and behavior. +// +// Experimental +// +// Notice: This package is EXPERIMENTAL and may be changed or removed in a +// later release. +package test + +import ( + "bytes" + "encoding/json" + "errors" + "flag" + "fmt" + "io" + "regexp" + "runtime" + "strconv" + "strings" + "testing" + "time" + + "github.com/go-logr/logr" + + "k8s.io/klog/v2" +) + +// InitKlog must be called once in an init function of a test package to +// configure klog for testing with Output. +// +// Experimental +// +// Notice: This function is EXPERIMENTAL and may be changed or removed in a +// later release. +func InitKlog() { + // klog gets configured so that it writes to a single output file that + // will be set during tests with SetOutput. + klog.InitFlags(nil) + flag.Set("v", "10") + flag.Set("log_file", "/dev/null") + flag.Set("logtostderr", "false") + flag.Set("alsologtostderr", "false") + flag.Set("stderrthreshold", "10") +} + +// OutputConfig contains optional settings for Output. +// +// Experimental +// +// Notice: This type is EXPERIMENTAL and may be changed or removed in a +// later release. +type OutputConfig struct { + // NewLogger is called to create a new logger. If nil, output via klog + // is tested. Support for -vmodule is optional. ClearLogger is called + // after each test, therefore it is okay to user SetLogger without + // undoing that in the callback. + NewLogger func(out io.Writer, v int, vmodule string) logr.Logger + + // AsBackend enables testing through klog and the logger set there with + // SetLogger. + AsBackend bool + + // ExpectedOutputMapping replaces the builtin expected output for test + // cases with something else. If nil or a certain case is not present, + // the original text is used. + // + // The expected output uses as a placeholder for the line of the + // log call. The source code is always the output.go file itself. When + // testing a logger directly, is used for the first + // WithValues call, for a second and + // for a third. + ExpectedOutputMapping map[string]string + + // SupportsVModule indicates that the logger supports the vmodule + // parameter. Ignored when logging through klog. + SupportsVModule bool +} + +// Output covers various special cases of emitting log output. +// It can be used for arbitrary logr.Logger implementations. +// +// The expected output is what klog would print. When testing loggers +// that emit different output, a mapping from klog output to the +// corresponding logger output must be provided, otherwise the +// test will compare against the expected klog output. +// +// Loggers will be tested with direct calls to Info or +// as backend for klog. +// +// Experimental +// +// Notice: This function is EXPERIMENTAL and may be changed or removed in a +// later release. The test cases and thus the expected output also may +// change. +func Output(t *testing.T, config OutputConfig) { + tests := map[string]struct { + withHelper bool // use wrappers that get skipped during stack unwinding + withNames []string + // For a first WithValues call: logger1 := logger.WithValues() + withValues []interface{} + // For another WithValues call: logger2 := logger1.WithValues() + moreValues []interface{} + // For another WithValues call on the same logger as before: logger3 := logger1.WithValues() + evenMoreValues []interface{} + v int + vmodule string + text string + values []interface{} + err error + expectedOutput string + }{ + "log with values": { + text: "test", + values: []interface{}{"akey", "avalue"}, + expectedOutput: `I output.go:] "test" akey="avalue" +`, + }, + "call depth": { + text: "helper", + withHelper: true, + values: []interface{}{"akey", "avalue"}, + expectedOutput: `I output.go:] "helper" akey="avalue" +`, + }, + "verbosity enabled": { + text: "you see me", + v: 9, + expectedOutput: `I output.go:] "you see me" +`, + }, + "verbosity disabled": { + text: "you don't see me", + v: 11, + }, + "vmodule": { + text: "v=11: you see me because of -vmodule output=11", + v: 11, + vmodule: "output=11", + }, + "other vmodule": { + text: "v=11: you still don't see me because of -vmodule output_helper=11", + v: 11, + vmodule: "output_helper=11", + }, + "log with name and values": { + withNames: []string{"me"}, + text: "test", + values: []interface{}{"akey", "avalue"}, + expectedOutput: `I output.go:] "me: test" akey="avalue" +`, + }, + "log with multiple names and values": { + withNames: []string{"hello", "world"}, + text: "test", + values: []interface{}{"akey", "avalue"}, + expectedOutput: `I output.go:] "hello/world: test" akey="avalue" +`, + }, + "override single value": { + withValues: []interface{}{"akey", "avalue"}, + text: "test", + values: []interface{}{"akey", "avalue2"}, + expectedOutput: `I output.go:] "test" akey="avalue2" +`, + }, + "override WithValues": { + withValues: []interface{}{"duration", time.Hour, "X", "y"}, + text: "test", + values: []interface{}{"duration", time.Minute, "A", "b"}, + expectedOutput: `I output.go:] "test" X="y" duration="1m0s" A="b" +`, + }, + "odd WithValues": { + withValues: []interface{}{"keyWithoutValue"}, + moreValues: []interface{}{"anotherKeyWithoutValue"}, + text: "odd WithValues", + expectedOutput: `I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" anotherKeyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +`, + }, + "multiple WithValues": { + withValues: []interface{}{"firstKey", 1}, + moreValues: []interface{}{"secondKey", 2}, + evenMoreValues: []interface{}{"secondKey", 3}, + text: "test", + expectedOutput: `I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=2 +I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=3 +`, + }, + "empty WithValues": { + withValues: []interface{}{}, + text: "test", + expectedOutput: `I output.go:] "test" +`, + }, + // TODO: unify behavior of loggers. + // klog doesn't deduplicate, klogr and textlogger do. We can ensure via static code analysis + // that this doesn't occur, so we shouldn't pay the runtime overhead for deduplication here + // and remove that from klogr and textlogger (https://github.com/kubernetes/klog/issues/286). + // "print duplicate keys in arguments": { + // text: "test", + // values: []interface{}{"akey", "avalue", "akey", "avalue2"}, + // expectedOutput: `I output.go:] "test" akey="avalue" akey="avalue2" + // `, + // }, + "preserve order of key/value pairs": { + withValues: []interface{}{"akey9", "avalue9", "akey8", "avalue8", "akey1", "avalue1"}, + text: "test", + values: []interface{}{"akey5", "avalue5", "akey4", "avalue4"}, + expectedOutput: `I output.go:] "test" akey9="avalue9" akey8="avalue8" akey1="avalue1" akey5="avalue5" akey4="avalue4" +`, + }, + "handle odd-numbers of KVs": { + text: "odd arguments", + values: []interface{}{"akey", "avalue", "akey2"}, + expectedOutput: `I output.go:] "odd arguments" akey="avalue" akey2="(MISSING)" +`, + }, + "html characters": { + text: "test", + values: []interface{}{"akey", "<&>"}, + expectedOutput: `I output.go:] "test" akey="<&>" +`, + }, + "quotation": { + text: `"quoted"`, + values: []interface{}{"key", `"quoted value"`}, + expectedOutput: `I output.go:] "\"quoted\"" key="\"quoted value\"" +`, + }, + "handle odd-numbers of KVs in both log values and Info args": { + withValues: []interface{}{"basekey1", "basevar1", "basekey2"}, + text: "both odd", + values: []interface{}{"akey", "avalue", "akey2"}, + expectedOutput: `I output.go:] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" +`, + }, + "KObj": { + text: "test", + values: []interface{}{"pod", klog.KObj(&kmeta{Name: "pod-1", Namespace: "kube-system"})}, + expectedOutput: `I output.go:] "test" pod="kube-system/pod-1" +`, + }, + "KObjs": { + text: "test", + 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] +`, + }, + "regular error types as value": { + text: "test", + values: []interface{}{"err", errors.New("whoops")}, + expectedOutput: `I output.go:] "test" err="whoops" +`, + }, + "ignore MarshalJSON": { + text: "test", + values: []interface{}{"err", &customErrorJSON{"whoops"}}, + expectedOutput: `I output.go:] "test" err="whoops" +`, + }, + "regular error types when using logr.Error": { + text: "test", + err: errors.New("whoops"), + expectedOutput: `E output.go:] "test" err="whoops" +`, + }, + "Error() for nil": { + text: "error nil", + err: (*customErrorJSON)(nil), + expectedOutput: `E output.go:] "error nil" err="" +`, + }, + "String() for nil": { + text: "stringer nil", + values: []interface{}{"stringer", (*stringer)(nil)}, + expectedOutput: `I output.go:] "stringer nil" stringer="" +`, + }, + "MarshalLog() for nil": { + text: "marshaler nil", + values: []interface{}{"obj", (*klog.ObjectRef)(nil)}, + expectedOutput: `I output.go:] "marshaler nil" obj="" +`, + }, + "Error() that panics": { + text: "error panic", + err: faultyError{}, + expectedOutput: `E output.go:] "error panic" err="" +`, + }, + "String() that panics": { + text: "stringer panic", + values: []interface{}{"stringer", faultyStringer{}}, + expectedOutput: `I output.go:] "stringer panic" stringer="" +`, + }, + "MarshalLog() that panics": { + text: "marshaler panic", + values: []interface{}{"obj", faultyMarshaler{}}, + expectedOutput: `I output.go:] "marshaler panic" obj={} +`, + }, + } + for n, test := range tests { + t.Run(n, func(t *testing.T) { + defer klog.ClearLogger() + + printWithLogger := func(logger logr.Logger) { + for _, name := range test.withNames { + logger = logger.WithName(name) + } + // When we have multiple WithValues calls, we test + // first with the initial set of additional values, then + // the combination, then again the original logger. + // It must not have been modified. This produces + // three log entries. + logger = logger.WithValues(test.withValues...) // + loggers := []logr.Logger{logger} + if test.moreValues != nil { + loggers = append(loggers, logger.WithValues(test.moreValues...), logger) // + } + if test.evenMoreValues != nil { + loggers = append(loggers, logger.WithValues(test.evenMoreValues...)) // + } + for _, logger := range loggers { + if test.withHelper { + loggerHelper(logger, test.text, test.values) // + } else if test.err != nil { + logger.Error(test.err, test.text, test.values...) // + } else { + logger.V(test.v).Info(test.text, test.values...) // + } + } + } + _, _, printWithLoggerLine, _ := runtime.Caller(0) + + printWithKlog := func() { + kv := []interface{}{} + haveKeyInValues := func(key interface{}) bool { + for i := 0; i < len(test.values); i += 2 { + if key == test.values[i] { + return true + } + } + return false + } + appendKV := func(withValues []interface{}) { + if len(withValues)%2 != 0 { + withValues = append(withValues, "(MISSING)") + } + for i := 0; i < len(withValues); i += 2 { + if !haveKeyInValues(withValues[i]) { + kv = append(kv, withValues[i], withValues[i+1]) + } + } + } + // Here we need to emulate the handling of WithValues above. + appendKV(test.withValues) + kvs := [][]interface{}{copySlice(kv)} + if test.moreValues != nil { + appendKV(test.moreValues) + kvs = append(kvs, copySlice(kv), copySlice(kvs[0])) + } + if test.evenMoreValues != nil { + kv = copySlice(kvs[0]) + appendKV(test.evenMoreValues) + kvs = append(kvs, copySlice(kv)) + } + for _, kv := range kvs { + if len(test.values) > 0 { + kv = append(kv, test.values...) + } + text := test.text + if len(test.withNames) > 0 { + text = strings.Join(test.withNames, "/") + ": " + text + } + if test.withHelper { + klogHelper(text, kv) + } else if test.err != nil { + klog.ErrorS(test.err, text, kv...) + } else { + klog.V(klog.Level(test.v)).InfoS(text, kv...) + } + } + } + _, _, printWithKlogLine, _ := runtime.Caller(0) + + testOutput := func(t *testing.T, expectedLine int, print func(buffer *bytes.Buffer)) { + var tmpWriteBuffer bytes.Buffer + klog.SetOutput(&tmpWriteBuffer) + print(&tmpWriteBuffer) + klog.Flush() + + actual := tmpWriteBuffer.String() + // Strip varying header. + re := `(?m)^(.).... ..:..:......... ....... output.go` + actual = regexp.MustCompile(re).ReplaceAllString(actual, `${1} output.go`) + + // Inject expected line. This matches the if checks above, which are + // the same for both printWithKlog and printWithLogger. + callLine := expectedLine + if test.withHelper { + callLine -= 8 + } else if test.err != nil { + callLine -= 6 + } else { + callLine -= 4 + } + expected := test.expectedOutput + if repl, ok := config.ExpectedOutputMapping[expected]; ok { + expected = repl + } + expectedWithPlaceholder := expected + expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", callLine)) + expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", expectedLine-18)) + expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", expectedLine-15)) + expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", expectedLine-12)) + if actual != expected { + if expectedWithPlaceholder == test.expectedOutput { + t.Errorf("Output mismatch. Expected:\n%s\nActual:\n%s\n", expectedWithPlaceholder, actual) + } else { + t.Errorf("Output mismatch. klog:\n%s\nExpected:\n%s\nActual:\n%s\n", test.expectedOutput, expectedWithPlaceholder, actual) + } + } + } + + if config.NewLogger == nil { + // Test klog. + testOutput(t, printWithKlogLine, func(buffer *bytes.Buffer) { + printWithKlog() + }) + return + } + + if config.AsBackend { + testOutput(t, printWithKlogLine, func(buffer *bytes.Buffer) { + klog.SetLogger(config.NewLogger(buffer, 10, "")) + printWithKlog() + }) + return + } + + if test.vmodule != "" && !config.SupportsVModule { + t.Skip("vmodule not supported") + } + + testOutput(t, printWithLoggerLine, func(buffer *bytes.Buffer) { + printWithLogger(config.NewLogger(buffer, 10, test.vmodule)) + }) + }) + } + + if config.NewLogger == nil || config.AsBackend { + // Test all klog output functions. + // + // Each test case must be defined with the same number of + // lines, then the source code location of the call itself + // can be computed below. + tests := []struct { + name string + logFunc func() + output string + }{ + { + name: "Info", + logFunc: func() { klog.Info("hello", "world") }, + output: "I output.go:] helloworld\n", // This looks odd, but simply is how klog works. + }, + { + name: "InfoDepth", + logFunc: func() { klog.InfoDepth(0, "hello", "world") }, + output: "I output.go:] helloworld\n", + }, + { + name: "Infoln", + logFunc: func() { klog.Infoln("hello", "world") }, + output: "I output.go:] hello world\n", + }, + { + name: "InfolnDepth", + logFunc: func() { klog.InfolnDepth(0, "hello", "world") }, + output: "I output.go:] hello world\n", + }, + { + name: "Infof", + logFunc: func() { klog.Infof("hello %s", "world") }, + output: "I output.go:] hello world\n", + }, + { + name: "InfofDepth", + logFunc: func() { klog.InfofDepth(0, "hello %s", "world") }, + output: "I output.go:] hello world\n", + }, + { + name: "InfoS", + logFunc: func() { klog.InfoS("hello", "what", "world") }, + output: "I output.go:] \"hello\" what=\"world\"\n", + }, + { + name: "InfoSDepth", + logFunc: func() { klog.InfoSDepth(0, "hello", "what", "world") }, + output: "I output.go:] \"hello\" what=\"world\"\n", + }, + { + name: "Warning", + logFunc: func() { klog.Warning("hello", "world") }, + output: "W output.go:] helloworld\n", + }, + { + name: "WarningDepth", + logFunc: func() { klog.WarningDepth(0, "hello", "world") }, + output: "W output.go:] helloworld\n", + }, + { + name: "Warningln", + logFunc: func() { klog.Warningln("hello", "world") }, + output: "W output.go:] hello world\n", + }, + { + name: "WarninglnDepth", + logFunc: func() { klog.WarninglnDepth(0, "hello", "world") }, + output: "W output.go:] hello world\n", + }, + { + name: "Warningf", + logFunc: func() { klog.Warningf("hello %s", "world") }, + output: "W output.go:] hello world\n", + }, + { + name: "WarningfDepth", + logFunc: func() { klog.WarningfDepth(0, "hello %s", "world") }, + output: "W output.go:] hello world\n", + }, + { + name: "Error", + logFunc: func() { klog.Error("hello", "world") }, + output: "E output.go:] helloworld\n", + }, + { + name: "ErrorDepth", + logFunc: func() { klog.ErrorDepth(0, "hello", "world") }, + output: "E output.go:] helloworld\n", + }, + { + name: "Errorln", + logFunc: func() { klog.Errorln("hello", "world") }, + output: "E output.go:] hello world\n", + }, + { + name: "ErrorlnDepth", + logFunc: func() { klog.ErrorlnDepth(0, "hello", "world") }, + output: "E output.go:] hello world\n", + }, + { + name: "Errorf", + logFunc: func() { klog.Errorf("hello %s", "world") }, + output: "E output.go:] hello world\n", + }, + { + name: "ErrorfDepth", + logFunc: func() { klog.ErrorfDepth(0, "hello %s", "world") }, + output: "E output.go:] hello world\n", + }, + { + name: "ErrorS", + logFunc: func() { klog.ErrorS(errors.New("hello"), "world") }, + output: "E output.go:] \"world\" err=\"hello\"\n", + }, + { + name: "ErrorSDepth", + logFunc: func() { klog.ErrorSDepth(0, errors.New("hello"), "world") }, + output: "E output.go:] \"world\" err=\"hello\"\n", + }, + { + name: "V().Info", + logFunc: func() { klog.V(1).Info("hello", "one", "world") }, + output: "I output.go:] hellooneworld\n", + }, + { + name: "V().InfoDepth", + logFunc: func() { klog.V(1).InfoDepth(0, "hello", "one", "world") }, + output: "I output.go:] hellooneworld\n", + }, + { + name: "V().Infoln", + logFunc: func() { klog.V(1).Infoln("hello", "one", "world") }, + output: "I output.go:] hello one world\n", + }, + { + name: "V().InfolnDepth", + logFunc: func() { klog.V(1).InfolnDepth(0, "hello", "one", "world") }, + output: "I output.go:] hello one world\n", + }, + { + name: "V().Infof", + logFunc: func() { klog.V(1).Infof("hello %s %s", "one", "world") }, + output: "I output.go:] hello one world\n", + }, + { + name: "V().InfofDepth", + logFunc: func() { klog.V(1).InfofDepth(0, "hello %s %s", "one", "world") }, + output: "I output.go:] hello one world\n", + }, + { + name: "V().InfoS", + logFunc: func() { klog.V(1).InfoS("hello", "what", "one world") }, + output: "I output.go:] \"hello\" what=\"one world\"\n", + }, + { + name: "V().InfoSDepth", + logFunc: func() { klog.V(1).InfoSDepth(0, "hello", "what", "one world") }, + output: "I output.go:] \"hello\" what=\"one world\"\n", + }, + { + name: "V().ErrorS", + logFunc: func() { klog.V(1).ErrorS(errors.New("hello"), "one world") }, + output: "E output.go:] \"one world\" err=\"hello\"\n", + }, + } + _, _, line, _ := runtime.Caller(0) + + for i, test := range tests { + t.Run(test.name, func(t *testing.T) { + var buffer bytes.Buffer + if config.NewLogger == nil { + klog.SetOutput(&buffer) + } else { + klog.SetLogger(config.NewLogger(&buffer, 10, "")) + defer klog.ClearLogger() + } + test.logFunc() + klog.Flush() + + actual := buffer.String() + // Strip varying header. + re := `(?m)^(.).... ..:..:......... ....... output.go` + actual = regexp.MustCompile(re).ReplaceAllString(actual, `${1} output.go`) + + // Inject expected line. This matches the if checks above, which are + // the same for both printWithKlog and printWithLogger. + callLine := line + 1 - (len(tests)-i)*5 + expected := test.output + + // When klog does string formating for + // non-structured calls, it passes the entire + // result, including a trailing newline, to + // Logger.Info. + if config.NewLogger != nil && + !strings.HasSuffix(test.name, "S") && + !strings.HasSuffix(test.name, "SDepth") { + // klog: I output.go:] hello world + // with logger: I output.go:] "hello world\n" + index := strings.Index(expected, "] ") + if index == -1 { + t.Fatalf("did not find ] separator: %s", expected) + } + expected = expected[0:index+2] + strconv.Quote(expected[index+2:]) + "\n" + + // Warnings become info messages. + if strings.HasPrefix(expected, "W") { + expected = "I" + expected[1:] + } + } + + if repl, ok := config.ExpectedOutputMapping[expected]; ok { + expected = repl + } + expectedWithPlaceholder := expected + expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", callLine)) + if actual != expected { + if expectedWithPlaceholder == test.output { + t.Errorf("Output mismatch. Expected:\n%s\nActual:\n%s\n", expectedWithPlaceholder, actual) + } else { + t.Errorf("Output mismatch. klog:\n%s\nExpected:\n%s\nActual:\n%s\n", test.output, expectedWithPlaceholder, actual) + } + } + }) + } + } +} + +func copySlice(in []interface{}) []interface{} { + return append([]interface{}{}, in...) +} + +type kmeta struct { + Name, Namespace string +} + +func (k kmeta) GetName() string { + return k.Name +} + +func (k kmeta) GetNamespace() string { + return k.Namespace +} + +var _ klog.KMetadata = kmeta{} + +type customErrorJSON struct { + s string +} + +var _ error = &customErrorJSON{} +var _ json.Marshaler = &customErrorJSON{} + +func (e *customErrorJSON) Error() string { + return e.s +} + +func (e *customErrorJSON) MarshalJSON() ([]byte, error) { + return json.Marshal(strings.ToUpper(e.s)) +} + +type stringer struct { + s string +} + +// String crashes when called for nil. +func (s *stringer) String() string { + return s.s +} + +var _ fmt.Stringer = &stringer{} + +type faultyStringer struct{} + +// String always panics. +func (f faultyStringer) String() string { + panic("fake String panic") +} + +var _ fmt.Stringer = faultyStringer{} + +type faultyMarshaler struct{} + +// MarshalLog always panics. +func (f faultyMarshaler) MarshalLog() interface{} { + panic("fake MarshalLog panic") +} + +var _ logr.Marshaler = faultyMarshaler{} + +type faultyError struct{} + +// Error always panics. +func (f faultyError) Error() string { + panic("fake Error panic") +} + +var _ error = faultyError{} diff --git a/vendor/k8s.io/klog/v2/test/output_helper.go b/vendor/k8s.io/klog/v2/test/output_helper.go new file mode 100644 index 00000000000..499395e38d8 --- /dev/null +++ b/vendor/k8s.io/klog/v2/test/output_helper.go @@ -0,0 +1,32 @@ +/* +Copyright 2021 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 test + +import ( + "github.com/go-logr/logr" + + "k8s.io/klog/v2" +) + +func loggerHelper(logger logr.Logger, msg string, kv []interface{}) { + logger = logger.WithCallDepth(1) + logger.Info(msg, kv...) +} + +func klogHelper(msg string, kv []interface{}) { + klog.InfoSDepth(1, msg, kv...) +} diff --git a/vendor/k8s.io/klog/v2/test/zapr.go b/vendor/k8s.io/klog/v2/test/zapr.go new file mode 100644 index 00000000000..20b118aadd3 --- /dev/null +++ b/vendor/k8s.io/klog/v2/test/zapr.go @@ -0,0 +1,271 @@ +/* +Copyright 2022 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 test + +// ZaprOutputMappingDirect provides a mapping from klog output to the +// corresponding zapr output when zapr is called directly. +// +// Experimental +// +// Notice: This package is EXPERIMENTAL and may be changed or removed in a +// later release. +func ZaprOutputMappingDirect() map[string]string { + return map[string]string{ + `I output.go:] "test" akey="<&>" +`: `{"caller":"test/output.go:","msg":"test","v":0,"akey":"<&>"} +`, + + `E output.go:] "test" err="whoops" +`: `{"caller":"test/output.go:","msg":"test","err":"whoops"} +`, + + `I output.go:] "helper" akey="avalue" +`: `{"caller":"test/output.go:","msg":"helper","v":0,"akey":"avalue"} +`, + + `I output.go:] "hello/world: test" akey="avalue" +`: `{"logger":"hello.world","caller":"test/output.go:","msg":"test","v":0,"akey":"avalue"} +`, + + `I output.go:] "test" X="y" duration="1m0s" A="b" +`: `{"caller":"test/output.go:","msg":"test","duration":"1h0m0s","X":"y","v":0,"duration":"1m0s","A":"b"} +`, + + `I output.go:] "test" akey9="avalue9" akey8="avalue8" akey1="avalue1" akey5="avalue5" akey4="avalue4" +`: `{"caller":"test/output.go:","msg":"test","akey9":"avalue9","akey8":"avalue8","akey1":"avalue1","v":0,"akey5":"avalue5","akey4":"avalue4"} +`, + + `I output.go:] "test" +`: `{"caller":"test/output.go:","msg":"test","v":0} +`, + + `I output.go:] "\"quoted\"" key="\"quoted value\"" +`: `{"caller":"test/output.go:","msg":"\"quoted\"","v":0,"key":"\"quoted value\""} +`, + + `I output.go:] "test" err="whoops" +`: `{"caller":"test/output.go:","msg":"test","v":0,"err":"whoops"} +`, + + `I output.go:] "test" pod="kube-system/pod-1" +`: `{"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:] "test" akey="avalue" +`: `{"caller":"test/output.go:","msg":"test","v":0,"akey":"avalue"} +`, + + `I output.go:] "me: test" akey="avalue" +`: `{"logger":"me","caller":"test/output.go:","msg":"test","v":0,"akey":"avalue"} +`, + + `I output.go:] "test" akey="avalue2" +`: `{"caller":"test/output.go:","msg":"test","akey":"avalue","v":0,"akey":"avalue2"} +`, + + `I output.go:] "you see me" +`: `{"caller":"test/output.go:","msg":"you see me","v":9} +`, + + `I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=2 +I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=3 +`: `{"caller":"test/output.go:","msg":"test","firstKey":1,"v":0} +{"caller":"test/output.go:","msg":"test","firstKey":1,"secondKey":2,"v":0} +{"caller":"test/output.go:","msg":"test","firstKey":1,"v":0} +{"caller":"test/output.go:","msg":"test","firstKey":1,"secondKey":3,"v":0} +`, + + `I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" anotherKeyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"keyWithoutValue"} +{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"anotherKeyWithoutValue"} +{"caller":"test/output.go:","msg":"odd WithValues","v":0} +{"caller":"test/output.go:","msg":"odd WithValues","v":0} +{"caller":"test/output.go:","msg":"odd WithValues","v":0} +`, + + `I output.go:] "odd arguments" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"akey2"} +{"caller":"test/output.go:","msg":"odd arguments","v":0,"akey":"avalue"} +`, + + `I output.go:] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"basekey2"} +{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","basekey1":"basevar1","ignored key":"akey2"} +{"caller":"test/output.go:","msg":"both odd","basekey1":"basevar1","v":0,"akey":"avalue"} +`, + + `I output.go:] "marshaler nil" obj="" +`: `{"caller":"test/output.go:","msg":"marshaler nil","v":0,"objError":"PANIC=value method k8s.io/klog/v2.ObjectRef.MarshalLog called using nil *ObjectRef pointer"} +`, + + // zap replaces a panic for a nil object with . + `E output.go:] "error nil" err="" +`: `{"caller":"test/output.go:","msg":"error nil","err":""} +`, + + `I output.go:] "stringer nil" stringer="" +`: `{"caller":"test/output.go:","msg":"stringer nil","v":0,"stringer":""} +`, + + `I output.go:] "stringer panic" stringer="" +`: `{"caller":"test/output.go:","msg":"stringer panic","v":0,"stringerError":"PANIC=fake String panic"} +`, + + `E output.go:] "error panic" err="" +`: `{"caller":"test/output.go:","msg":"error panic","errError":"PANIC=fake Error panic"} +`, + + `I output.go:] "marshaler panic" obj={} +`: `{"caller":"test/output.go:","msg":"marshaler panic","v":0,"objError":"PANIC=fake MarshalLog panic"} +`, + + // klog.Info + `I output.go:] "helloworld\n" +`: `{"caller":"test/output.go:","msg":"helloworld\n","v":0} +`, + + // klog.Infoln + `I output.go:] "hello world\n" +`: `{"caller":"test/output.go:","msg":"hello world\n","v":0} +`, + + // klog.Error + `E output.go:] "helloworld\n" +`: `{"caller":"test/output.go:","msg":"helloworld\n"} +`, + + // klog.Errorln + `E output.go:] "hello world\n" +`: `{"caller":"test/output.go:","msg":"hello world\n"} +`, + + // klog.ErrorS + `E output.go:] "world" err="hello" +`: `{"caller":"test/output.go:","msg":"world","err":"hello"} +`, + + // klog.InfoS + `I output.go:] "hello" what="world" +`: `{"caller":"test/output.go:","msg":"hello","v":0,"what":"world"} +`, + + // klog.V(1).Info + `I output.go:] "hellooneworld\n" +`: `{"caller":"test/output.go:","msg":"hellooneworld\n","v":1} +`, + + // klog.V(1).Infoln + `I output.go:] "hello one world\n" +`: `{"caller":"test/output.go:","msg":"hello one world\n","v":1} +`, + + // klog.V(1).ErrorS + `E output.go:] "one world" err="hello" +`: `{"caller":"test/output.go:","msg":"one world","err":"hello"} +`, + + // klog.V(1).InfoS + `I output.go:] "hello" what="one world" +`: `{"caller":"test/output.go:","msg":"hello","v":1,"what":"one world"} +`, + } +} + +// ZaprOutputMappingIndirect provides a mapping from klog output to the +// corresponding zapr output when zapr is called indirectly through +// klog. +// +// This is different from ZaprOutputMappingDirect because: +// - WithName gets added to the message by Output. +// - zap uses . as separator instead of / between WithName values, +// here we get slashes because Output concatenates these values. +// - WithValues are added to the normal key/value parameters by +// Output, which puts them after "v". +// - Output does that without emitting the warning that we get +// from zapr. +// - zap drops keys with missing values, here we get "(MISSING)". +// - zap does not de-duplicate key/value pairs, here klog does that +// for it. +// +// Experimental +// +// Notice: This package is EXPERIMENTAL and may be changed or removed in a +// later release. +func ZaprOutputMappingIndirect() map[string]string { + mapping := ZaprOutputMappingDirect() + + for key, value := range map[string]string{ + `I output.go:] "hello/world: test" akey="avalue" +`: `{"caller":"test/output.go:","msg":"hello/world: test","v":0,"akey":"avalue"} +`, + + `I output.go:] "me: test" akey="avalue" +`: `{"caller":"test/output.go:","msg":"me: test","v":0,"akey":"avalue"} +`, + + `I output.go:] "odd parameters" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"akey2"} +{"caller":"test/output.go:","msg":"odd parameters","v":0,"basekey1":"basevar1","basekey2":"(MISSING)","akey":"avalue"} +`, + + `I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" anotherKeyWithoutValue="(MISSING)" +I output.go:] "odd WithValues" keyWithoutValue="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd WithValues","v":0,"keyWithoutValue":"(MISSING)"} +{"caller":"test/output.go:","msg":"odd WithValues","v":0,"keyWithoutValue":"(MISSING)","anotherKeyWithoutValue":"(MISSING)"} +{"caller":"test/output.go:","msg":"odd WithValues","v":0,"keyWithoutValue":"(MISSING)"} +`, + + `I output.go:] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"akey2"} +{"caller":"test/output.go:","msg":"both odd","v":0,"basekey1":"basevar1","basekey2":"(MISSING)","akey":"avalue"} +`, + + `I output.go:] "test" akey9="avalue9" akey8="avalue8" akey1="avalue1" akey5="avalue5" akey4="avalue4" +`: `{"caller":"test/output.go:","msg":"test","v":0,"akey9":"avalue9","akey8":"avalue8","akey1":"avalue1","akey5":"avalue5","akey4":"avalue4"} +`, + + `I output.go:] "test" akey="avalue2" +`: `{"caller":"test/output.go:","msg":"test","v":0,"akey":"avalue2"} +`, + + `I output.go:] "test" X="y" duration="1m0s" A="b" +`: `{"caller":"test/output.go:","msg":"test","v":0,"X":"y","duration":"1m0s","A":"b"} +`, + + `I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=2 +I output.go:] "test" firstKey=1 +I output.go:] "test" firstKey=1 secondKey=3 +`: `{"caller":"test/output.go:","msg":"test","v":0,"firstKey":1} +{"caller":"test/output.go:","msg":"test","v":0,"firstKey":1,"secondKey":2} +{"caller":"test/output.go:","msg":"test","v":0,"firstKey":1} +{"caller":"test/output.go:","msg":"test","v":0,"firstKey":1,"secondKey":3} +`, + } { + mapping[key] = value + } + return mapping +} diff --git a/vendor/modules.txt b/vendor/modules.txt index 13fbafc16ed..26f582f6b97 100644 --- a/vendor/modules.txt +++ b/vendor/modules.txt @@ -2137,6 +2137,7 @@ k8s.io/klog/v2/internal/buffer k8s.io/klog/v2/internal/clock k8s.io/klog/v2/internal/serialize k8s.io/klog/v2/internal/severity +k8s.io/klog/v2/test # k8s.io/kube-aggregator v0.0.0 => ./staging/src/k8s.io/kube-aggregator ## explicit; go 1.18 k8s.io/kube-aggregator/pkg/apis/apiregistration