Static Analyzer: require log.WithError instead of log.Errorf("bad: %v", err) (#11143)

* Add analysis template with failing test

* Works for the most common use case

* Progress on tool and more test cases

* Improvements

* handle nil

* works for the most part

* Fix some TODOs in the tool

* Fix some TODOs in the tool

tools/analyzers/logruswitherror/BUILD.bazel

@@ -0,0 +1,26 @@
+load("@prysm//tools/go:def.bzl", "go_library", "go_test")
+
+go_library(
+    name = "go_default_library",
+    srcs = ["analyzer.go"],
+    importpath = "github.com/prysmaticlabs/prysm/tools/analyzers/logruswitherror",
+    visibility = ["//visibility:public"],
+    deps = [
+        "@org_golang_x_tools//go/analysis:go_default_library",
+        "@org_golang_x_tools//go/analysis/passes/inspect:go_default_library",
+        "@org_golang_x_tools//go/ast/inspector:go_default_library",
+    ],
+)
+
+go_test(
+    name = "go_default_test",
+    srcs = ["analyzer_test.go"],
+    data = glob(["testdata/**"]) + [
+        "@go_sdk//:files",
+    ],
+    embed = [":go_default_library"],
+    deps = [
+        "//build/bazel:go_default_library",
+        "@org_golang_x_tools//go/analysis/analysistest:go_default_library",
+    ],
+)

tools/analyzers/logruswitherror/analyzer.go

@@ -0,0 +1,103 @@
+// Package logruswitherror implements a static analyzer to ensure that log statements do not use
+// errors in templated log statements. Authors should use logrus.WithError().
+package logruswitherror
+
+import (
+	"errors"
+	"go/ast"
+	"go/types"
+
+	"golang.org/x/tools/go/analysis"
+	"golang.org/x/tools/go/analysis/passes/inspect"
+	"golang.org/x/tools/go/ast/inspector"
+)
+
+// Doc explaining the tool.
+const Doc = "This analyzer requires that log statements do not use errors in templated log statements."
+
+const errImproperUsage = "use log.WithError rather than templated log statements with errors"
+
+// Map of logrus templated log functions.
+var logFns = map[string]interface{}{
+	"Debugf":   nil,
+	"Infof":    nil,
+	"Printf":   nil,
+	"Warnf":    nil,
+	"Warningf": nil,
+	"Errorf":   nil,
+	"Fatalf":   nil,
+	"Panicf":   nil,
+}
+
+// Analyzer runs static analysis.
+var Analyzer = &analysis.Analyzer{
+	Name:     "logruswitherror",
+	Doc:      Doc,
+	Requires: []*analysis.Analyzer{inspect.Analyzer},
+	Run:      run,
+}
+
+func run(pass *analysis.Pass) (interface{}, error) {
+	inspect, ok := pass.ResultOf[inspect.Analyzer].(*inspector.Inspector)
+	if !ok {
+		return nil, errors.New("analyzer is not type *inspector.Inspector")
+	}
+
+	nodeFilter := []ast.Node{
+		(*ast.CallExpr)(nil),
+	}
+
+	inspect.Preorder(nodeFilter, func(node ast.Node) {
+		switch stmt := node.(type) {
+		case *ast.CallExpr:
+			fse, ok := stmt.Fun.(*ast.SelectorExpr)
+			if !ok {
+				return
+			}
+
+			// Only complain on log functions.
+			if x, ok := fse.X.(*ast.Ident); !ok || x.Name != "log" {
+				return
+			}
+
+			// Lookup function name
+			fnName := fse.Sel.Name
+
+			// If function matches any of the logrus functions, check if it uses errors.
+			if _, ok := logFns[fnName]; !ok {
+				return
+			}
+
+			for _, arg := range stmt.Args {
+				switch a := arg.(type) {
+				case *ast.Ident:
+					// Check if the error is a variable.
+					if a.Obj == nil {
+						return
+					}
+
+					var typ types.Type
+
+					switch f := a.Obj.Decl.(type) {
+					case *ast.AssignStmt:
+						name := a.Name
+						for _, lhs := range f.Lhs {
+							if l, ok := lhs.(*ast.Ident); ok && l.Name == name {
+								typ = pass.TypesInfo.TypeOf(l)
+								break
+							}
+						}
+					case *ast.Field:
+						typ = pass.TypesInfo.TypeOf(f.Type)
+					}
+
+					if typ != nil && typ.String() == "error" {
+						pass.Reportf(a.Pos(), errImproperUsage)
+					}
+				}
+			}
+		}
+	})
+
+	return nil, nil
+}

tools/analyzers/logruswitherror/analyzer_test.go

@@ -0,0 +1,20 @@
+package logruswitherror
+
+import (
+	"testing"
+
+	"github.com/prysmaticlabs/prysm/build/bazel"
+	"golang.org/x/tools/go/analysis/analysistest"
+)
+
+func init() {
+	if bazel.BuiltWithBazel() {
+		bazel.SetGoEnv()
+	}
+}
+
+func TestAnalyzer(t *testing.T) {
+	testdata := bazel.TestDataPath(t)
+	analysistest.TestData = func() string { return testdata }
+	analysistest.Run(t, testdata, Analyzer, "a")
+}

tools/analyzers/logruswitherror/testdata/src/a/a.go

@@ -0,0 +1,76 @@
+package testdata
+
+import (
+	"errors"
+	"fmt"
+)
+
+var log = &logger{}
+
+func LogThis(err error) {
+	// Most common use cases with all types of formatted log methods.
+	log.Debugf("Something really bad happened: %v", err)   // want "use log.WithError rather than templated log statements with errors"
+	log.Infof("Something really bad happened: %v", err)    // want "use log.WithError rather than templated log statements with errors"
+	log.Printf("Something really bad happened: %v", err)   // want "use log.WithError rather than templated log statements with errors"
+	log.Warnf("Something really bad happened: %v", err)    // want "use log.WithError rather than templated log statements with errors"
+	log.Warningf("Something really bad happened: %v", err) // want "use log.WithError rather than templated log statements with errors"
+	log.Errorf("Something really bad happened: %v", err)   // want "use log.WithError rather than templated log statements with errors"
+	log.Fatalf("Something really bad happened: %v", err)   // want "use log.WithError rather than templated log statements with errors"
+	log.Panicf("Something really bad happened: %v", err)   // want "use log.WithError rather than templated log statements with errors"
+
+	// Other common use cases.
+	log.Panicf("Something really bad happened %d times: %v", 12, err) // want "use log.WithError rather than templated log statements with errors"
+
+	if _, err := do(); err != nil {
+		log.Errorf("Something really bad happened: %v", err) // want "use log.WithError rather than templated log statements with errors"
+	}
+
+	if ok, err := false, do2(); !ok || err != nil {
+		log.Errorf("Something really bad happened: %v", err) // want "use log.WithError rather than templated log statements with errors"
+	}
+
+	log.WithError(err).Error("Something bad happened, but this log statement is OK :)")
+
+	_ = fmt.Errorf("this is ok: %v", err)
+}
+
+func do() (bool, error) {
+	return false, errors.New("bad")
+}
+
+func do2() error {
+	return errors.New("bad2")
+}
+
+type logger struct{}
+
+func (*logger) Debugf(format string, args ...interface{}) {
+}
+
+func (*logger) Infof(format string, args ...interface{}) {
+}
+
+func (*logger) Printf(format string, args ...interface{}) {
+}
+
+func (*logger) Warnf(format string, args ...interface{}) {
+}
+
+func (*logger) Warningf(format string, args ...interface{}) {
+}
+
+func (*logger) Errorf(format string, args ...interface{}) {
+}
+
+func (*logger) Error(msg string) {
+}
+
+func (*logger) Fatalf(format string, args ...interface{}) {
+}
+
+func (*logger) Panicf(format string, args ...interface{}) {
+}
+
+func (l *logger) WithError(err error) *logger {
+	return l
+}