From 1399d95e1c12ffa321cb4162f1271d392e01fb68 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Tue, 28 Mar 2023 16:53:58 +0200 Subject: [PATCH] logcheck: check that fmt.Stringer gets implemented properly If a type inherits String from some embedded field, then the klog text output will only print the result of that function call, which then includes only information about the embedded field (example: https://github.com/kubernetes/kubernetes/pull/115950). The right solution for this problem is TBD. --- logcheck/main_test.go | 14 +++ logcheck/pkg/logcheck.go | 102 ++++++++++++++++-- .../apimachinery/pkg/apis/meta/v1/types.go | 40 +++++++ logcheck/testdata/src/marshaler/marshaler.go | 59 ++++++++++ logcheck/testdata/src/stringer/stringer.go | 56 ++++++++++ 5 files changed, 263 insertions(+), 8 deletions(-) create mode 100644 logcheck/testdata/src/k8s.io/apimachinery/pkg/apis/meta/v1/types.go create mode 100644 logcheck/testdata/src/marshaler/marshaler.go create mode 100644 logcheck/testdata/src/stringer/stringer.go diff --git a/logcheck/main_test.go b/logcheck/main_test.go index 4394332..8fad590 100644 --- a/logcheck/main_test.go +++ b/logcheck/main_test.go @@ -143,6 +143,20 @@ func TestAnalyzer(t *testing.T) { }, testPackage: "allowBadkeysLogs", }, + { + name: "Detect incomplete fmt.Stringer", + enabled: map[string]string{ + "value": "true", + }, + testPackage: "stringer", + }, + { + name: "Detect incomplete logr.Marshaler", + enabled: map[string]string{ + "value": "true", + }, + testPackage: "marshaler", + }, } for _, tc := range tests { t.Run(tc.name, func(t *testing.T) { diff --git a/logcheck/pkg/logcheck.go b/logcheck/pkg/logcheck.go index f1f8249..20dec91 100644 --- a/logcheck/pkg/logcheck.go +++ b/logcheck/pkg/logcheck.go @@ -39,6 +39,7 @@ const ( withHelpersCheck = "with-helpers" verbosityZeroCheck = "verbosity-zero" keyCheck = "key" + valueCheck = "value" deprecationsCheck = "deprecations" ) @@ -63,6 +64,7 @@ func Analyser() *analysis.Analyzer { withHelpersCheck: new(bool), verbosityZeroCheck: new(bool), keyCheck: new(bool), + valueCheck: new(bool), deprecationsCheck: new(bool), }, } @@ -79,6 +81,7 @@ klog methods (Info, Infof, Error, Errorf, Warningf, etc).`) logcheckFlags.BoolVar(c.enabled[withHelpersCheck], prefix+withHelpersCheck, false, `When true, logcheck will warn about direct calls to WithName, WithValues and NewContext.`) logcheckFlags.BoolVar(c.enabled[verbosityZeroCheck], prefix+verbosityZeroCheck, true, `When true, logcheck will check whether the parameter for V() is 0.`) logcheckFlags.BoolVar(c.enabled[keyCheck], prefix+keyCheck, true, `When true, logcheck will check whether name arguments are valid keys according to the guidelines in (https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#name-arguments).`) + logcheckFlags.BoolVar(c.enabled[valueCheck], prefix+valueCheck, false, `When true, logcheck will check for problematic values (for example, types that have an incomplete fmt.Stringer implementation).`) logcheckFlags.BoolVar(c.enabled[deprecationsCheck], prefix+deprecationsCheck, true, `When true, logcheck will analyze the usage of deprecated Klog function calls.`) logcheckFlags.Var(&c.fileOverrides, "config", `A file which overrides the global settings for checks on a per-file basis via regular expressions.`) @@ -145,6 +148,7 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { fName := selExpr.Sel.Name filename := pass.Pkg.Path() + "/" + path.Base(pass.Fset.Position(fexpr.Pos()).Filename) + valueCheckEnabled := c.isEnabled(valueCheck, filename) keyCheckEnabled := c.isEnabled(keyCheck, filename) parametersCheckEnabled := c.isEnabled(parametersCheck, filename) @@ -178,7 +182,7 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { return } - if keyCheckEnabled || parametersCheckEnabled { + if keyCheckEnabled || parametersCheckEnabled || valueCheckEnabled { // if format specifier is used, check for arg length will most probably fail // so check for format specifier first and skip if found if parametersCheckEnabled && checkForFormatSpecifier(fexpr, pass) { @@ -186,9 +190,9 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { } switch fName { case "InfoS": - kvCheck(args[1:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled) + kvCheck(args[1:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled) case "ErrorS": - kvCheck(args[2:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled) + kvCheck(args[2:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled) } } // verbosity Zero Check @@ -196,7 +200,7 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { checkForVerbosityZero(fexpr, pass) } } else if isGoLogger(selExpr.X, pass) { - if keyCheckEnabled || parametersCheckEnabled { + if keyCheckEnabled || parametersCheckEnabled || valueCheckEnabled { // if format specifier is used, check for arg length will most probably fail // so check for format specifier first and skip if found if parametersCheckEnabled && checkForFormatSpecifier(fexpr, pass) { @@ -204,11 +208,11 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { } switch fName { case "WithValues": - kvCheck(args, fun, pass, fName, keyCheckEnabled, parametersCheckEnabled) + kvCheck(args, fun, pass, fName, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled) case "Info": - kvCheck(args[1:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled) + kvCheck(args[1:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled) case "Error": - kvCheck(args[2:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled) + kvCheck(args[2:], fun, pass, fName, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled) } } if c.isEnabled(withHelpersCheck, filename) { @@ -550,7 +554,7 @@ func isVerbosityZero(expr ast.Expr) bool { // kvCheck check if all keys in keyAndValues are valid keys according to the guidelines // and that the values can be formatted. -func kvCheck(keyValues []ast.Expr, fun ast.Expr, pass *analysis.Pass, funName string, keyCheckEnabled, parametersCheckEnabled bool) { +func kvCheck(keyValues []ast.Expr, fun ast.Expr, pass *analysis.Pass, funName string, keyCheckEnabled, parametersCheckEnabled, valueCheckEnabled bool) { if len(keyValues)%2 != 0 { pass.Report(analysis.Diagnostic{ Pos: fun.Pos(), @@ -561,6 +565,14 @@ func kvCheck(keyValues []ast.Expr, fun ast.Expr, pass *analysis.Pass, funName st for index, arg := range keyValues { if index%2 != 0 { + // Check values? + if valueCheckEnabled { + // Check the type. + if typeAndValue, ok := pass.TypesInfo.Types[arg]; ok { + checkFormatter(pass, arg, typeAndValue, "String", "fmt.Stringer", isFmtStringer) + checkFormatter(pass, arg, typeAndValue, "MarshalLog", "logr.Marshaler", isLogrMarshaler) + } + } continue } @@ -608,3 +620,77 @@ func kvCheck(keyValues []ast.Expr, fun ast.Expr, pass *analysis.Pass, funName st } } } + +func checkFormatter(pass *analysis.Pass, arg ast.Expr, typeAndValue types.TypeAndValue, methodName, interfaceName string, check func(function *types.Func) bool) { + if obj, index, _ := types.LookupFieldOrMethod(typeAndValue.Type, typeAndValue.Addressable(), nil /* package */, methodName); obj != nil { + if function, ok := obj.(*types.Func); ok && len(index) > 1 && check(function) && !isWrapperStruct(typeAndValue.Type) { + pass.Report(analysis.Diagnostic{ + Pos: arg.Pos(), + Message: fmt.Sprintf("The type %s inherits %s as implementation of %s, which covers only a subset of the value. Implement %s for the type or wrap it with klog.Format.", typeAndValue.Type.String(), function.FullName(), interfaceName, methodName), + }) + } + } +} + +// isFmtStringer checks whether the function has the "func() string" signature. +func isFmtStringer(function *types.Func) bool { + signature, ok := function.Type().(*types.Signature) + if !ok { + return false + } + params := signature.Params() + if params != nil && params.Len() != 0 { + return false + } + results := signature.Results() + if results == nil || results.Len() != 1 { + return false + } + result := results.At(0) + basic, ok := result.Type().(*types.Basic) + if !ok { + return false + } + if basic.Kind() != types.String { + return false + } + return true +} + +// isLogrMarshaler checks whether the function has the "func() interface{}" signature. +func isLogrMarshaler(function *types.Func) bool { + signature, ok := function.Type().(*types.Signature) + if !ok { + return false + } + params := signature.Params() + if params != nil && params.Len() != 0 { + return false + } + results := signature.Results() + if results == nil || results.Len() != 1 { + return false + } + result := results.At(0) + if _, ok := result.Type().(*types.Interface); !ok { + return false + } + return true +} + +// isWrapperStruct returns true for types that are a struct with a single field +// or a pointer to one, like for example +// https://pkg.go.dev/k8s.io/apimachinery/pkg/apis/meta/v1#Time. +func isWrapperStruct(t types.Type) bool { + if ptr, ok := t.(*types.Pointer); ok { + t = ptr.Elem() + } + if named, ok := t.(*types.Named); ok { + t = named.Underlying() + } + if strct, ok := t.(*types.Struct); ok { + return strct.NumFields() == 1 + } + + return false +} diff --git a/logcheck/testdata/src/k8s.io/apimachinery/pkg/apis/meta/v1/types.go b/logcheck/testdata/src/k8s.io/apimachinery/pkg/apis/meta/v1/types.go new file mode 100644 index 0000000..597f4f2 --- /dev/null +++ b/logcheck/testdata/src/k8s.io/apimachinery/pkg/apis/meta/v1/types.go @@ -0,0 +1,40 @@ +/* +Copyright 2023 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 v1 + +import ( + "fmt" + "strings" +) + +type TypeMeta struct { + Kind string `json:"kind,omitempty" protobuf:"bytes,1,opt,name=kind"` + APIVersion string `json:"apiVersion,omitempty" protobuf:"bytes,2,opt,name=apiVersion"` +} + +// String is generated (https://github.com/kubernetes/apimachinery/blob/v0.26.3/pkg/apis/meta/v1/generated.pb.go#L4757). +func (this *TypeMeta) String() string { + if this == nil { + return "nil" + } + s := strings.Join([]string{`&TypeMeta{`, + `Kind:` + fmt.Sprintf("%v", this.Kind) + `,`, + `APIVersion:` + fmt.Sprintf("%v", this.APIVersion) + `,`, + `}`, + }, "") + return s +} diff --git a/logcheck/testdata/src/marshaler/marshaler.go b/logcheck/testdata/src/marshaler/marshaler.go new file mode 100644 index 0000000..b792ee5 --- /dev/null +++ b/logcheck/testdata/src/marshaler/marshaler.go @@ -0,0 +1,59 @@ +/* +Copyright 2023 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 marshaler + +import ( + klog "k8s.io/klog/v2" +) + +func foo() { + klog.Background().Info("Starting", "config", config{}) // want `The type marshaler.config inherits \(marshaler.Meta\).MarshalLog as implementation of logr.Marshaler, which covers only a subset of the value. Implement MarshalLog for the type or wrap it with klog.Format.` + klog.Background().Info("Starting", "config", configWithMarshaler{}) + klog.Background().Info("Starting", "config", &config{}) // want `The type \*marshaler.config inherits \(marshaler.Meta\).MarshalLog as implementation of logr.Marshaler, which covers only a subset of the value. Implement MarshalLog for the type or wrap it with klog.Format.` + klog.Background().Info("Starting", "config", &configWithMarshaler{}) + klog.Background().Info("Starting", "config", &simpleConfig{}) +} + +type Meta struct { + kind string +} + +func (m Meta) MarshalLog() interface{} { + return m.kind +} + +type config struct { + Meta // implements logr.Marshaler + + RealField int +} + +type configWithMarshaler config + +func (c configWithMarshaler) Size() int { + return 1 +} + +func (c configWithMarshaler) MarshalLog() interface{} { + return "foo" +} + +// simpleConfig only has a single field. In this case inheriting the Marshaler implementation +// is fine. +type simpleConfig struct { + Meta +} diff --git a/logcheck/testdata/src/stringer/stringer.go b/logcheck/testdata/src/stringer/stringer.go new file mode 100644 index 0000000..d13ef46 --- /dev/null +++ b/logcheck/testdata/src/stringer/stringer.go @@ -0,0 +1,56 @@ +/* +Copyright 2023 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 stringer + +import ( + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + klog "k8s.io/klog/v2" +) + +func foo() { + klog.Background().Info("Starting", "config", config{}) // No warning because TypeMeta implement String only for pointer receivers. + klog.Background().Info("Starting", "config", configWithStringer{}) + klog.Background().Info("Starting", "config", &config{}) // want `The type \*stringer.config inherits \(\*k8s.io/apimachinery/pkg/apis/meta/v1.TypeMeta\).String as implementation of fmt.Stringer, which covers only a subset of the value. Implement String for the type or wrap it with klog.Format.` + klog.Background().Info("Starting", "config", &configWithStringer{}) + klog.Background().Info("Starting", "config", &simpleConfig{}) +} + +// config mimicks KubeletConfig (see +// https://github.com/kubernetes/kubernetes/pull/115950). As far as logging is +// concerned, the type is broken: it implements fmt.Stringer because it +// embeds TypeMeta, but the result of String() is incomplete. +type config struct { + metav1.TypeMeta // implements fmt.Stringer (but only for addressable values) + + RealField int +} + +type configWithStringer config + +func (c configWithStringer) Size() int { + return 1 +} + +func (c configWithStringer) String() string { + return "foo" +} + +// simpleConfig only has a single field. In this case inheriting the String implementation +// is fine. This occurs for https://pkg.go.dev/k8s.io/apimachinery/pkg/apis/meta/v1#Time. +type simpleConfig struct { + metav1.TypeMeta +}