From 7fe422138ac62b5811fe7b1be134c6d09720e480 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E6=9D=A8=E5=86=9B10092085?= Date: Sun, 28 Aug 2022 00:38:36 +0800 Subject: [PATCH] add klog.v(0) and logger.v(0) check --- logcheck/main_test.go | 15 ++++ logcheck/pkg/logcheck.go | 72 ++++++++++++++++--- .../allowVerbosityZeroLogs.go | 69 ++++++++++++++++++ .../doNotAllowVerbosityZeroLogs.go | 69 ++++++++++++++++++ 4 files changed, 217 insertions(+), 8 deletions(-) create mode 100644 logcheck/testdata/src/allowVerbosityZeroLogs/allowVerbosityZeroLogs.go create mode 100644 logcheck/testdata/src/doNotAllowVerbosityZeroLogs/doNotAllowVerbosityZeroLogs.go diff --git a/logcheck/main_test.go b/logcheck/main_test.go index 4f9d66a..db19652 100644 --- a/logcheck/main_test.go +++ b/logcheck/main_test.go @@ -103,6 +103,21 @@ func TestAnalyzer(t *testing.T) { }, testPackage: "helpers", }, + { + name: "Do not allow Verbosity Zero logs", + enabled: map[string]string{ + "structured": "false", + }, + testPackage: "doNotAllowVerbosityZeroLogs", + }, + { + name: "Allow Verbosity Zero logs", + enabled: map[string]string{ + "structured": "false", + "verbosity-zero": "false", + }, + testPackage: "allowVerbosityZeroLogs", + }, } 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 38122de..2973360 100644 --- a/logcheck/pkg/logcheck.go +++ b/logcheck/pkg/logcheck.go @@ -32,10 +32,11 @@ import ( ) const ( - structuredCheck = "structured" - parametersCheck = "parameters" - contextualCheck = "contextual" - withHelpersCheck = "with-helpers" + structuredCheck = "structured" + parametersCheck = "parameters" + contextualCheck = "contextual" + withHelpersCheck = "with-helpers" + verbosityZeroCheck = "verbosity-zero" ) type checks map[string]*bool @@ -53,10 +54,11 @@ func (c config) isEnabled(check string, filename string) bool { func Analyser() *analysis.Analyzer { c := config{ enabled: checks{ - structuredCheck: new(bool), - parametersCheck: new(bool), - contextualCheck: new(bool), - withHelpersCheck: new(bool), + structuredCheck: new(bool), + parametersCheck: new(bool), + contextualCheck: new(bool), + withHelpersCheck: new(bool), + verbosityZeroCheck: new(bool), }, } c.fileOverrides.validChecks = map[string]bool{} @@ -70,6 +72,7 @@ klog methods (Info, Infof, Error, Errorf, Warningf, etc).`) logcheckFlags.BoolVar(c.enabled[parametersCheck], prefix+parametersCheck, true, `When true, logcheck will check parameters of structured logging calls.`) logcheckFlags.BoolVar(c.enabled[contextualCheck], prefix+contextualCheck, false, `When true, logcheck will only allow log calls for contextual logging (retrieving a Logger from klog or the context and logging through that) and warn about all others.`) 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.Var(&c.fileOverrides, "config", `A file which overrides the global settings for checks on a per-file basis via regular expressions.`) // Use env variables as defaults. This is necessary when used as plugin @@ -172,6 +175,11 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { checkForFormatSpecifier(fexpr, pass) } } + // verbosity Zero Check + if c.isEnabled(verbosityZeroCheck, filename) { + checkForVerbosityZero(fexpr, pass) + } + } else if isGoLogger(selExpr.X, pass) { if c.isEnabled(parametersCheck, filename) { checkForFormatSpecifier(fexpr, pass) @@ -193,6 +201,10 @@ func checkForFunctionExpr(fexpr *ast.CallExpr, pass *analysis.Pass, c *config) { }) } } + // verbosity Zero Check + if c.isEnabled(verbosityZeroCheck, filename) { + checkForVerbosityZero(fexpr, pass) + } } else if fName == "NewContext" && isPackage(selExpr.X, "github.com/go-logr/logr", pass) && c.isEnabled(withHelpersCheck, filename) { @@ -496,3 +508,47 @@ func checkForIfEnabled(i *ast.IfStmt, pass *analysis.Pass, c *config) { funcCall, varName, funcCall, varName, varName), }) } + +func checkForVerbosityZero(fexpr *ast.CallExpr, pass *analysis.Pass) { + iselExpr, ok := fexpr.Fun.(*ast.SelectorExpr) + if !ok { + return + } + expr := iselExpr.X + if !isKlogVerbose(expr, pass) && !isGoLogger(expr, pass) { + return + } + if isVerbosityZero(expr) { + msg := fmt.Sprintf("Logging with V(0) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.") + pass.Report(analysis.Diagnostic{ + Pos: fexpr.Fun.Pos(), + Message: msg, + }) + } +} + +func isVerbosityZero(expr ast.Expr) bool { + subCallExpr, ok := expr.(*ast.CallExpr) + if !ok { + return false + } + subSelExpr, ok := subCallExpr.Fun.(*ast.SelectorExpr) + if !ok || subSelExpr.Sel.Name != "V" || len(subCallExpr.Args) != 1 { + return false + } + + if lit, ok := subCallExpr.Args[0].(*ast.BasicLit); ok && lit.Value == "0" { + return true + } + + if id, ok := subCallExpr.Args[0].(*ast.Ident); ok && id.Obj.Kind == 2 { + v, ok := id.Obj.Decl.(*ast.ValueSpec) + if !ok || len(v.Values) != 1 { + return false + } + if lit, ok := v.Values[0].(*ast.BasicLit); ok && lit.Value == "0" { + return true + } + } + return false +} diff --git a/logcheck/testdata/src/allowVerbosityZeroLogs/allowVerbosityZeroLogs.go b/logcheck/testdata/src/allowVerbosityZeroLogs/allowVerbosityZeroLogs.go new file mode 100644 index 0000000..ee1ebf2 --- /dev/null +++ b/logcheck/testdata/src/allowVerbosityZeroLogs/allowVerbosityZeroLogs.go @@ -0,0 +1,69 @@ +/* +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. +*/ + +// This fake package is created as golang.org/x/tools/go/analysis/analysistest +// expects it to be here for loading. This package is used to test allow-unstructured +// flag which suppresses errors when unstructured logging is used. +// This is a test file for unstructured logging static check tool unit tests. + +package Verbosity + +import ( + "github.com/go-logr/logr" + klog "k8s.io/klog/v2" +) + +const ( + zeroConst = 0 + oneConst = 1 +) + +var ( + zeroVar klog.Level = 0 + oneVar klog.Level = 1 + l, logger logr.Logger +) + +func verbosityLogging() { + klog.V(0).Info("test log") + klog.V(0).Infof("test log") + klog.V(0).Infoln("test log") + klog.V(0).InfoS("I'm logging at level 0.") + klog.V(zeroConst).InfoS("I'm logging at level 0.") + klog.V(zeroVar).InfoS("I'm logging at level 0.") + klog.V(1).Info("test log") + klog.V(1).Infof("test log") + klog.V(1).Infoln("test log") + klog.V(1).InfoS("I'm logging at level 1.") + klog.V(oneConst).InfoS("I'm logging at level 1.") + klog.V(oneVar).InfoS("I'm logging at level 1.") + klog.Info("test log") + klog.Infof("test log") + klog.Infoln("test log") + klog.InfoS("I'm logging at level 0.") + + logger.Info("hello", "1", "2") + logger.Error(nil, "hello", "1", "2") + logger.WithValues("1", "2") + + logger.V(0).Info("hello", "1", "2") + logger.V(0).Error(nil, "hello", "1", "2") + logger.V(0).WithValues("1", "2") + + logger.V(1).Info("hello", "1", "2") + logger.V(1).Error(nil, "hello", "1", "2") + logger.V(1).WithValues("1", "2") +} diff --git a/logcheck/testdata/src/doNotAllowVerbosityZeroLogs/doNotAllowVerbosityZeroLogs.go b/logcheck/testdata/src/doNotAllowVerbosityZeroLogs/doNotAllowVerbosityZeroLogs.go new file mode 100644 index 0000000..4b6ede8 --- /dev/null +++ b/logcheck/testdata/src/doNotAllowVerbosityZeroLogs/doNotAllowVerbosityZeroLogs.go @@ -0,0 +1,69 @@ +/* +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. +*/ + +// This fake package is created as golang.org/x/tools/go/analysis/analysistest +// expects it to be here for loading. This package is used to test allow-unstructured +// flag which suppresses errors when unstructured logging is used. +// This is a test file for unstructured logging static check tool unit tests. + +package Verbosity + +import ( + "github.com/go-logr/logr" + klog "k8s.io/klog/v2" +) + +const ( + zeroConst = 0 + oneConst = 1 +) + +var ( + zeroVar klog.Level = 0 + oneVar klog.Level = 1 + l, logger logr.Logger +) + +func verbosityLogging() { + klog.V(0).Info("test log") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + klog.V(0).Infof("test log") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + klog.V(0).Infoln("test log") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + klog.V(0).InfoS("I'm logging at level 0.") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + klog.V(zeroConst).InfoS("I'm logging at level 0.") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + klog.V(zeroVar).InfoS("I'm logging at level 0.") + klog.V(1).Info("test log") + klog.V(1).Infof("test log") + klog.V(1).Infoln("test log") + klog.V(1).InfoS("I'm logging at level 1.") + klog.V(oneConst).InfoS("I'm logging at level 1.") + klog.V(oneVar).InfoS("I'm logging at level 1.") + klog.Info("test log") + klog.Infof("test log") + klog.Infoln("test log") + klog.InfoS("I'm logging at level 0.") + + logger.Info("hello", "1", "2") + logger.Error(nil, "hello", "1", "2") + logger.WithValues("1", "2") + + logger.V(0).Info("hello", "1", "2") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + logger.V(0).Error(nil, "hello", "1", "2") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + logger.V(0).WithValues("1", "2") // want `Logging with V\(0\) is semantically equivalent to the same expression without it and just causes unnecessary overhead. It should get removed.` + + logger.V(1).Info("hello", "1", "2") + logger.V(1).Error(nil, "hello", "1", "2") + logger.V(1).WithValues("1", "2") +}