K8SPSMDB-906: Logging improvements (#1199)

* Standard controller names.

* Propper pbmName key.

* Remove unnecessary LOG_VERBOSE env var.

---------

Co-authored-by: Viacheslav Sarzhan <[email protected]>

Author: inelpandzic

cmd/mongodb-healthcheck/main.go

@@ -17,12 +17,17 @@ package main
 import (
 	"context"
 	"os"
+	"strconv"
+	"strings"
+
+	uzap "go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"sigs.k8s.io/controller-runtime/pkg/log/zap"
 
 	"github.com/percona/percona-server-mongodb-operator/healthcheck"
 	"github.com/percona/percona-server-mongodb-operator/healthcheck/pkg"
 	"github.com/percona/percona-server-mongodb-operator/healthcheck/tools/db"
 	"github.com/percona/percona-server-mongodb-operator/healthcheck/tools/tool"
-	log "github.com/sirupsen/logrus"
 )
 
 var (
@@ -31,17 +36,24 @@ var (
 )
 
 func main() {
-	app, _ := tool.New("Performs health and readiness checks for MongoDB", GitCommit, GitBranch)
+	app := tool.New("Performs health and readiness checks for MongoDB", GitCommit, GitBranch)
 
 	k8sCmd := app.Command("k8s", "Performs liveness check for MongoDB on Kubernetes")
 	livenessCmd := k8sCmd.Command("liveness", "Run a liveness check of MongoDB").Default()
 	_ = k8sCmd.Command("readiness", "Run a readiness check of MongoDB")
 	startupDelaySeconds := livenessCmd.Flag("startupDelaySeconds", "").Default("7200").Uint64()
 	component := k8sCmd.Flag("component", "").Default("mongod").String()
 
+	opts := zap.Options{
+		Encoder: getLogEncoder(),
+		Level:   getLogLevel(),
+	}
+	log := zap.New(zap.UseFlagOptions(&opts))
+
 	restoreInProgress, err := fileExists("/opt/percona/restore-in-progress")
 	if err != nil {
-		log.Fatalf("check if restore in progress: %v", err)
+		log.Error(err, "check if restore in progress")
+		os.Exit(1)
 	}
 
 	if restoreInProgress {
@@ -53,65 +65,70 @@ func main() {
 		pkg.EnvMongoDBClusterMonitorUser,
 		pkg.EnvMongoDBClusterMonitorPassword,
 	)
+
 	if err != nil {
-		log.Fatalf("new cfg: %s", err)
+		log.Error(err, "new cfg")
+		os.Exit(1)
 	}
 
 	command, err := app.Parse(os.Args[1:])
 	if err != nil {
-		log.Fatalf("Cannot parse command line: %s", err)
+		log.Error(err, "Cannot parse command line")
+		os.Exit(1)
 	}
 
 	client, err := db.Dial(cnf)
 	if err != nil {
-		log.Fatalf("connection error: %v", err)
+		log.Error(err, "connection error")
+		os.Exit(1)
 	}
 
 	defer func() {
 		if err := client.Disconnect(context.TODO()); err != nil {
-			log.Fatalf("failed to disconnect: %v", err)
+			log.Error(err, "failed to disconnect")
+			os.Exit(1)
 		}
 	}()
 
 	switch command {
 
 	case "k8s liveness":
-		log.Infof("Running Kubernetes liveness check for %s", *component)
+		log.Info("Running Kubernetes liveness check for", "component", component)
 		switch *component {
 
 		case "mongod":
 			memberState, err := healthcheck.HealthCheckMongodLiveness(client, int64(*startupDelaySeconds))
 			if err != nil {
 				client.Disconnect(context.TODO()) // nolint:golint,errcheck
-				log.Errorf("Member failed Kubernetes liveness check: %s", err.Error())
+				log.Error(err, "Member failed Kubernetes liveness check")
 				os.Exit(1)
 			}
-			log.Infof("Member passed Kubernetes liveness check with replication state: %d", *memberState)
+			log.Info("Member passed Kubernetes liveness check with replication state", "state", memberState)
 
 		case "mongos":
 			err := healthcheck.HealthCheckMongosLiveness(client)
 			if err != nil {
 				client.Disconnect(context.TODO()) // nolint:golint,errcheck
-				log.Errorf("Member failed Kubernetes liveness check: %s", err.Error())
+				log.Error(err, "Member failed Kubernetes liveness check")
 				os.Exit(1)
 			}
-			log.Infof("Member passed Kubernetes liveness check")
+			log.Info("Member passed Kubernetes liveness check")
 		}
 
 	case "k8s readiness":
-		log.Infof("Running Kubernetes readiness check for %s", *component)
+		log.Info("Running Kubernetes readiness check for component", "component", component)
 		switch *component {
 
 		case "mongod":
 			client.Disconnect(context.TODO()) // nolint:golint,errcheck
-			log.Error("readiness check for mongod is not implemented")
+			log.Error(err, "readiness check for mongod is not implemented")
 			os.Exit(1)
 
 		case "mongos":
 			err := healthcheck.MongosReadinessCheck(client)
 			if err != nil {
 				client.Disconnect(context.TODO()) // nolint:golint,errcheck
-				log.Errorf("Member failed Kubernetes readiness check: %s", err.Error())
+				log.Error(err, "Member failed Kubernetes readiness check")
 				os.Exit(1)
 			}
 		}
@@ -128,3 +145,40 @@ func fileExists(name string) (bool, error) {
 	}
 	return true, nil
 }
+
+func getLogEncoder() zapcore.Encoder {
+	consoleEnc := zapcore.NewConsoleEncoder(uzap.NewDevelopmentEncoderConfig())
+
+	s, found := os.LookupEnv("LOG_STRUCTURED")
+	if !found {
+		return consoleEnc
+	}
+
+	useJson, err := strconv.ParseBool(s)
+	if err != nil {
+		return consoleEnc
+	}
+	if !useJson {
+		return consoleEnc
+	}
+
+	return zapcore.NewJSONEncoder(uzap.NewProductionEncoderConfig())
+}
+
+func getLogLevel() zapcore.LevelEnabler {
+	l, found := os.LookupEnv("LOG_LEVEL")
+	if !found {
+		return zapcore.InfoLevel
+	}
+
+	switch strings.ToUpper(l) {
+	case "DEBUG":
+		return zapcore.DebugLevel
+	case "INFO":
+		return zapcore.InfoLevel
+	case "ERROR":
+		return zapcore.ErrorLevel
+	default:
+		return zapcore.InfoLevel
+	}
+}

deploy/bundle.yaml

@@ -17168,7 +17168,5 @@ spec:
               value: percona-server-mongodb-operator
             - name: RESYNC_PERIOD
               value: 5s
-            - name: LOG_VERBOSE
-              value: "false"
             - name: DISABLE_TELEMETRY
               value: "false"

deploy/cw-bundle.yaml

@@ -17179,7 +17179,5 @@ spec:
               value: percona-server-mongodb-operator
             - name: RESYNC_PERIOD
               value: 5s
-            - name: LOG_VERBOSE
-              value: "false"
             - name: DISABLE_TELEMETRY
               value: "false"

deploy/cw-operator.yaml

@@ -38,7 +38,5 @@ spec:
               value: percona-server-mongodb-operator
             - name: RESYNC_PERIOD
               value: 5s
-            - name: LOG_VERBOSE
-              value: "false"
             - name: DISABLE_TELEMETRY
               value: "false"

deploy/operator.yaml

@@ -40,7 +40,5 @@ spec:
               value: percona-server-mongodb-operator
             - name: RESYNC_PERIOD
               value: 5s
-            - name: LOG_VERBOSE
-              value: "false"
             - name: DISABLE_TELEMETRY
               value: "false"

healthcheck/pkg/env.go

@@ -16,7 +16,6 @@ package pkg
 
 const (
 	// general
-	EnvLogVerbose     = "LOG_VERBOSE"
 	EnvServiceName    = "SERVICE_NAME"
 	EnvMongoDBPort    = "MONGODB_PORT"
 	EnvMongoDBIp      = "MONGODB_IP"

healthcheck/tools/logger/logger.go

@@ -22,23 +22,18 @@ import (
 
 	"github.com/alecthomas/kingpin"
 	tools "github.com/percona/percona-server-mongodb-operator/healthcheck"
-	"github.com/percona/percona-server-mongodb-operator/healthcheck/tools/logger"
 )
 
 // Author is the author used by kingpin
 const Author = "Percona LLC."
 
 // New sets up a new kingpin.Application
-func New(help, commit, branch string) (*kingpin.Application, *bool) {
+func New(help, commit, branch string) *kingpin.Application {
 	app := kingpin.New(filepath.Base(os.Args[0]), help)
 	app.Author(Author)
 	app.Version(fmt.Sprintf(
 		"%s version %s\ngit commit %s, branch %s\ngo version %s",
 		app.Name, tools.Version, commit, branch, runtime.Version(),
 	))
-	return app, logger.SetupLogger(
-		app,
-		logger.GetLogFormatter(),
-		os.Stdout,
-	)
+	return app
 }

healthcheck/tools/tool/tool.go

@@ -114,7 +114,7 @@ func (b *Backup) Status(ctx context.Context, cr *api.PerconaServerMongoDBBackup)
 	}
 
 	if meta == nil || meta.Name == "" || errors.Is(err, pbm.ErrNotFound) {
-		logf.FromContext(ctx).Info("Waiting for backup metadata", "PBM name", cr.Status.PBMname, "backup", cr.Name)
+		logf.FromContext(ctx).Info("Waiting for backup metadata", "pbmName", cr.Status.PBMname, "backup", cr.Name)
 		return status, nil
 	}
 

pkg/controller/perconaservermongodbbackup/backup.go

@@ -51,7 +51,7 @@ func newReconciler(mgr manager.Manager) reconcile.Reconciler {
 // add adds a new Controller to mgr with r as the reconcile.Reconciler
 func add(mgr manager.Manager, r reconcile.Reconciler) error {
 	// Create a new controller
-	c, err := controller.New("perconaservermongodbbackup-controller", mgr, controller.Options{Reconciler: r})
+	c, err := controller.New("psmdbbackup-controller", mgr, controller.Options{Reconciler: r})
 	if err != nil {
 		return err
 	}