Add debug logging levels

cmd/main.go

@@ -33,6 +33,7 @@ import (
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
 
 	appstacksv1 "github.com/application-stacks/runtime-component-operator/api/v1"
+	"github.com/application-stacks/runtime-component-operator/common"
 	"github.com/application-stacks/runtime-component-operator/internal/controller"
 	"github.com/application-stacks/runtime-component-operator/utils"
 	certmanagerv1 "github.com/cert-manager/cert-manager/pkg/apis/certmanager/v1"
@@ -78,7 +79,14 @@ func main() {
 			"Enabling this will ensure there is only one active controller manager.")
 	flag.Parse()
 
-	ctrl.SetLogger(zap.New(zap.UseDevMode(true)))
+	utils.CreateConfigMap(controller.OperatorName)
+
+	opts := zap.Options{
+		Level:           common.LevelFunc,
+		StacktraceLevel: common.StackLevelFunc,
+		Development:     true,
+	}
+	ctrl.SetLogger(zap.New(zap.UseFlagOptions(&opts)))
 
 	// see https://github.com/operator-framework/operator-sdk/issues/1813
 	leaseDuration := 30 * time.Second
@@ -133,8 +141,6 @@ func main() {
 	}
 	// +kubebuilder:scaffold:builder
 
-	utils.CreateConfigMap(controller.OperatorName)
-
 	if err := mgr.AddHealthzCheck("healthz", healthz.Ping); err != nil {
 		setupLog.Error(err, "unable to set up health check")
 		os.Exit(1)

common/config.go

@@ -1,6 +1,8 @@
 package common
 
 import (
+	uberzap "go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	corev1 "k8s.io/api/core/v1"
 )
 
@@ -17,11 +19,52 @@ const (
 
 	// OpConfigCMCADuration default duration for cert-manager issued service certificate
 	OpConfigCMCertDuration = "certManagerCertDuration"
+
+	// OpConfigLogLevel the level of logs to be written
+	OpConfigLogLevel = "operatorLogLevel"
+
+	// The allowed values for OpConfigLogLevel
+	logLevelWarning  = "warning"
+	logLevelInfo     = "info"
+	logLevelDebug    = "fine"
+	logLevelDebug2   = "finer"
+	logLevelDebugMax = "finest"
+
+	// Constants to use when fetching a debug level logger
+	LogLevelDebug  = 1
+	LogLevelDebug2 = 2
+
+	// zap logging level constants
+	zLevelWarn   zapcore.Level = 1
+	zLevelInfo   zapcore.Level = 0
+	zLevelDebug  zapcore.Level = -1
+	zLevelDebug2 zapcore.Level = -2
+	// zapcore.Level is defined as int8, so this logs everything
+	zLevelDebugMax zapcore.Level = -127
 )
 
 // Config stores operator configuration
 var Config = OpConfig{}
 
+var LevelFunc = uberzap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
+	return lvl >= Config.GetZapLogLevel()
+})
+
+var StackLevelFunc = uberzap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
+	configuredLevel := Config.GetZapLogLevel()
+	if configuredLevel > zapcore.DebugLevel {
+		// No stack traces unless fine/finer/finest has been requested
+		// Zap's debug is mapped to fine
+		return false
+	}
+	// Stack traces for error or worse (fatal/panic)
+	if lvl >= zapcore.ErrorLevel {
+		return true
+	}
+	// Logging is set to fine/finer/finest but msg is info or less. No stack trace
+	return false
+})
+
 // LoadFromConfigMap creates a config out of kubernetes config map
 func (oc OpConfig) LoadFromConfigMap(cm *corev1.ConfigMap) {
 	for k, v := range DefaultOpConfig() {
@@ -33,11 +76,37 @@ func (oc OpConfig) LoadFromConfigMap(cm *corev1.ConfigMap) {
 	}
 }
 
+// Returns the zap log level corresponding to the value of the
+// 'logLevel' key in the config map. Returns 'info' if they key
+// is missing or contains an invalid value.
+func (oc OpConfig) GetZapLogLevel() zapcore.Level {
+	level, ok := oc[OpConfigLogLevel]
+	if !ok {
+		return zLevelInfo
+	}
+	switch level {
+	case logLevelWarning:
+		return zLevelWarn
+	case logLevelInfo:
+		return zLevelInfo
+	case logLevelDebug:
+		return zLevelDebug
+	case logLevelDebug2:
+		return zLevelDebug2
+	case logLevelDebugMax:
+		return zLevelDebugMax
+	default:
+		// config value is invalid.
+		return zLevelInfo
+	}
+}
+
 // DefaultOpConfig returns default configuration
 func DefaultOpConfig() OpConfig {
 	cfg := OpConfig{}
 	cfg[OpConfigDefaultHostname] = ""
 	cfg[OpConfigCMCADuration] = "8766h"
 	cfg[OpConfigCMCertDuration] = "2160h"
+	cfg[OpConfigLogLevel] = logLevelInfo
 	return cfg
 }

utils/reconciler.go

@@ -106,6 +106,7 @@ func (r *ReconcilerBase) SetDiscoveryClient(discovery discovery.DiscoveryInterfa
 }
 
 var log = logf.Log.WithName("utils")
+var logD1 = log.V(common.LogLevelDebug)
 
 // CreateOrUpdate ...
 func (r *ReconcilerBase) CreateOrUpdate(obj client.Object, owner metav1.Object, reconcile func() error) error {
@@ -122,7 +123,7 @@ func (r *ReconcilerBase) CreateOrUpdate(obj client.Object, owner metav1.Object,
 	var gvk schema.GroupVersionKind
 	gvk, err = apiutil.GVKForObject(obj, r.scheme)
 	if err == nil {
-		log.Info("Reconciled", "Kind", gvk.Kind, "Namespace", obj.GetNamespace(), "Name", obj.GetName(), "Status", result)
+		logD1.Info("Reconciled", "Kind", gvk.Kind, "Namespace", obj.GetNamespace(), "Name", obj.GetName(), "Status", result)
 	}
 
 	return err

utils/utils.go

@@ -18,7 +18,6 @@ import (
 	"k8s.io/client-go/kubernetes/scheme"
 	"k8s.io/client-go/rest"
 	"k8s.io/client-go/tools/remotecommand"
-	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/client"
 	clientcfg "sigs.k8s.io/controller-runtime/pkg/client/config"
 	"sigs.k8s.io/controller-runtime/pkg/controller/controllerutil"
@@ -1729,12 +1728,12 @@ func addSecretResourceVersionAsEnvVar(pts *corev1.PodTemplateSpec, object metav1
 // This should only be called once from main.go on operator start
 // It checks for the presence of the operators config map and
 // creates it if it doesn't exist
+// As we load logging config from the config map, we can't use log messages as the logger won't be setup yet.
 func CreateConfigMap(mapName string) {
-	utilsLog := ctrl.Log.WithName("utils-setup")
-	// This function is called from main, so the normal client isn't setup properly
+	// The config map may not be in a watched namespace, in which case the normal client won't read it.
 	client, clerr := client.New(clientcfg.GetConfigOrDie(), client.Options{})
 	if clerr != nil {
-		utilsLog.Error(clerr, "Couldn't create a client for config map creation")
+		fmt.Fprintf(os.Stderr, "Couldn't create a client for config map creation: %s\n", clerr)
 		return
 	}
 
@@ -1743,7 +1742,7 @@ func CreateConfigMap(mapName string) {
 		// This could happen if the operator is running locally, i.e. outside the cluster
 		watchNamespaces, err := GetWatchNamespaces()
 		if err != nil {
-			utilsLog.Error(err, "Error getting watch namespace")
+			fmt.Fprintf(os.Stderr, "Error getting watch namespace: %s\n", err)
 			return
 		}
 		// If the operator is running locally, use the first namespace in the `watchNamespaces`
@@ -1752,12 +1751,12 @@ func CreateConfigMap(mapName string) {
 	configMap := &corev1.ConfigMap{}
 	err := client.Get(context.TODO(), types.NamespacedName{Name: mapName, Namespace: operatorNs}, configMap)
 	if err != nil && apierrors.IsNotFound(err) {
-		utilsLog.Error(err, "The operator config map was not found. Attempting to create it")
+		fmt.Fprintf(os.Stderr, "The operator config map was not found. Attempting to create it: %s\n", err)
 	} else if err != nil {
-		utilsLog.Error(err, "Couldn't retrieve operator config map")
+		fmt.Fprintf(os.Stderr, "Couldn't retrieve operator config map: %s\n", err)
 		return
 	} else {
-		utilsLog.Info("Existing operator config map was found")
+		fmt.Fprintf(os.Stderr, "Existing operator config map was found\n")
 		return
 	}
 
@@ -1775,9 +1774,9 @@ func CreateConfigMap(mapName string) {
 		return nil
 	})
 	if cerr != nil {
-		utilsLog.Error(cerr, "Couldn't create config map in namespace "+operatorNs)
+		fmt.Fprintf(os.Stderr, "Couldn't create config map in namespace %s: %s\n", operatorNs, err)
 	} else {
-		utilsLog.Info("Operator Config map created in namespace " + operatorNs)
+		fmt.Fprintf(os.Stderr, "Operator Config map created in namespace %s\n", operatorNs)
 	}
 }