enhance log format using zapr logger. (#195)

Signed-off-by: morvencao <[email protected]>

Makefile

@@ -60,7 +60,7 @@ mqtt_password_file=${PWD}/secrets/mqtt.password
 mqtt_config_file=${PWD}/secrets/mqtt.config
 
 # Log verbosity level
-glog_v:=10
+klog_v:=10
 
 # Location of the JSON web key set used to verify tokens:
 jwks_url:=https://sso.redhat.com/auth/realms/redhat-external/protocol/openid-connect/certs
@@ -269,7 +269,7 @@ cmds:
 		--local="true" \
 		--ignore-unknown-parameters="true" \
 		--param="ENVIRONMENT=$(OCM_ENV)" \
-		--param="GLOG_V=$(glog_v)" \
+		--param="KLOG_V=$(klog_v)" \
 		--param="SERVER_REPLICAS=$(SERVER_REPLICAS)" \
 		--param="DATABASE_HOST=$(db_host)" \
 		--param="DATABASE_NAME=$(db_name)" \

cmd/maestro/agent/cmd.go

@@ -2,16 +2,13 @@ package agent
 
 import (
 	"context"
-	"flag"
 	"fmt"
-	"os"
 
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 	utilruntime "k8s.io/apimachinery/pkg/util/runtime"
 	utilflag "k8s.io/component-base/cli/flag"
 	"k8s.io/component-base/version"
-	"k8s.io/klog/v2"
 	ocmfeature "open-cluster-management.io/api/feature"
 	commonoptions "open-cluster-management.io/ocm/pkg/common/options"
 	"open-cluster-management.io/ocm/pkg/features"
@@ -38,17 +35,8 @@ func NewAgentCommand() *cobra.Command {
 	cmd.Short = "Start the Maestro Agent"
 	cmd.Long = "Start the Maestro Agent"
 
-	// check if the flag is already registered to avoid duplicate flag define error
-	if flag.CommandLine.Lookup("alsologtostderr") != nil {
-		flag.CommandLine = flag.NewFlagSet(os.Args[0], flag.ExitOnError)
-	}
-
-	// add klog flags
-	klog.InitFlags(nil)
-
-	flags := cmd.Flags()
+	flags := cmd.PersistentFlags()
 	flags.SetNormalizeFunc(utilflag.WordSepNormalizeFunc)
-	flags.AddGoFlagSet(flag.CommandLine)
 
 	// add common flags
 	// commonOptions.AddFlags(flags)
@@ -58,8 +46,11 @@ func NewAgentCommand() *cobra.Command {
 	// add alias flags
 	addFlags(flags)
 
-	utilruntime.Must(features.SpokeMutableFeatureGate.Add(ocmfeature.DefaultSpokeWorkFeatureGates))
-	utilruntime.Must(features.SpokeMutableFeatureGate.Set(fmt.Sprintf("%s=true", ocmfeature.RawFeedbackJsonString)))
+	// add pre-run to set feature gates
+	cmd.PreRun = func(cmd *cobra.Command, args []string) {
+		utilruntime.Must(features.SpokeMutableFeatureGate.Add(ocmfeature.DefaultSpokeWorkFeatureGates))
+		utilruntime.Must(features.SpokeMutableFeatureGate.Set(fmt.Sprintf("%s=true", ocmfeature.RawFeedbackJsonString)))
+	}
 
 	return cmd
 }

cmd/maestro/environments/framework.go

@@ -6,7 +6,6 @@ import (
 	"strings"
 
 	"github.com/getsentry/sentry-go"
-	"github.com/golang/glog"
 	"github.com/openshift-online/maestro/pkg/client/cloudevents"
 	"github.com/openshift-online/maestro/pkg/client/grpcauthorizer"
 	"github.com/openshift-online/maestro/pkg/client/ocm"
@@ -16,6 +15,7 @@ import (
 	"k8s.io/client-go/kubernetes"
 	"k8s.io/client-go/rest"
 	"k8s.io/client-go/tools/clientcmd"
+	"k8s.io/klog/v2"
 
 	"open-cluster-management.io/sdk-go/pkg/cloudevents/generic"
 )
@@ -76,36 +76,36 @@ func (e *Env) AddFlags(flags *pflag.FlagSet) error {
 // This should be called after the e.Config has been set appropriately though AddFlags and pasing, done elsewhere
 // The environment does NOT handle flag parsing
 func (e *Env) Initialize() error {
-	glog.Infof("Initializing %s environment", e.Name)
+	klog.Infof("Initializing %s environment", e.Name)
 
 	envImpl, found := environments[e.Name]
 	if !found {
-		glog.Fatalf("Unknown runtime environment: %s", e.Name)
+		klog.Fatalf("Unknown runtime environment: %s", e.Name)
 	}
 
 	if err := envImpl.VisitConfig(&e.ApplicationConfig); err != nil {
-		glog.Fatalf("Failed to visit ApplicationConfig: %s", err)
+		klog.Fatalf("Failed to visit ApplicationConfig: %s", err)
 	}
 
 	messages := environment.Config.ReadFiles()
 	if len(messages) != 0 {
 		err := fmt.Errorf("unable to read configuration files:\n%s", strings.Join(messages, "\n"))
 		sentry.CaptureException(err)
-		glog.Fatalf("Unable to read configuration files:\n%s", strings.Join(messages, "\n"))
+		klog.Fatalf("Unable to read configuration files:\n%s", strings.Join(messages, "\n"))
 	}
 
 	// each env will set db explicitly because the DB impl has a `once` init section
 	if err := envImpl.VisitDatabase(&e.Database); err != nil {
-		glog.Fatalf("Failed to visit Database: %s", err)
+		klog.Fatalf("Failed to visit Database: %s", err)
 	}
 
 	if err := envImpl.VisitMessageBroker(&e.MessageBroker); err != nil {
-		glog.Fatalf("Failed to visit MessageBroker: %s", err)
+		klog.Fatalf("Failed to visit MessageBroker: %s", err)
 	}
 
 	e.LoadServices()
 	if err := envImpl.VisitServices(&e.Services); err != nil {
-		glog.Fatalf("Failed to visit Services: %s", err)
+		klog.Fatalf("Failed to visit Services: %s", err)
 	}
 
 	// Load clients after services so that clients can use services
@@ -114,7 +114,7 @@ func (e *Env) Initialize() error {
 		return err
 	}
 	if err := envImpl.VisitClients(&e.Clients); err != nil {
-		glog.Fatalf("Failed to visit Clients: %s", err)
+		klog.Fatalf("Failed to visit Clients: %s", err)
 	}
 
 	err = e.InitializeSentry()
@@ -129,7 +129,7 @@ func (e *Env) Initialize() error {
 
 	if _, ok := envImpl.(HandlerVisitor); ok {
 		if err := (envImpl.(HandlerVisitor)).VisitHandlers(&e.Handlers); err != nil {
-			glog.Fatalf("Failed to visit Handlers: %s", err)
+			klog.Fatalf("Failed to visit Handlers: %s", err)
 		}
 	}
 
@@ -162,39 +162,39 @@ func (e *Env) LoadClients() error {
 
 	// Create OCM Authz client
 	if e.Config.OCM.EnableMock {
-		glog.Infof("Using Mock OCM Authz Client")
+		klog.Infof("Using Mock OCM Authz Client")
 		e.Clients.OCM, err = ocm.NewClientMock(ocmConfig)
 	} else {
 		e.Clients.OCM, err = ocm.NewClient(ocmConfig)
 	}
 	if err != nil {
-		glog.Errorf("Unable to create OCM Authz client: %s", err.Error())
+		klog.Errorf("Unable to create OCM Authz client: %s", err.Error())
 		return err
 	}
 
 	// Create CloudEvents Source client
 	if e.Config.MessageBroker.EnableMock {
-		glog.Infof("Using Mock CloudEvents Source Client")
+		klog.Infof("Using Mock CloudEvents Source Client")
 		e.Clients.CloudEventsSource = cloudevents.NewSourceClientMock(e.Services.Resources())
 	} else {
 		// For gRPC message broker type, Maestro server does not require the source client to publish resources or subscribe to resource status.
 		if e.Config.MessageBroker.MessageBrokerType != "grpc" {
 			_, config, err := generic.NewConfigLoader(e.Config.MessageBroker.MessageBrokerType, e.Config.MessageBroker.MessageBrokerConfig).
 				LoadConfig()
 			if err != nil {
-				glog.Errorf("Unable to load configuration: %s", err.Error())
+				klog.Errorf("Unable to load configuration: %s", err.Error())
 				return err
 			}
 
 			cloudEventsSourceOptions, err := generic.BuildCloudEventsSourceOptions(config,
 				e.Config.MessageBroker.ClientID, e.Config.MessageBroker.SourceID)
 			if err != nil {
-				glog.Errorf("Unable to build cloudevent source options: %s", err.Error())
+				klog.Errorf("Unable to build cloudevent source options: %s", err.Error())
 				return err
 			}
 			e.Clients.CloudEventsSource, err = cloudevents.NewSourceClient(cloudEventsSourceOptions, e.Services.Resources())
 			if err != nil {
-				glog.Errorf("Unable to create CloudEvents Source client: %s", err.Error())
+				klog.Errorf("Unable to create CloudEvents Source client: %s", err.Error())
 				return err
 			}
 		}
@@ -203,22 +203,22 @@ func (e *Env) LoadClients() error {
 	// Create GRPC authorizer based on configuration
 	if e.Config.GRPCServer.EnableGRPCServer {
 		if e.Config.GRPCServer.GRPCAuthNType == "mock" {
-			glog.Infof("Using Mock GRPC Authorizer")
+			klog.Infof("Using Mock GRPC Authorizer")
 			e.Clients.GRPCAuthorizer = grpcauthorizer.NewMockGRPCAuthorizer()
 		} else {
 			kubeConfig, err := clientcmd.BuildConfigFromFlags("", e.Config.GRPCServer.GRPCAuthorizerConfig)
 			if err != nil {
-				glog.Warningf("Unable to create kube client config: %s", err.Error())
+				klog.Warningf("Unable to create kube client config: %s", err.Error())
 				// fallback to in-cluster config
 				kubeConfig, err = rest.InClusterConfig()
 				if err != nil {
-					glog.Errorf("Unable to create kube client config: %s", err.Error())
+					klog.Errorf("Unable to create kube client config: %s", err.Error())
 					return err
 				}
 			}
 			kubeClient, err := kubernetes.NewForConfig(kubeConfig)
 			if err != nil {
-				glog.Errorf("Unable to create kube client: %s", err.Error())
+				klog.Errorf("Unable to create kube client: %s", err.Error())
 				return err
 			}
 			e.Clients.GRPCAuthorizer = grpcauthorizer.NewKubeGRPCAuthorizer(kubeClient)
@@ -235,12 +235,12 @@ func (e *Env) InitializeSentry() error {
 		key := e.Config.Sentry.Key
 		url := e.Config.Sentry.URL
 		project := e.Config.Sentry.Project
-		glog.Infof("Sentry error reporting enabled to %s on project %s", url, project)
+		klog.Infof("Sentry error reporting enabled to %s on project %s", url, project)
 		options.Dsn = fmt.Sprintf("https://%s@%s/%s", key, url, project)
 	} else {
 		// Setting the DSN to an empty string effectively disables sentry
 		// See https://godoc.org/github.com/getsentry/sentry-go#ClientOptions Dsn
-		glog.Infof("Disabling Sentry error reporting")
+		klog.Infof("Disabling Sentry error reporting")
 		options.Dsn = ""
 	}
 
@@ -264,7 +264,7 @@ func (e *Env) InitializeSentry() error {
 
 	err = sentry.Init(options)
 	if err != nil {
-		glog.Errorf("Unable to initialize sentry integration: %s", err.Error())
+		klog.Errorf("Unable to initialize sentry integration: %s", err.Error())
 		return err
 	}
 	return nil
@@ -273,7 +273,7 @@ func (e *Env) InitializeSentry() error {
 func (e *Env) Teardown() {
 	if e.Name != TestingEnv {
 		if err := e.Database.SessionFactory.Close(); err != nil {
-			glog.Fatalf("Unable to close db connection: %s", err.Error())
+			klog.Fatalf("Unable to close db connection: %s", err.Error())
 		}
 		e.Clients.OCM.Close()
 	}
@@ -282,7 +282,7 @@ func (e *Env) Teardown() {
 func setConfigDefaults(flags *pflag.FlagSet, defaults map[string]string) error {
 	for name, value := range defaults {
 		if err := flags.Set(name, value); err != nil {
-			glog.Errorf("Error setting flag %s: %v", name, err)
+			klog.Errorf("Error setting flag %s: %v", name, err)
 			return err
 		}
 	}

cmd/maestro/main.go

@@ -2,37 +2,62 @@ package main
 
 import (
 	"flag"
+	"os"
+	"strconv"
 
-	"github.com/golang/glog"
-	"github.com/spf13/cobra"
-
+	"github.com/go-logr/zapr"
 	"github.com/openshift-online/maestro/cmd/maestro/agent"
 	"github.com/openshift-online/maestro/cmd/maestro/migrate"
 	"github.com/openshift-online/maestro/cmd/maestro/servecmd"
+	"github.com/spf13/cobra"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"k8s.io/klog/v2"
 )
 
 // nolint
 //
 //go:generate go-bindata -o ../../data/generated/openapi/openapi.go -pkg openapi -prefix ../../openapi/ ../../openapi
 
 func main() {
-	// This is needed to make `glog` believe that the flags have already been parsed, otherwise
-	// every log messages is prefixed by an error message stating the the flags haven't been
-	// parsed.
-	_ = flag.CommandLine.Parse([]string{})
+	// check if the glog flag is already registered to avoid duplicate flag define error
+	if flag.CommandLine.Lookup("alsologtostderr") != nil {
+		flag.CommandLine = flag.NewFlagSet(os.Args[0], flag.ExitOnError)
+	}
 
-	//pflag.CommandLine.AddGoFlagSet(flag.CommandLine)
+	// add klog flags
+	klog.InitFlags(nil)
 
-	// Always log to stderr by default
-	if err := flag.Set("logtostderr", "true"); err != nil {
-		glog.Infof("Unable to set logtostderr to true")
-	}
+	// Set up klog backing logger
+	cobra.OnInitialize(func() {
+		// Retrieve log level from klog flags
+		logLevel, err := strconv.ParseInt(flag.CommandLine.Lookup("v").Value.String(), 10, 8)
+		if err != nil {
+			klog.Fatalf("can't parse log level: %v", err)
+		}
+
+		// Initialize zap logger
+		zc := zap.NewDevelopmentConfig()
+		// zap log level is the inverse of klog log level, for more details refer to:
+		// https://github.com/go-logr/zapr?tab=readme-ov-file#increasing-verbosity
+		zc.Level = zap.NewAtomicLevelAt(zapcore.Level(0 - logLevel))
+		zapLog, err := zc.Build()
+		if err != nil {
+			klog.Fatalf("can't initialize zap logger: %v", err)
+		}
+		// Set backing logger for klog
+		klog.SetLogger(zapr.NewLogger(zapLog))
+	})
 
+	// Initialize root command
 	rootCmd := &cobra.Command{
 		Use:  "maestro",
 		Long: "maestro is a multi-cluster resources orchestrator for Kubernetes",
 	}
 
+	// Add klog flags to root command
+	rootCmd.PersistentFlags().AddGoFlagSet(flag.CommandLine)
+
 	// All subcommands under root
 	migrateCmd := migrate.NewMigrationCommand()
 	serveCmd := servecmd.NewServerCommand()
@@ -42,6 +67,6 @@ func main() {
 	rootCmd.AddCommand(migrateCmd, serveCmd, agentCmd)
 
 	if err := rootCmd.Execute(); err != nil {
-		glog.Fatalf("error running command: %v", err)
+		klog.Fatalf("error running command: %v", err)
 	}
 }

cmd/maestro/migrate/cmd.go

@@ -2,11 +2,10 @@ package migrate
 
 import (
 	"context"
-	"flag"
 
-	"github.com/golang/glog"
 	"github.com/openshift-online/maestro/pkg/db/db_session"
 	"github.com/spf13/cobra"
+	"k8s.io/klog/v2"
 
 	"github.com/openshift-online/maestro/pkg/config"
 	"github.com/openshift-online/maestro/pkg/db"
@@ -24,18 +23,17 @@ func NewMigrationCommand() *cobra.Command {
 	}
 
 	dbConfig.AddFlags(cmd.PersistentFlags())
-	cmd.PersistentFlags().AddGoFlagSet(flag.CommandLine)
 	return cmd
 }
 
 func runMigration(_ *cobra.Command, _ []string) {
 	err := dbConfig.ReadFiles()
 	if err != nil {
-		glog.Fatal(err)
+		klog.Fatal(err)
 	}
 
 	connection := db_session.NewProdFactory(dbConfig)
 	if err := db.Migrate(connection.New(context.Background())); err != nil {
-		glog.Fatal(err)
+		klog.Fatal(err)
 	}
 }