Skip to content

Commit

Permalink
Upgrade controller logging (#4222)
Browse files Browse the repository at this point in the history
* Import zapr and zap packages

* Create logging package to create loggers

* Change ParseFlags() to InitFlags()

* Refactor main

* Switch other use to textlogger

* Switch other uses

* Fix lint issues

* Refactor based on PR feedback

* Address PR feedback
  • Loading branch information
theunrepentantgeek authored Sep 2, 2024
1 parent 618f71a commit 1ae868d
Show file tree
Hide file tree
Showing 13 changed files with 200 additions and 85 deletions.
54 changes: 13 additions & 41 deletions v2/cmd/controller/app/flags.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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
}
4 changes: 2 additions & 2 deletions v2/cmd/controller/app/setup.go
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down Expand Up @@ -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 {
Expand Down
101 changes: 101 additions & 0 deletions v2/cmd/controller/logging/logging.go
Original file line number Diff line number Diff line change
@@ -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
}
32 changes: 23 additions & 9 deletions v2/cmd/controller/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
}
3 changes: 3 additions & 0 deletions v2/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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
Expand Down
4 changes: 2 additions & 2 deletions v2/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -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=
Expand Down
5 changes: 4 additions & 1 deletion v2/internal/controllers/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
14 changes: 9 additions & 5 deletions v2/internal/genericarmclient/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)

Expand All @@ -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,
Expand All @@ -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
}
Expand Down
18 changes: 12 additions & 6 deletions v2/internal/testcommon/kube_test_context_envtest.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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()
Expand Down Expand Up @@ -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())
Expand Down
5 changes: 4 additions & 1 deletion v2/pkg/genruntime/test/suite_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
Loading

0 comments on commit 1ae868d

Please sign in to comment.