Skip to content

Commit

Permalink
Add custom Linter to not allow improper usage of logger.Error(nil, ..…
Browse files Browse the repository at this point in the history
….) calls and fix found linter issues. (#1599)

Fix: Prevent nil errors in setupLog.Error to ensure proper logging

Closes; #1566
Closes: #1556

Furthermore, it solves a similar scenario in the EventHandler code implementation found with the new custom linter check.
  • Loading branch information
camilamacedo86 authored Feb 11, 2025
1 parent c451127 commit 4304961
Show file tree
Hide file tree
Showing 11 changed files with 239 additions and 18 deletions.
10 changes: 9 additions & 1 deletion Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -99,9 +99,17 @@ help-extended: #HELP Display extended help.
#SECTION Development

.PHONY: lint
lint: $(GOLANGCI_LINT) #HELP Run golangci linter.
lint: lint-custom $(GOLANGCI_LINT) #HELP Run golangci linter.
$(GOLANGCI_LINT) run --build-tags $(GO_BUILD_TAGS) $(GOLANGCI_LINT_ARGS)

.PHONY: custom-linter-build
custom-linter-build: #HELP Build custom linter
go build -tags $(GO_BUILD_TAGS) -o ./bin/custom-linter ./hack/ci/custom-linters/cmd

.PHONY: lint-custom
lint-custom: custom-linter-build #HELP Call custom linter for the project
go vet -tags=$(GO_BUILD_TAGS) -vettool=./bin/custom-linter ./...

.PHONY: tidy
tidy: #HELP Update dependencies.
# Force tidy to use the version already in go.mod
Expand Down
9 changes: 7 additions & 2 deletions catalogd/cmd/catalogd/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ package main

import (
"crypto/tls"
"errors"
"flag"
"fmt"
"log"
Expand Down Expand Up @@ -149,12 +150,16 @@ func main() {
}

if (certFile != "" && keyFile == "") || (certFile == "" && keyFile != "") {
setupLog.Error(nil, "unable to configure TLS certificates: tls-cert and tls-key flags must be used together")
setupLog.Error(errors.New("missing TLS configuration"),
"tls-cert and tls-key flags must be used together",
"certFile", certFile, "keyFile", keyFile)
os.Exit(1)
}

if metricsAddr != "" && certFile == "" && keyFile == "" {
setupLog.Error(nil, "metrics-bind-address requires tls-cert and tls-key flags to be set")
setupLog.Error(errors.New("invalid metrics configuration"),
"metrics-bind-address requires tls-cert and tls-key flags to be set",
"metricsAddr", metricsAddr, "certFile", certFile, "keyFile", keyFile)
os.Exit(1)
}

Expand Down
9 changes: 7 additions & 2 deletions cmd/operator-controller/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ package main
import (
"context"
"crypto/tls"
"errors"
"flag"
"fmt"
"net/http"
Expand Down Expand Up @@ -136,12 +137,16 @@ func main() {
}

if (certFile != "" && keyFile == "") || (certFile == "" && keyFile != "") {
setupLog.Error(nil, "unable to configure TLS certificates: tls-cert and tls-key flags must be used together")
setupLog.Error(errors.New("missing TLS configuration"),
"tls-cert and tls-key flags must be used together",
"certFile", certFile, "keyFile", keyFile)
os.Exit(1)
}

if metricsAddr != "" && certFile == "" && keyFile == "" {
setupLog.Error(nil, "metrics-bind-address requires tls-cert and tls-key flags to be set")
setupLog.Error(errors.New("invalid metrics configuration"),
"metrics-bind-address requires tls-cert and tls-key flags to be set",
"metricsAddr", metricsAddr, "certFile", certFile, "keyFile", keyFile)
os.Exit(1)
}

Expand Down
3 changes: 2 additions & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ require (
github.com/stretchr/testify v1.10.0
golang.org/x/exp v0.0.0-20241009180824-f66d83c29e7c
golang.org/x/sync v0.11.0
golang.org/x/tools v0.29.0
gopkg.in/yaml.v2 v2.4.0
helm.sh/helm/v3 v3.17.0
k8s.io/api v0.32.0
Expand Down Expand Up @@ -226,13 +227,13 @@ require (
go.opentelemetry.io/otel/trace v1.33.0 // indirect
go.opentelemetry.io/proto/otlp v1.3.1 // indirect
golang.org/x/crypto v0.32.0 // indirect
golang.org/x/mod v0.22.0 // indirect
golang.org/x/net v0.34.0 // indirect
golang.org/x/oauth2 v0.25.0 // indirect
golang.org/x/sys v0.29.0 // indirect
golang.org/x/term v0.28.0 // indirect
golang.org/x/text v0.21.0 // indirect
golang.org/x/time v0.7.0 // indirect
golang.org/x/tools v0.29.0 // indirect
gomodules.xyz/jsonpatch/v2 v2.4.0 // indirect
google.golang.org/genproto v0.0.0-20240903143218-8af14fe29dc1 // indirect
google.golang.org/genproto/googleapis/api v0.0.0-20240903143218-8af14fe29dc1 // indirect
Expand Down
12 changes: 12 additions & 0 deletions hack/ci/custom-linters/analyzers/analyzers_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
package analyzers

import (
"testing"

"golang.org/x/tools/go/analysis/analysistest"
)

func TestSetupLogErrorCheck(t *testing.T) {
testdata := analysistest.TestData()
analysistest.Run(t, testdata, SetupLogErrorCheck)
}
119 changes: 119 additions & 0 deletions hack/ci/custom-linters/analyzers/setuplognilerrorcheck.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,119 @@
package analyzers

import (
"bytes"
"go/ast"
"go/format"
"go/token"
"go/types"

"golang.org/x/tools/go/analysis"
)

var SetupLogErrorCheck = &analysis.Analyzer{
Name: "setuplogerrorcheck",
Doc: "Detects improper usage of logger.Error() calls, ensuring the first argument is a non-nil error.",
Run: runSetupLogErrorCheck,
}

func runSetupLogErrorCheck(pass *analysis.Pass) (interface{}, error) {
for _, f := range pass.Files {
ast.Inspect(f, func(n ast.Node) bool {
callExpr, ok := n.(*ast.CallExpr)
if !ok {
return true
}

// Ensure function being called is logger.Error
selectorExpr, ok := callExpr.Fun.(*ast.SelectorExpr)
if !ok || selectorExpr.Sel.Name != "Error" {
return true
}

// Ensure receiver (logger) is identified
ident, ok := selectorExpr.X.(*ast.Ident)
if !ok {
return true
}

// Verify if the receiver is logr.Logger
obj := pass.TypesInfo.ObjectOf(ident)
if obj == nil {
return true
}

named, ok := obj.Type().(*types.Named)
if !ok || named.Obj().Pkg() == nil || named.Obj().Pkg().Path() != "github.com/go-logr/logr" || named.Obj().Name() != "Logger" {
return true
}

if len(callExpr.Args) == 0 {
return true
}

// Get the actual source code line where the issue occurs
var srcBuffer bytes.Buffer
if err := format.Node(&srcBuffer, pass.Fset, callExpr); err != nil {
return true
}
sourceLine := srcBuffer.String()

// Check if the first argument of the error log is nil
firstArg, ok := callExpr.Args[0].(*ast.Ident)
if ok && firstArg.Name == "nil" {
suggestedError := "errors.New(\"kind error (i.e. configuration error)\")"
suggestedMessage := "\"error message describing the failed operation\""

if len(callExpr.Args) > 1 {
if msgArg, ok := callExpr.Args[1].(*ast.BasicLit); ok && msgArg.Kind == token.STRING {
suggestedMessage = msgArg.Value
}
}

pass.Reportf(callExpr.Pos(),
"Incorrect usage of 'logger.Error(nil, ...)'. The first argument must be a non-nil 'error'. "+
"Passing 'nil' results in silent failures, making debugging harder.\n\n"+
"\U0001F41B **What is wrong?**\n %s\n\n"+
"\U0001F4A1 **How to solve? Return the error, i.e.:**\n logger.Error(%s, %s, \"key\", value)\n\n",
sourceLine, suggestedError, suggestedMessage)
return true
}

// Ensure at least two arguments exist (error + message)
if len(callExpr.Args) < 2 {
pass.Reportf(callExpr.Pos(),
"Incorrect usage of 'logger.Error(error, ...)'. Expected at least an error and a message string.\n\n"+
"\U0001F41B **What is wrong?**\n %s\n\n"+
"\U0001F4A1 **How to solve?**\n Provide a message, e.g. logger.Error(err, \"descriptive message\")\n\n",
sourceLine)
return true
}

// Ensure key-value pairs (if any) are valid
if (len(callExpr.Args)-2)%2 != 0 {
pass.Reportf(callExpr.Pos(),
"Incorrect usage of 'logger.Error(error, \"msg\", ...)'. Key-value pairs must be provided after the message, but an odd number of arguments was found.\n\n"+
"\U0001F41B **What is wrong?**\n %s\n\n"+
"\U0001F4A1 **How to solve?**\n Ensure all key-value pairs are complete, e.g. logger.Error(err, \"msg\", \"key\", value, \"key2\", value2)\n\n",
sourceLine)
return true
}

for i := 2; i < len(callExpr.Args); i += 2 {
keyArg := callExpr.Args[i]
keyType := pass.TypesInfo.TypeOf(keyArg)
if keyType == nil || keyType.String() != "string" {
pass.Reportf(callExpr.Pos(),
"Incorrect usage of 'logger.Error(error, \"msg\", key, value)'. Keys in key-value pairs must be strings, but got: %s.\n\n"+
"\U0001F41B **What is wrong?**\n %s\n\n"+
"\U0001F4A1 **How to solve?**\n Ensure keys are strings, e.g. logger.Error(err, \"msg\", \"key\", value)\n\n",
keyType, sourceLine)
return true
}
}

return true
})
}
return nil, nil
}
5 changes: 5 additions & 0 deletions hack/ci/custom-linters/analyzers/testdata/go.mod
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
module testdata

go 1.23.4

require github.com/go-logr/logr v1.4.2
2 changes: 2 additions & 0 deletions hack/ci/custom-linters/analyzers/testdata/go.sum
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
github.com/go-logr/logr v1.4.2 h1:6pFjapn8bFcIbiKo3XT4j/BhANplGihG6tvd+8rYgrY=
github.com/go-logr/logr v1.4.2/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY=
26 changes: 26 additions & 0 deletions hack/ci/custom-linters/analyzers/testdata/main.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
package main

import (
"github.com/go-logr/logr"
)

func testLogger() {
var logger logr.Logger
var err error
var value int

// Case 1: Nil error - Ensures the first argument cannot be nil.
logger.Error(nil, "message") // want ".*results in silent failures, making debugging harder.*"

// Case 2: Odd number of key-value arguments - Ensures key-value pairs are complete.
logger.Error(err, "message", "key1") // want ".*Key-value pairs must be provided after the message, but an odd number of arguments was found.*"

// Case 3: Key in key-value pair is not a string - Ensures keys in key-value pairs are strings.
logger.Error(err, "message", 123, value) // want ".*Ensure keys are strings.*"

// Case 4: Values are passed without corresponding keys - Ensures key-value arguments are structured properly.
logger.Error(err, "message", value, "key2", value) // want ".*Key-value pairs must be provided after the message, but an odd number of arguments was found.*"

// Case 5: Correct Usage - Should not trigger any warnings.
logger.Error(err, "message", "key1", value, "key2", "value")
}
17 changes: 17 additions & 0 deletions hack/ci/custom-linters/cmd/main.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
package main

import (
"golang.org/x/tools/go/analysis"
"golang.org/x/tools/go/analysis/unitchecker"

"github.com/operator-framework/operator-controller/hack/ci/custom-linters/analyzers"
)

// Define the custom Linters implemented in the project
var customLinters = []*analysis.Analyzer{
analyzers.SetupLogErrorCheck,
}

func main() {
unitchecker.Main(customLinters...)
}
45 changes: 33 additions & 12 deletions internal/contentmanager/source/internal/eventhandler.go
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@ limitations under the License.

import (
"context"
"errors"
"fmt"

cgocache "k8s.io/client-go/tools/cache"
Expand Down Expand Up @@ -94,8 +95,11 @@ func (e *EventHandler[object, request]) OnAdd(obj interface{}) {
if o, ok := obj.(object); ok {
c.Object = o
} else {
log.Error(nil, "OnAdd missing Object",
"object", obj, "type", fmt.Sprintf("%T", obj))
log.Error(errors.New("failed to cast object"),
"OnAdd missing Object",
"expected_type", fmt.Sprintf("%T", c.Object),
"received_type", fmt.Sprintf("%T", obj),
"object", obj)
return
}

Expand All @@ -118,20 +122,27 @@ func (e *EventHandler[object, request]) OnUpdate(oldObj, newObj interface{}) {
if o, ok := oldObj.(object); ok {
u.ObjectOld = o
} else {
log.Error(nil, "OnUpdate missing ObjectOld",
"object", oldObj, "type", fmt.Sprintf("%T", oldObj))
log.Error(errors.New("failed to cast old object"),
"OnUpdate missing ObjectOld",
"object", oldObj,
"expected_type", fmt.Sprintf("%T", u.ObjectOld),
"received_type", fmt.Sprintf("%T", oldObj))
return
}

// Pull Object out of the object
if o, ok := newObj.(object); ok {
u.ObjectNew = o
} else {
log.Error(nil, "OnUpdate missing ObjectNew",
"object", newObj, "type", fmt.Sprintf("%T", newObj))
log.Error(errors.New("failed to cast new object"),
"OnUpdate missing ObjectNew",
"object", newObj,
"expected_type", fmt.Sprintf("%T", u.ObjectNew),
"received_type", fmt.Sprintf("%T", newObj))
return
}

// Run predicates before proceeding
for _, p := range e.predicates {
if !p.Update(u) {
return
Expand All @@ -148,18 +159,25 @@ func (e *EventHandler[object, request]) OnUpdate(oldObj, newObj interface{}) {
func (e *EventHandler[object, request]) OnDelete(obj interface{}) {
d := event.TypedDeleteEvent[object]{}

// Handle tombstone events (cache.DeletedFinalStateUnknown)
if obj == nil {
log.Error(errors.New("received nil object"),
"OnDelete received a nil object, ignoring event")
return
}

// Deal with tombstone events by pulling the object out. Tombstone events wrap the object in a
// DeleteFinalStateUnknown struct, so the object needs to be pulled out.
// Copied from sample-controller
// This should never happen if we aren't missing events, which we have concluded that we are not
// and made decisions off of this belief. Maybe this shouldn't be here?
var ok bool
if _, ok = obj.(client.Object); !ok {
if _, ok := obj.(client.Object); !ok {
// If the object doesn't have Metadata, assume it is a tombstone object of type DeletedFinalStateUnknown
tombstone, ok := obj.(cgocache.DeletedFinalStateUnknown)
if !ok {
log.Error(nil, "Error decoding objects. Expected cache.DeletedFinalStateUnknown",
"type", fmt.Sprintf("%T", obj),
log.Error(errors.New("unexpected object type"),
"Error decoding objects, expected cache.DeletedFinalStateUnknown",
"received_type", fmt.Sprintf("%T", obj),
"object", obj)
return
}
Expand All @@ -175,8 +193,11 @@ func (e *EventHandler[object, request]) OnDelete(obj interface{}) {
if o, ok := obj.(object); ok {
d.Object = o
} else {
log.Error(nil, "OnDelete missing Object",
"object", obj, "type", fmt.Sprintf("%T", obj))
log.Error(errors.New("failed to cast object"),
"OnDelete missing Object",
"expected_type", fmt.Sprintf("%T", d.Object),
"received_type", fmt.Sprintf("%T", obj),
"object", obj)
return
}

Expand Down

0 comments on commit 4304961

Please sign in to comment.