diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 1e6806d1..5ff4d899 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -14,11 +14,14 @@ jobs: go-version: ${{ matrix.go-version }} - name: Checkout code uses: actions/checkout@v2 - - name: Test + - name: Test klog run: | go get -t -v ./... go test -v -race ./... - cd hack/tools && go test -v -race ./... + - name: Test hack/tools + run: cd hack/tools && go test -v -race ./... + - name: Test examples + run: cd examples && go test -v -race ./... lint: runs-on: ubuntu-latest steps: diff --git a/examples/go.mod b/examples/go.mod index 2768f2c1..d7956666 100644 --- a/examples/go.mod +++ b/examples/go.mod @@ -3,7 +3,10 @@ module example go 1.13 require ( + github.com/go-logr/logr v1.2.2 + github.com/go-logr/zapr v1.2.2 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b + go.uber.org/zap v1.19.0 k8s.io/klog/v2 v2.30.0 ) diff --git a/examples/go.sum b/examples/go.sum index 4d41cc90..5b43f393 100644 --- a/examples/go.sum +++ b/examples/go.sum @@ -1,8 +1,56 @@ -github.com/go-logr/logr v0.1.0 h1:M1Tv3VzNlEHg6uyACnRdtrploV2P7wZqH8BoQMtz0cg= -github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas= -github.com/go-logr/logr v1.2.0 h1:QK40JKJyMdUDz+h+xvCsru/bJhvG0UxvePV0ufL/AcE= +github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8= +github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +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.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.2.2 h1:ahHml/yUpnlb96Rp8HCvtYVPY8ZYpxq3g7UYchIYwbs= +github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/zapr v1.2.2 h1:5YNlIL6oZLydaV4dOFjL8YpgXF/tPeTbnpatnu3cq6o= +github.com/go-logr/zapr v1.2.2/go.mod h1:eIauM6P8qSvTw5o2ez6UEAfGjQKrxQTl5EoK+Qa2oG4= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b h1:VKtxabqXZkF25pY9ekfRL6a582T4P37/31XEstQ5p58= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= -k8s.io/klog/v2 v2.0.0-20200324194303-db919253a3bc h1:E/enZ+SqXD3ChluFNvXqlLcUkqMQQDpiyGruRq5pjvY= -k8s.io/klog/v2 v2.0.0-20200324194303-db919253a3bc/go.mod h1:q4PVo0BneA7GsUJvFqoEvOCVmYJP0c5Y4VxrAYpJrIk= +github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= +github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +go.uber.org/atomic v1.7.0 h1:ADUqmZGgLDDfbSL9ZmPxKTybcoEYHgpYfELNoN+7hsw= +go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/goleak v1.1.10 h1:z+mqJhf6ss6BSfSM671tgKyZBFPTTJM+HLxnhPC3wu0= +go.uber.org/goleak v1.1.10/go.mod h1:8a7PlsEVH3e/a/GLqe5IIrQx6GzcnRmZEufDUTk4A7A= +go.uber.org/multierr v1.6.0 h1:y6IPFStTAIT5Ytl7/XYmHvzXQ7S3g/IeZW9hyZ5thw4= +go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= +go.uber.org/zap v1.19.0 h1:mZQZefskPPCMIBCSEH0v2/iUqqLrYtaeqwD6FUGUnFE= +go.uber.org/zap v1.19.0/go.mod h1:xg/QME4nWcxGxrpdeYfq7UvYrLh66cuVKdrbD1XF/NI= +golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/lint v0.0.0-20190930215403-16217165b5de h1:5hukYrvBGR8/eNkX5mdUezrA6JiaEZDtJb9Ei+1LlBs= +golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc= +golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= +golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs= +golang.org/x/tools v0.0.0-20191108193012-7d206e10da11 h1:Yq9t9jnGoR+dBuitxdo9l6Q7xh/zOyNnYUtDKaQ3x0E= +golang.org/x/tools v0.0.0-20191108193012-7d206e10da11/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= +golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.8 h1:obN1ZagJSUGI0Ek/LBmuj4SNLPfIny3KsKFopxRdj10= +gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b h1:h8qDotaEPuJATrMmW04NCwg7v22aHH28wwpauUhK9Oo= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/examples/output_test/output_test.go b/examples/output_test/output_test.go new file mode 100644 index 00000000..0624e3a7 --- /dev/null +++ b/examples/output_test/output_test.go @@ -0,0 +1,153 @@ +/* +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 output_test shows how to use k8s.io/klog/v2/test +// and provides unit testing with dependencies that wouldn't +// be acceptable for the main module. +package output_test + +import ( + "io" + "testing" + + "github.com/go-logr/logr" + "github.com/go-logr/zapr" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + + "k8s.io/klog/v2" + "k8s.io/klog/v2/klogr" + "k8s.io/klog/v2/test" + "k8s.io/klog/v2/textlogger" +) + +func init() { + test.InitKlog() +} + +// TestKlogOutput tests klog output without a logger. +func TestKlogOutput(t *testing.T) { + test.Output(t, test.OutputConfig{}) +} + +// TestTextloggerOutput tests the textlogger, directly and as backend. +func TestTextloggerOutput(t *testing.T) { + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + config := textlogger.NewConfig( + textlogger.Verbosity(v), + textlogger.Output(out), + ) + if err := config.VModule().Set(vmodule); err != nil { + panic(err) + } + return textlogger.NewLogger(config) + } + t.Run("direct", func(t *testing.T) { + test.Output(t, test.OutputConfig{NewLogger: newLogger, SupportsVModule: true}) + }) + t.Run("klog-backend", func(t *testing.T) { + test.Output(t, test.OutputConfig{NewLogger: newLogger, AsBackend: true}) + }) +} + +// TestTextloggerOutput tests the zapr, directly and as backend. +func TestZaprOutput(t *testing.T) { + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + return newZaprLogger(out, v) + } + t.Run("direct", func(t *testing.T) { + test.Output(t, test.OutputConfig{NewLogger: newLogger, ExpectedOutputMapping: test.ZaprOutputMappingDirect()}) + }) + t.Run("klog-backend", func(t *testing.T) { + test.Output(t, test.OutputConfig{NewLogger: newLogger, AsBackend: true, ExpectedOutputMapping: test.ZaprOutputMappingIndirect()}) + }) +} + +// TestKlogrOutput tests klogr output via klog. +func TestKlogrOutput(t *testing.T) { + test.Output(t, test.OutputConfig{ + NewLogger: func(out io.Writer, v int, vmodule string) logr.Logger { + return klogr.NewWithOptions(klogr.WithFormat(klogr.FormatKlog)) + }, + }) +} + +// TestKlogrStackText tests klogr -> klog -> text logger. +func TestKlogrStackText(t *testing.T) { + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + // Backend: text output. + config := textlogger.NewConfig( + textlogger.Verbosity(v), + textlogger.Output(out), + ) + if err := config.VModule().Set(vmodule); err != nil { + panic(err) + } + klog.SetLogger(textlogger.NewLogger(config)) + + // Frontend: klogr. + return klogr.NewWithOptions(klogr.WithFormat(klogr.FormatKlog)) + } + test.Output(t, test.OutputConfig{NewLogger: newLogger, SupportsVModule: true}) +} + +// TestKlogrStackKlogr tests klogr -> klog -> zapr. +// +// This exposes whether verbosity is passed through correctly +// (https://github.com/kubernetes/klog/issues/294) because klogr logging +// records that. +func TestKlogrStackZapr(t *testing.T) { + mapping := test.ZaprOutputMappingIndirect() + + // klogr doesn't warn about invalid KVs and just inserts + // "(MISSING)". + for key, value := range map[string]string{ + `I output.go:] "odd arguments" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"odd arguments","v":0,"akey":"avalue","akey2":"(MISSING)"} +`, + + `I output.go:] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" +`: `{"caller":"test/output.go:","msg":"both odd","v":0,"basekey1":"basevar1","basekey2":"(MISSING)","akey":"avalue","akey2":"(MISSING)"} +`, + } { + mapping[key] = value + } + + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + // Backend: zapr as configured in k8s.io/component-base/logs/json. + klog.SetLogger(newZaprLogger(out, v)) + + // Frontend: klogr. + return klogr.NewWithOptions(klogr.WithFormat(klogr.FormatKlog)) + } + test.Output(t, test.OutputConfig{NewLogger: newLogger, ExpectedOutputMapping: mapping}) +} + +func newZaprLogger(out io.Writer, v int) logr.Logger { + encoderConfig := &zapcore.EncoderConfig{ + MessageKey: "msg", + CallerKey: "caller", + NameKey: "logger", + EncodeDuration: zapcore.StringDurationEncoder, + EncodeCaller: zapcore.ShortCallerEncoder, + } + encoder := zapcore.NewJSONEncoder(*encoderConfig) + zapV := -zapcore.Level(v) + core := zapcore.NewCore(encoder, zapcore.AddSync(out), zapV) + l := zap.New(core, zap.WithCaller(true)) + logger := zapr.NewLoggerWithOptions(l, zapr.LogInfoLevel("v"), zapr.ErrorKey("err")) + return logger +} diff --git a/klogr/klogr.go b/klogr/klogr.go index 02433e84..8206c10d 100644 --- a/klogr/klogr.go +++ b/klogr/klogr.go @@ -122,13 +122,13 @@ func (l klogger) Info(level int, msg string, kvList ...interface{}) { trimmed := serialize.TrimDuplicates(l.values, kvList) fixedStr := flatten(trimmed[0]...) userStr := flatten(trimmed[1]...) - klog.InfoDepth(l.callDepth+1, l.prefix, " ", msgStr, " ", fixedStr, " ", userStr) + klog.V(klog.Level(level)).InfoDepth(l.callDepth+1, l.prefix, " ", msgStr, " ", fixedStr, " ", userStr) case FormatKlog: trimmed := serialize.TrimDuplicates(l.values, kvList) if l.prefix != "" { msg = l.prefix + ": " + msg } - klog.InfoSDepth(l.callDepth+1, msg, append(trimmed[0], trimmed[1]...)...) + klog.V(klog.Level(level)).InfoSDepth(l.callDepth+1, msg, append(trimmed[0], trimmed[1]...)...) } } diff --git a/test/output.go b/test/output.go index a4174914..0c447a82 100644 --- a/test/output.go +++ b/test/output.go @@ -67,7 +67,9 @@ func InitKlog() { // 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. + // 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 @@ -187,10 +189,10 @@ func Output(t *testing.T, config OutputConfig) { "odd WithValues": { withValues: []interface{}{"keyWithoutValue"}, moreValues: []interface{}{"anotherKeyWithoutValue"}, - text: "test", - expectedOutput: `I output.go:] "test" keyWithoutValue="(MISSING)" -I output.go:] "test" keyWithoutValue="(MISSING)" anotherKeyWithoutValue="(MISSING)" -I output.go:] "test" keyWithoutValue="(MISSING)" + 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": { @@ -228,9 +230,9 @@ I output.go:] "test" firstKey=1 secondKey=3 `, }, "handle odd-numbers of KVs": { - text: "test", + text: "odd arguments", values: []interface{}{"akey", "avalue", "akey2"}, - expectedOutput: `I output.go:] "test" akey="avalue" akey2="(MISSING)" + expectedOutput: `I output.go:] "odd arguments" akey="avalue" akey2="(MISSING)" `, }, "html characters": { @@ -247,9 +249,9 @@ I output.go:] "test" firstKey=1 secondKey=3 }, "handle odd-numbers of KVs in both log values and Info args": { withValues: []interface{}{"basekey1", "basevar1", "basekey2"}, - text: "test", + text: "both odd", values: []interface{}{"akey", "avalue", "akey2"}, - expectedOutput: `I output.go:] "test" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" + expectedOutput: `I output.go:] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)" `, }, "KObj": { @@ -289,6 +291,8 @@ I output.go:] "test" firstKey=1 secondKey=3 } 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) @@ -298,21 +302,21 @@ I output.go:] "test" firstKey=1 secondKey=3 // the combination, then again the original logger. // It must not have been modified. This produces // three log entries. - logger = logger.WithValues(test.withValues...) + logger = logger.WithValues(test.withValues...) // loggers := []logr.Logger{logger} if test.moreValues != nil { - loggers = append(loggers, logger.WithValues(test.moreValues...), logger) + loggers = append(loggers, logger.WithValues(test.moreValues...), logger) // } if test.evenMoreValues != nil { - loggers = append(loggers, logger.WithValues(test.evenMoreValues...)) + loggers = append(loggers, logger.WithValues(test.evenMoreValues...)) // } for _, logger := range loggers { if test.withHelper { - loggerHelper(logger, test.text, test.values) + loggerHelper(logger, test.text, test.values) // } else if test.err != nil { - logger.Error(test.err, test.text, test.values...) + logger.Error(test.err, test.text, test.values...) // } else { - logger.V(test.v).Info(test.text, test.values...) + logger.V(test.v).Info(test.text, test.values...) // } } } @@ -394,12 +398,17 @@ I output.go:] "test" firstKey=1 secondKey=3 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 { - t.Errorf("Output mismatch. Expected:\n%s\nActual:\n%s\n", expected, actual) + 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) + } } } @@ -414,7 +423,6 @@ I output.go:] "test" firstKey=1 secondKey=3 if config.AsBackend { testOutput(t, printWithKlogLine, func(buffer *bytes.Buffer) { klog.SetLogger(config.NewLogger(buffer, 10, "")) - defer klog.ClearLogger() printWithKlog() }) return @@ -645,9 +653,14 @@ I output.go:] "test" firstKey=1 secondKey=3 if repl, ok := config.ExpectedOutputMapping[expected]; ok { expected = repl } + expectedWithPlaceholder := expected expected = strings.ReplaceAll(expected, "", fmt.Sprintf("%d", callLine)) if actual != expected { - t.Errorf("Output mismatch. Expected:\n%s\nActual:\n%s\n", expected, actual) + 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) + } } }) } diff --git a/test/output_test.go b/test/output_test.go deleted file mode 100644 index 5a43a1ce..00000000 --- a/test/output_test.go +++ /dev/null @@ -1,65 +0,0 @@ -/* -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 ( - "io" - "testing" - - "github.com/go-logr/logr" - - "k8s.io/klog/v2/klogr" - "k8s.io/klog/v2/textlogger" -) - -func init() { - InitKlog() -} - -// TestKlogOutput tests klog output without a logger. -func TestKlogOutput(t *testing.T) { - Output(t, OutputConfig{}) -} - -// TestTextloggerOutput tests the textlogger, directly and as backend. -func TestTextloggerOutput(t *testing.T) { - newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { - config := textlogger.NewConfig( - textlogger.Verbosity(v), - textlogger.Output(out), - ) - if err := config.VModule().Set(vmodule); err != nil { - panic(err) - } - return textlogger.NewLogger(config) - } - t.Run("direct", func(t *testing.T) { - Output(t, OutputConfig{NewLogger: newLogger, SupportsVModule: true}) - }) - t.Run("klog-backend", func(t *testing.T) { - Output(t, OutputConfig{NewLogger: newLogger, AsBackend: true}) - }) -} - -// TestKlogrOutput tests klogr output via klog. -func TestKlogrOutput(t *testing.T) { - Output(t, OutputConfig{ - NewLogger: func(out io.Writer, v int, vmodule string) logr.Logger { - return klogr.NewWithOptions(klogr.WithFormat(klogr.FormatKlog)) - }, - }) -} diff --git a/test/zapr.go b/test/zapr.go new file mode 100644 index 00000000..0bd94731 --- /dev/null +++ b/test/zapr.go @@ -0,0 +1,246 @@ +/* +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"} +`, + + // 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 +}