[Feature] Add new logger services (#750)

Author: ajanikow

CHANGELOG.md

@@ -5,6 +5,7 @@
 - Deprecate Alpine image usage
 - Use persistent name and namespace in ArangoDeployment reconcilation loop
 - Remove finalizers when Server container is already terminated and reduce initial reconciliation delay
+- Add new logger services - reconciliation and event
 
 ## [1.1.9](https://github.com/arangodb/kube-arangodb/tree/1.1.9) (2021-05-28)
 - Add IP, DNS, ShortDNS, HeadlessService (Default) communication methods

main.go

@@ -139,7 +139,7 @@ func init() {
 	f.StringVar(&serverOptions.tlsSecretName, "server.tls-secret-name", "", "Name of secret containing tls.crt & tls.key for HTTPS server (if empty, self-signed certificate is used)")
 	f.StringVar(&serverOptions.adminSecretName, "server.admin-secret-name", defaultAdminSecretName, "Name of secret containing username + password for login to the dashboard")
 	f.BoolVar(&serverOptions.allowAnonymous, "server.allow-anonymous-access", false, "Allow anonymous access to the dashboard")
-	f.StringArrayVar(&logLevels, "log.level", []string{defaultLogLevel}, "Set log levels in format <level> or <logger>=<level>")
+	f.StringArrayVar(&logLevels, "log.level", []string{defaultLogLevel}, fmt.Sprintf("Set log levels in format <level> or <logger>=<level>. Possible loggers: %s", strings.Join(logging.LoggerNames(), ", ")))
 	f.BoolVar(&operatorOptions.enableDeployment, "operator.deployment", false, "Enable to run the ArangoDeployment operator")
 	f.BoolVar(&operatorOptions.enableDeploymentReplication, "operator.deployment-replication", false, "Enable to run the ArangoDeploymentReplication operator")
 	f.BoolVar(&operatorOptions.enableStorage, "operator.storage", false, "Enable to run the ArangoLocalStorage operator")
@@ -193,7 +193,7 @@ func cmdMainRun(cmd *cobra.Command, args []string) {
 		return log.With().Str("operator-id", operatorID).Logger()
 	})
 
-	klog.SetOutput(logService.MustGetLogger("klog"))
+	klog.SetOutput(logService.MustGetLogger(logging.LoggerNameKLog))
 	klog.Info("nice to meet you")
 	klog.Flush()
 
@@ -253,7 +253,7 @@ func cmdMainRun(cmd *cobra.Command, args []string) {
 		AdminSecretName:    serverOptions.adminSecretName,
 		AllowAnonymous:     serverOptions.allowAnonymous,
 	}, server.Dependencies{
-		Log:           logService.MustGetLogger("server"),
+		Log:           logService.MustGetLogger(logging.LoggerNameServer),
 		LivenessProbe: &livenessProbe,
 		Deployment: server.OperatorDependency{
 			Enabled: cfg.EnableDeployment,

pkg/backup/handlers/arango/backup/backup_suite_test.go

@@ -27,6 +27,8 @@ import (
 	"fmt"
 	"testing"
 
+	"github.com/rs/zerolog/log"
+
 	"github.com/arangodb/kube-arangodb/pkg/util/errors"
 
 	"github.com/arangodb/go-driver"
@@ -59,7 +61,7 @@ func newFakeHandler() *handler {
 		kubeClient: k,
 
 		arangoClientTimeout: defaultArangoClientTimeout,
-		eventRecorder:       newEventInstance(event.NewEventRecorder("mock", k)),
+		eventRecorder:       newEventInstance(event.NewEventRecorder(log.Logger, "mock", k)),
 	}
 }
 

pkg/backup/handlers/arango/policy/handler_suite_test.go

@@ -27,6 +27,8 @@ import (
 	"fmt"
 	"testing"
 
+	"github.com/rs/zerolog/log"
+
 	"github.com/arangodb/kube-arangodb/pkg/apis/backup"
 	"github.com/arangodb/kube-arangodb/pkg/apis/deployment"
 
@@ -50,7 +52,7 @@ func newFakeHandler() *handler {
 	h := &handler{
 		client:        f,
 		kubeClient:    k,
-		eventRecorder: newEventInstance(event.NewEventRecorder("mock", k)),
+		eventRecorder: newEventInstance(event.NewEventRecorder(log.Logger, "mock", k)),
 	}
 
 	return h

pkg/backup/operator/event/event.go

@@ -26,18 +26,20 @@ import (
 	"context"
 	"fmt"
 
-	"github.com/rs/zerolog/log"
+	"github.com/rs/zerolog"
+
 	core "k8s.io/api/core/v1"
 	meta "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/util/uuid"
 	"k8s.io/client-go/kubernetes"
 )
 
 // NewEventRecorder creates new event recorder
-func NewEventRecorder(name string, kubeClientSet kubernetes.Interface) Recorder {
+func NewEventRecorder(logger zerolog.Logger, name string, kubeClientSet kubernetes.Interface) Recorder {
 	return &eventRecorder{
 		kubeClientSet: kubeClientSet,
 		name:          name,
+		logger:        logger,
 	}
 }
 
@@ -51,6 +53,7 @@ type Recorder interface {
 type eventRecorder struct {
 	name          string
 	kubeClientSet kubernetes.Interface
+	logger        zerolog.Logger
 }
 
 func (e *eventRecorder) newEvent(group, version, kind string, object meta.Object, eventType, reason, message string) *core.Event {
@@ -90,15 +93,15 @@ func (e *eventRecorder) newObjectReference(group, version, kind string, object m
 func (e *eventRecorder) event(group, version, kind string, object meta.Object, eventType, reason, message string) {
 	_, err := e.kubeClientSet.CoreV1().Events(object.GetNamespace()).Create(context.Background(), e.newEvent(group, version, kind, object, eventType, reason, message), meta.CreateOptions{})
 	if err != nil {
-		log.Warn().Err(err).
+		e.logger.Warn().Err(err).
 			Str("APIVersion", fmt.Sprintf("%s/%s", group, version)).
 			Str("Kind", kind).
 			Str("Object", fmt.Sprintf("%s/%s", object.GetNamespace(), object.GetName())).
 			Msgf("Unable to send event")
 		return
 	}
 
-	log.Info().
+	e.logger.Info().
 		Str("APIVersion", fmt.Sprintf("%s/%s", group, version)).
 		Str("Kind", kind).
 		Str("Object", fmt.Sprintf("%s/%s", object.GetNamespace(), object.GetName())).

pkg/backup/operator/event/event_test.go

@@ -27,6 +27,8 @@ import (
 	"fmt"
 	"testing"
 
+	"github.com/rs/zerolog/log"
+
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	core "k8s.io/api/core/v1"
@@ -39,7 +41,7 @@ func Test_Event_Handler(t *testing.T) {
 	// Arrange
 	c := fake.NewSimpleClientset()
 
-	recorder := NewEventRecorder("mock", c)
+	recorder := NewEventRecorder(log.Logger, "mock", c)
 
 	group := string(uuid.NewUUID())
 	version := "v1"

pkg/backup/operator/operator.go

@@ -26,13 +26,14 @@ import (
 	"sync"
 	"time"
 
+	"github.com/rs/zerolog"
+
 	"github.com/arangodb/kube-arangodb/pkg/util/errors"
 
 	"github.com/arangodb/kube-arangodb/pkg/backup/operator/operation"
 
 	"github.com/prometheus/client_golang/prometheus"
 
-	"github.com/rs/zerolog/log"
 	"k8s.io/apimachinery/pkg/util/wait"
 	"k8s.io/client-go/tools/cache"
 	"k8s.io/client-go/util/workqueue"
@@ -62,10 +63,11 @@ type Operator interface {
 }
 
 // NewOperator creates new operator
-func NewOperator(name, namespace string) Operator {
+func NewOperator(logger zerolog.Logger, name, namespace string) Operator {
 	o := &operator{
 		name:      name,
 		namespace: namespace,
+		logger:    logger,
 		workqueue: workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), name),
 	}
 
@@ -80,6 +82,8 @@ type operator struct {
 
 	started bool
 
+	logger zerolog.Logger
+
 	name      string
 	namespace string
 
@@ -192,14 +196,14 @@ func (o *operator) Start(threadiness int, stopCh <-chan struct{}) error {
 
 func (o *operator) start(threadiness int, stopCh <-chan struct{}) error {
 	// Execute pre checks
-	log.Info().Msgf("Executing Lifecycle PreStart")
+	o.logger.Info().Msgf("Executing Lifecycle PreStart")
 	for _, handler := range o.handlers {
 		if err := ExecLifecyclePreStart(handler); err != nil {
 			return err
 		}
 	}
 
-	log.Info().Msgf("Starting informers")
+	o.logger.Info().Msgf("Starting informers")
 	for _, starter := range o.starters {
 		starter.Start(stopCh)
 	}
@@ -208,12 +212,12 @@ func (o *operator) start(threadiness int, stopCh <-chan struct{}) error {
 		return err
 	}
 
-	log.Info().Msgf("Starting workers")
+	o.logger.Info().Msgf("Starting workers")
 	for i := 0; i < threadiness; i++ {
 		go wait.Until(o.worker, time.Second, stopCh)
 	}
 
-	log.Info().Msgf("Operator started")
+	o.logger.Info().Msgf("Operator started")
 	return nil
 }
 

pkg/backup/operator/operator_test.go

@@ -26,6 +26,8 @@ import (
 	"context"
 	"time"
 
+	"github.com/rs/zerolog/log"
+
 	"github.com/arangodb/kube-arangodb/pkg/backup/operator/operation"
 
 	"github.com/stretchr/testify/assert"
@@ -43,7 +45,7 @@ import (
 func Test_Operator_InformerProcessing(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 	size := 64
 
 	objects := make([]string, size)
@@ -92,7 +94,7 @@ func Test_Operator_InformerProcessing(t *testing.T) {
 func Test_Operator_MultipleInformers(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 	size := 16
 
 	objects := make([]string, size)
@@ -153,7 +155,7 @@ func Test_Operator_MultipleInformers(t *testing.T) {
 func Test_Operator_MultipleInformers_IgnoredTypes(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 	size := 16
 
 	objects := make([]string, size)
@@ -213,7 +215,7 @@ func Test_Operator_MultipleInformers_IgnoredTypes(t *testing.T) {
 func Test_Operator_MultipleInformers_MultipleHandlers(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 	size := 16
 
 	objects := make([]string, size)
@@ -321,7 +323,7 @@ func Test_Operator_MultipleInformers_MultipleHandlers(t *testing.T) {
 func Test_Operator_InformerProcessing_Namespaced(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 	size := 16
 
 	objects := make([]string, size)

pkg/backup/operator/operator_worker.go

@@ -25,8 +25,6 @@ package operator
 import (
 	"github.com/arangodb/kube-arangodb/pkg/backup/operator/operation"
 	"github.com/arangodb/kube-arangodb/pkg/util/errors"
-
-	"github.com/rs/zerolog/log"
 )
 
 func (o *operator) worker() {
@@ -39,7 +37,7 @@ func (o *operator) processNextItem() bool {
 	defer func() {
 		// Recover from panic to not shutdown whole operator
 		if err := recover(); err != nil {
-			e := log.Error()
+			e := o.logger.Error()
 
 			switch obj := err.(type) {
 			case error:
@@ -65,7 +63,7 @@ func (o *operator) processNextItem() bool {
 	err := o.processObject(obj)
 
 	if err != nil {
-		log.Error().Err(err).Interface("object", obj).Msgf("Error during object handling")
+		o.logger.Error().Err(err).Interface("object", obj).Msgf("Error during object handling")
 		return true
 	}
 
@@ -98,7 +96,7 @@ func (o *operator) processObject(obj interface{}) error {
 
 	o.objectProcessed.Inc()
 
-	log.Debug().Msgf("Received Item Action: %s, Type: %s/%s/%s, Namespace: %s, Name: %s",
+	o.logger.Trace().Msgf("Received Item Action: %s, Type: %s/%s/%s, Namespace: %s, Name: %s",
 		item.Operation,
 		item.Group,
 		item.Version,
@@ -111,7 +109,7 @@ func (o *operator) processObject(obj interface{}) error {
 		return errors.Newf("error syncing '%s': %s, requeuing", key, err.Error())
 	}
 
-	log.Debug().Msgf("Processed Item Action: %s, Type: %s/%s/%s, Namespace: %s, Name: %s",
+	o.logger.Trace().Msgf("Processed Item Action: %s, Type: %s/%s/%s, Namespace: %s, Name: %s",
 		item.Operation,
 		item.Group,
 		item.Version,

pkg/backup/operator/operator_worker_test.go

@@ -25,6 +25,8 @@ package operator
 import (
 	"testing"
 
+	"github.com/rs/zerolog/log"
+
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"k8s.io/apimachinery/pkg/util/uuid"
@@ -33,7 +35,7 @@ import (
 func Test_Worker_Empty(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 
 	stopCh := make(chan struct{})
 
@@ -53,7 +55,7 @@ func Test_Worker_Empty(t *testing.T) {
 func Test_Worker_CatchAll(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 
 	stopCh := make(chan struct{})
 
@@ -82,7 +84,7 @@ func Test_Worker_CatchAll(t *testing.T) {
 func Test_Worker_EnsureFirstProcessStopLoop(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 
 	stopCh := make(chan struct{})
 
@@ -116,7 +118,7 @@ func Test_Worker_EnsureFirstProcessStopLoop(t *testing.T) {
 func Test_Worker_EnsureObjectIsProcessedBySecondHandler(t *testing.T) {
 	// Arrange
 	name := string(uuid.NewUUID())
-	o := NewOperator(name, name)
+	o := NewOperator(log.Logger, name, name)
 
 	stopCh := make(chan struct{})