Upgrade controller logging

v2/cmd/controller/app/flags.go

@@ -8,10 +8,6 @@ package app
 import (
 	"flag"
 	"fmt"
-
-	"k8s.io/klog/v2"
-
-	"github.com/Azure/azure-service-operator/v2/internal/version"
 )
 
 type Flags struct {
@@ -40,45 +36,21 @@ func (f Flags) String() string {
 		f.CRDPatterns)
 }
 
-func ParseFlags(args []string) (Flags, error) {
-	exeName := args[0] + " " + version.BuildVersion
-	flagSet := flag.NewFlagSet(exeName, flag.ExitOnError)
-	klog.InitFlags(flagSet)
-
-	var metricsAddr string
-	var profilingMetrics bool
-	var secureMetrics bool
-	var healthAddr string
-	var webhookPort int
-	var webhookCertDir string
-	var enableLeaderElection bool
-	var crdManagementMode string
-	var crdPatterns string
+func InitFlags(flagSet *flag.FlagSet) *Flags {
+	result := &Flags{}
 
 	// default here for 'MetricsAddr' is set to "0", which sets metrics to be disabled if 'metrics-addr' flag is omitted.
-	flagSet.StringVar(&metricsAddr, "metrics-addr", "0", "The address the metric endpoint binds to.")
-	flagSet.BoolVar(&secureMetrics, "secure-metrics", true, "Enable secure metrics. This secures the pprof and metrics endpoints via Kubernetes RBAC and HTTPS")
-	flagSet.BoolVar(&profilingMetrics, "profiling-metrics", false, "Enable pprof metrics, only enabled in conjunction with secure-metrics. This will enable serving pprof metrics endpoints")
-
-	flagSet.StringVar(&healthAddr, "health-addr", "", "The address the healthz endpoint binds to.")
-	flagSet.IntVar(&webhookPort, "webhook-port", 9443, "The port the webhook endpoint binds to.")
-	flagSet.StringVar(&webhookCertDir, "webhook-cert-dir", "", "The directory the webhook server's certs are stored.")
-	flagSet.BoolVar(&enableLeaderElection, "enable-leader-election", false,
-		"Enable leader election for controllers manager. Enabling this will ensure there is only one active controllers manager.")
-	flagSet.StringVar(&crdManagementMode, "crd-management", "auto",
+	flagSet.StringVar(&result.MetricsAddr, "metrics-addr", "0", "The address the metric endpoint binds to.")
+	flagSet.BoolVar(&result.SecureMetrics, "secure-metrics", true, "Enable secure metrics. This secures the pprof and metrics endpoints via Kubernetes RBAC and HTTPS")
+	flagSet.BoolVar(&result.ProfilingMetrics, "profiling-metrics", false, "Enable pprof metrics, only enabled in conjunction with secure-metrics. This will enable serving pprof metrics endpoints")
+	flagSet.StringVar(&result.HealthAddr, "health-addr", "", "The address the healthz endpoint binds to.")
+	flagSet.IntVar(&result.WebhookPort, "webhook-port", 9443, "The port the webhook endpoint binds to.")
+	flagSet.StringVar(&result.WebhookCertDir, "webhook-cert-dir", "", "The directory the webhook server's certs are stored.")
+	flagSet.BoolVar(&result.EnableLeaderElection, "enable-leader-election", false, "Enable leader election for controllers manager. Enabling this will ensure there is only one active controllers manager.")
+
+	flagSet.StringVar(&result.CRDManagementMode, "crd-management", "auto",
 		"Instructs the operator on how it should manage the Custom Resource Definitions. One of 'auto', 'none'")
-	flagSet.StringVar(&crdPatterns, "crd-pattern", "", "Install these CRDs. CRDs already in the cluster will also always be upgraded.")
-
-	flagSet.Parse(args[1:]) //nolint:errcheck
+	flagSet.StringVar(&result.CRDPatterns, "crd-pattern", "", "Install these CRDs. CRDs already in the cluster will also always be upgraded.")
 
-	return Flags{
-		MetricsAddr:          metricsAddr,
-		SecureMetrics:        secureMetrics,
-		HealthAddr:           healthAddr,
-		WebhookPort:          webhookPort,
-		WebhookCertDir:       webhookCertDir,
-		EnableLeaderElection: enableLeaderElection,
-		CRDManagementMode:    crdManagementMode,
-		CRDPatterns:          crdPatterns,
-	}, nil
+	return result
 }

v2/cmd/controller/app/setup.go

@@ -52,7 +52,7 @@ import (
 	"github.com/Azure/azure-service-operator/v2/pkg/genruntime/conditions"
 )
 
-func SetupControllerManager(ctx context.Context, setupLog logr.Logger, flgs Flags) manager.Manager {
+func SetupControllerManager(ctx context.Context, setupLog logr.Logger, flgs *Flags) manager.Manager {
 	scheme := controllers.CreateScheme()
 	_ = apiextensions.AddToScheme(scheme) // Used for managing CRDs
 
@@ -211,7 +211,7 @@ func SetupControllerManager(ctx context.Context, setupLog logr.Logger, flgs Flag
 	return mgr
 }
 
-func getMetricsOpts(flags Flags) server.Options {
+func getMetricsOpts(flags *Flags) server.Options {
 	var metricsOptions server.Options
 
 	if flags.SecureMetrics {

v2/cmd/controller/logging/logging.go

@@ -0,0 +1,101 @@
+/*
+Copyright (c) Microsoft Corporation.
+Licensed under the MIT license.
+*/
+
+package logging
+
+import (
+	"flag"
+
+	"github.com/go-logr/logr"
+	"github.com/go-logr/zapr"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"k8s.io/klog/v2/textlogger"
+
+	"github.com/Azure/azure-service-operator/v2/internal/logging"
+)
+
+type Config struct {
+	// verbosity indicates the level of logging.
+	// Higher values indicate more logging.
+	verbosity int
+
+	// useJSON indicates whether we should output logs in JSON format.
+	// Default is no
+	useJSON bool
+}
+
+// Create returns a new logger, ready for use.
+// This can be called multiple times if required.
+func Create(cfg *Config) logr.Logger {
+	if cfg != nil && cfg.useJSON {
+		log, err := createJSONLogger(cfg)
+		if err != nil {
+			log = createTextLogger(cfg)
+			log.Error(err, "failed to create JSON logger, falling back to text")
+		}
+
+		return log
+	}
+
+	return createTextLogger(cfg)
+}
+
+func createTextLogger(cfg *Config) logr.Logger {
+	opts := []textlogger.ConfigOption{}
+	if cfg != nil {
+		opts = append(opts, textlogger.Verbosity(cfg.verbosity))
+	}
+
+	c := textlogger.NewConfig(opts...)
+	return textlogger.NewLogger(c)
+}
+
+func createJSONLogger(cfg *Config) (logr.Logger, error) {
+	level := zap.InfoLevel
+	if cfg != nil {
+		switch cfg.verbosity {
+		case 0:
+			level = zap.ErrorLevel
+		case 1:
+			level = zap.WarnLevel
+		case 2:
+			level = zap.InfoLevel
+		default: // 3 or above
+			level = zap.DebugLevel
+		}
+	}
+
+	encoder := zap.NewProductionEncoderConfig()
+	encoder.EncodeTime = zapcore.ISO8601TimeEncoder
+
+	c := zap.Config{
+		Level:            zap.NewAtomicLevelAt(level),
+		Development:      false,
+		Encoding:         "json",
+		EncoderConfig:    encoder,
+		OutputPaths:      []string{"stderr"},
+		ErrorOutputPaths: []string{"stderr"},
+	}
+
+	logger, err := c.Build()
+	if err != nil {
+		return logr.Logger{}, err
+	}
+
+	return zapr.NewLogger(logger), nil
+}
+
+// InitFlags initializes the flags for the logging package
+func InitFlags(fs *flag.FlagSet) *Config {
+	result := &Config{}
+
+	fs.IntVar(&result.verbosity, "verbose", logging.Verbose, "Enable verbose logging")
+	fs.IntVar(&result.verbosity, "v", logging.Verbose, "Enable verbose logging")
+
+	fs.BoolVar(&result.useJSON, "json-logging", false, "Enable JSON logging")
+
+	return result
+}

v2/cmd/controller/main.go

@@ -6,31 +6,45 @@ Licensed under the MIT license.
 package main
 
 import (
+	"flag"
 	"os"
 
 	_ "k8s.io/client-go/plugin/pkg/client/auth/gcp"
-	"k8s.io/klog/v2/klogr"
 	ctrl "sigs.k8s.io/controller-runtime"
 
 	"github.com/Azure/azure-service-operator/v2/cmd/controller/app"
+	"github.com/Azure/azure-service-operator/v2/cmd/controller/logging"
+	"github.com/Azure/azure-service-operator/v2/internal/version"
 )
 
 func main() {
-	setupLog := ctrl.Log.WithName("setup")
-	ctrl.SetLogger(klogr.New()) //nolint: staticcheck
+	// Set up to parse command line flags
+	exeName := os.Args[0] + " " + version.BuildVersion
+	flagSet := flag.NewFlagSet(exeName, flag.ExitOnError)
+
+	// Create a temporary logger for while we get set up
+	log := logging.Create(&logging.Config{})
+
 	ctx := ctrl.SetupSignalHandler()
 
-	flgs, err := app.ParseFlags(os.Args)
+	// Add application and logging flags
+	appFlags := app.InitFlags(flagSet)
+	logFlags := logging.InitFlags(flagSet)
+	err := flagSet.Parse(os.Args[1:])
 	if err != nil {
-		setupLog.Error(err, "failed to parse cmdline flags")
+		log.Error(err, "failed to parse cmdline flags")
 		os.Exit(1)
 	}
 
-	setupLog.Info("Launching with flags", "flags", flgs.String())
-	mgr := app.SetupControllerManager(ctx, setupLog, flgs)
-	setupLog.Info("starting manager")
+	// Replace the logger with a configured one
+	log = logging.Create(logFlags)
+	ctrl.SetLogger(log)
+	log.Info("Launching with flags", "flags", appFlags.String())
+
+	mgr := app.SetupControllerManager(ctx, log, appFlags)
+	log.Info("starting manager")
 	if err = mgr.Start(ctx); err != nil {
-		setupLog.Error(err, "failed to start manager")
+		log.Error(err, "failed to start manager")
 		os.Exit(1)
 	}
 }

v2/go.mod

@@ -27,6 +27,7 @@ require (
 	github.com/benbjohnson/clock v1.3.5
 	github.com/dnaeon/go-vcr v1.2.0
 	github.com/go-logr/logr v1.4.2
+	github.com/go-logr/zapr v1.3.0
 	github.com/go-sql-driver/mysql v1.8.1
 	github.com/google/go-cmp v0.6.0
 	github.com/google/uuid v1.6.0
@@ -40,6 +41,7 @@ require (
 	github.com/pkg/errors v0.9.1
 	github.com/prometheus/client_golang v1.20.2
 	github.com/spf13/cobra v1.8.1
+	go.uber.org/zap v1.27.0
 	golang.org/x/crypto v0.26.0
 	golang.org/x/exp v0.0.0-20240823005443-9b4947da3948
 	golang.org/x/sync v0.8.0
@@ -115,6 +117,7 @@ require (
 	go.opentelemetry.io/otel/sdk v1.29.0 // indirect
 	go.opentelemetry.io/otel/trace v1.29.0 // indirect
 	go.opentelemetry.io/proto/otlp v1.3.1 // indirect
+	go.uber.org/multierr v1.11.0 // indirect
 	golang.org/x/net v0.28.0 // indirect
 	golang.org/x/oauth2 v0.22.0 // indirect
 	golang.org/x/sys v0.24.0 // indirect

v2/go.sum

@@ -469,8 +469,8 @@ go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9i
 go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0=
 go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
 go.uber.org/zap v1.17.0/go.mod h1:MXVU+bhUf/A7Xi2HNOnopQOrmycQ5Ih87HtOu4q5SSo=
-go.uber.org/zap v1.26.0 h1:sI7k6L95XOKS281NhVKOFCUNIvv9e0w4BF8N3u+tCRo=
-go.uber.org/zap v1.26.0/go.mod h1:dtElttAiwGvoJ/vj4IwHBS/gXsEu/pZ50mUIRWuG0so=
+go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8=
+go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E=
 golang.org/x/crypto v0.0.0-20181029021203-45a5f77698d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
 golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
 golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=

v2/internal/controllers/suite_test.go

@@ -42,8 +42,11 @@ func setup() error {
 
 	// If you need to debug envtest setup/teardown,
 	// set a global logger for controller-runtime:
+	//
 	// import (ctrl "sigs.k8s.io/controller-runtime")
-	// ctrl.SetLogger(klogr.New())
+	// cfg := textlogger.NewConfig(textlogger.Verbosity(Debug)) // Use verbose logging in tests
+	// log := textlogger.NewLogger(cfg)
+	// ctrl.SetLogger(log)
 
 	nameConfig := testcommon.NewResourceNameConfig(
 		testcommon.ResourcePrefix,

v2/internal/genericarmclient/suite_test.go

@@ -13,9 +13,11 @@ import (
 
 	"github.com/onsi/gomega"
 	"github.com/onsi/gomega/format"
-	"k8s.io/klog/v2/klogr"
+	"k8s.io/klog/v2/textlogger"
+
 	ctrl "sigs.k8s.io/controller-runtime"
 
+	. "github.com/Azure/azure-service-operator/v2/internal/logging"
 	"github.com/Azure/azure-service-operator/v2/internal/testcommon"
 )
 
@@ -26,14 +28,16 @@ var testContext testcommon.TestContext
 func setup() error {
 	recordReplay := os.Getenv("RECORD_REPLAY") != "0"
 
-	log.Println("Running test setup")
-
 	gomega.SetDefaultEventuallyTimeout(DefaultEventuallyTimeout)
 	gomega.SetDefaultEventuallyPollingInterval(5 * time.Second)
 	format.TruncateThreshold = 4000 // Force a longer truncate threshold
 
 	// setup global logger for controller-runtime:
-	ctrl.SetLogger(klogr.New()) //nolint: staticcheck
+	cfg := textlogger.NewConfig(textlogger.Verbosity(Debug)) // Use verbose logging in tests
+	log := textlogger.NewLogger(cfg)
+	ctrl.SetLogger(log)
+
+	log.Info("Running test setup")
 
 	nameConfig := testcommon.NewResourceNameConfig(
 		testcommon.ResourcePrefix,
@@ -44,7 +48,7 @@ func setup() error {
 	// set global test context
 	testContext = testcommon.NewTestContext(testcommon.DefaultTestRegion, recordReplay, nameConfig)
 
-	log.Println("Done with test setup")
+	log.Info("Done with test setup")
 
 	return nil
 }

v2/internal/testcommon/kube_test_context_envtest.go

@@ -30,7 +30,6 @@ import (
 	"sigs.k8s.io/controller-runtime/pkg/client"
 	"sigs.k8s.io/controller-runtime/pkg/controller"
 	"sigs.k8s.io/controller-runtime/pkg/envtest"
-	ctrllog "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/metrics/server"
 	"sigs.k8s.io/controller-runtime/pkg/reconcile"
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
@@ -89,10 +88,13 @@ func createSharedEnvTest(cfg testConfig, namespaceResources *namespaceResources)
 		Scheme: scheme,
 	}
 
-	// TODO: Switch to klogr.New() below the below if we want controller-runtime logs in the tests.
+	// Switch logger below if we want controller-runtime logs in the tests.
 	// By default we've disabled controller runtime logs because they're very verbose and usually not useful.
-	// ctrl.SetLogger(klogr.New())
-	ctrl.SetLogger(logr.New(ctrllog.NullLogSink{}))
+	// import (ctrl "sigs.k8s.io/controller-runtime")
+	// cfg := textlogger.NewConfig(textlogger.Verbosity(Debug)) // Use verbose logging in tests
+	// log := textlogger.NewLogger(cfg)
+	// ctrl.SetLogger(log)
+	ctrl.SetLogger(logr.Discard())
 
 	log.Println("Starting envtest")
 	kubeConfig, err := environment.Start()
@@ -160,8 +162,12 @@ func createSharedEnvTest(cfg testConfig, namespaceResources *namespaceResources)
 
 	// TODO: Uncomment the below if we want controller-runtime logs in the tests.
 	// By default we've disabled controller runtime logs because they're very verbose and usually not useful.
-	// ctrl.SetLogger(klogr.New())
-	ctrl.SetLogger(logr.New(ctrllog.NullLogSink{}))
+	//
+	// import (ctrl "sigs.k8s.io/controller-runtime")
+	// cfg := textlogger.NewConfig(textlogger.Verbosity(Debug)) // Use verbose logging in tests
+	// log := textlogger.NewLogger(cfg)
+	// ctrl.SetLogger(log)
+	ctrl.SetLogger(logr.Discard())
 
 	loggerFactory := func(obj metav1.Object) logr.Logger {
 		result := namespaceResources.Lookup(obj.GetNamespace())

v2/pkg/genruntime/test/suite_test.go

@@ -41,8 +41,11 @@ func setup() error {
 
 	// If you need to debug envtest setup/teardown,
 	// set a global logger for controller-runtime:
+	//
 	// import (ctrl "sigs.k8s.io/controller-runtime")
-	// ctrl.SetLogger(klogr.New())
+	// cfg := textlogger.NewConfig(textlogger.Verbosity(Debug)) // Use verbose logging in tests
+	// log := textlogger.NewLogger(cfg)
+	// ctrl.SetLogger(log)
 
 	nameConfig := testcommon.NewResourceNameConfig(
 		testcommon.ResourcePrefix,