🐛 Fix: Prevent nil errors in log.Error to ensure proper logging and add sanity check and add custom linter to avoid this scenario in the future

Makefile

@@ -95,9 +95,18 @@ 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
+LINTER_DIR := ./hack/ci/custom-linters/cmd
+custom-linter-build: # HELP Build custom linter
+	cd $(LINTER_DIR) && go build -tags '$(GO_BUILD_TAGS)' -o $(ROOT_DIR)/bin/custom-linter
+
+.PHONY: lint-custom #HELP Call custom linter for the project
+lint-custom: custom-linter-build
+	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

catalogd/cmd/catalogd/main.go

@@ -18,6 +18,7 @@ package main
 
 import (
 	"crypto/tls"
+	"errors"
 	"flag"
 	"fmt"
 	"log"
@@ -145,12 +146,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"),
+			"message", "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"),
+			"message", "metrics-bind-address requires tls-cert and tls-key flags to be set",
+			"metricsAddr", metricsAddr, "certFile", certFile, "keyFile", keyFile)
 		os.Exit(1)
 	}
 

cmd/operator-controller/main.go

@@ -19,6 +19,7 @@ package main
 import (
 	"context"
 	"crypto/tls"
+	"errors"
 	"flag"
 	"fmt"
 	"net/http"
@@ -132,12 +133,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"),
+			"message", "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"),
+			"message", "metrics-bind-address requires tls-cert and tls-key flags to be set",
+			"metricsAddr", metricsAddr, "certFile", certFile, "keyFile", keyFile)
 		os.Exit(1)
 	}
 

hack/ci/custom-linters/analyzers/setuplognilerrorcheck.go

@@ -0,0 +1,88 @@
+package analyzers
+
+import (
+	"bytes"
+	"fmt"
+	"go/ast"
+	"go/format"
+	"go/token"
+	"go/types"
+
+	"golang.org/x/tools/go/analysis"
+)
+
+var SetupLogNilErrorCheck = &analysis.Analyzer{
+	Name: "setuplognilerrorcheck",
+	Doc:  "Detects improper usage of logger.Error() calls, ensuring the first argument is a non-nil error.",
+	Run:  runSetupLogNilErrorCheck,
+}
+
+func runSetupLogNilErrorCheck(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
+			}
+
+			// Check if the first argument of the error log is nil
+			firstArg, ok := callExpr.Args[0].(*ast.Ident)
+			if !ok || firstArg.Name != "nil" {
+				return true
+			}
+
+			// Extract error message for the suggestion
+			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
+				}
+			}
+
+			// Get the actual source code line where the issue occurs
+			var srcBuffer bytes.Buffer
+			if err := format.Node(&srcBuffer, pass.Fset, callExpr); err == nil {
+				sourceLine := srcBuffer.String()
+				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"+
+						fmt.Sprintf("   %s\n\n", sourceLine)+
+						"\U0001F4A1 **How to solve? Return the error, i.e.:**\n"+
+						fmt.Sprintf("   logger.Error(%s, %s, \"key\", value)\n\n", suggestedError, suggestedMessage))
+			}
+
+			return true
+		})
+	}
+	return nil, nil
+}

hack/ci/custom-linters/cmd/main.go

@@ -0,0 +1,16 @@
+package main
+
+import (
+	"github.com/operator-framework/operator-controller/hack/ci/custom-linters/analyzers"
+	"golang.org/x/tools/go/analysis"
+	"golang.org/x/tools/go/analysis/unitchecker"
+)
+
+// Define the custom Linters implemented in the project
+var customLinters = []*analysis.Analyzer{
+	analyzers.SetupLogNilErrorCheck,
+}
+
+func main() {
+	unitchecker.Main(customLinters...)
+}

hack/ci/custom-linters/go.mod

@@ -0,0 +1,5 @@
+module github.com/operator-framework/operator-controller/hack/ci/custom-linters
+
+go 1.23.4
+
+require golang.org/x/tools v0.29.0

hack/ci/custom-linters/go.sum

@@ -0,0 +1,8 @@
+github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
+github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
+golang.org/x/mod v0.22.0 h1:D4nJWe9zXqHOmWqj4VMOJhvzj7bEZg4wEYa759z1pH4=
+golang.org/x/mod v0.22.0/go.mod h1:6SkKJ3Xj0I0BrPOZoBy3bdMptDDU9oJrpohJ3eWZ1fY=
+golang.org/x/sync v0.10.0 h1:3NQrjDixjgGwUOCaF8w2+VYHv0Ve/vGYSbdkTa98gmQ=
+golang.org/x/sync v0.10.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk=
+golang.org/x/tools v0.29.0 h1:Xx0h3TtM9rzQpQuR4dKLrdglAmCEN5Oi+P74JdhdzXE=
+golang.org/x/tools v0.29.0/go.mod h1:KMQVMRsVxU6nHCFXrBPhDB8XncLNLM0lIy/F14RP588=

internal/contentmanager/source/internal/eventhandler.go

@@ -38,6 +38,7 @@ limitations under the License.
 
 import (
 	"context"
+	"errors"
 	"fmt"
 
 	cgocache "k8s.io/client-go/tools/cache"
@@ -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
 	}
 
@@ -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
@@ -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
 		}
@@ -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
 	}