Add kubernetes objects aware logger with zap (#2179)

Using controller-runtime zap integration which is aware of Kubernetesobjects and logs only name+namespace of the object when complete runtime.Object compatible type is given to logger.

Signed-off-by: Sanket Sudake <sanketsudake@gmail.com>

pkg/executor/executortype/poolmgr/gp.go

@@ -104,7 +104,7 @@ func MakeGenericPool(
 			zap.Duration("default", podReadyTimeout))
 	}
 
-	gpLogger.Info("creating pool", zap.Any("environment", env.ObjectMeta))
+	gpLogger.Info("creating pool", zap.Any("environment", env))
 
 	// TODO: in general we need to provide the user a way to configure pools.  Initial
 	// replicas, autoscaling params, various timeouts, etc.

pkg/executor/executortype/poolmgr/gp_deployment.go

@@ -199,7 +199,7 @@ func (gp *GenericPool) createPoolDeployment(ctx context.Context, env *fv1.Enviro
 	}
 
 	gp.deployment = depl
-	gp.logger.Info("deployment created", zap.String("deployment", depl.Name), zap.String("ns", depl.Namespace), zap.Any("environment", env.ObjectMeta))
+	gp.logger.Info("deployment created", zap.String("deployment", depl.Name), zap.String("ns", depl.Namespace), zap.Any("environment", env))
 
 	return nil
 }

pkg/executor/executortype/poolmgr/poolpodcontroller.go

@@ -66,6 +66,7 @@ func NewPoolPodController(logger *zap.Logger,
 	pkgInformer finformerv1.PackageInformer,
 	envInformer finformerv1.EnvironmentInformer,
 	rsInformer appsinformers.ReplicaSetInformer) *PoolPodController {
+	logger = logger.Named("pool_pod_controller")
 	p := &PoolPodController{
 		logger:           logger,
 		kubernetesClient: kubernetesClient,

pkg/logger/logger.go

@@ -25,7 +25,6 @@ import (
 	"time"
 
 	"go.uber.org/zap"
-	"go.uber.org/zap/zapcore"
 	corev1 "k8s.io/api/core/v1"
 	k8sInformers "k8s.io/client-go/informers"
 	k8sCache "k8s.io/client-go/tools/cache"
@@ -33,6 +32,7 @@ import (
 	fv1 "github.com/fission/fission/pkg/apis/core/v1"
 	"github.com/fission/fission/pkg/crd"
 	"github.com/fission/fission/pkg/utils"
+	"github.com/fission/fission/pkg/utils/loggerfactory"
 )
 
 var nodeName = os.Getenv("NODE_NAME")
@@ -158,36 +158,25 @@ func symlinkReaper(zapLogger *zap.Logger) {
 }
 
 func Start() {
-	config := zap.NewProductionConfig()
-	config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
-	zapLogger, err := config.Build()
-	if err != nil {
-		log.Fatalf("can't initialize zap logger: %v", err)
-	}
-
-	defer func() {
-		err := zapLogger.Sync()
-		if err != nil {
-			log.Fatalf("failed to sync zap logger: %v", err)
-		}
-	}()
+	logger := loggerfactory.GetLogger()
+	defer logger.Sync()
 
 	if _, err := os.Stat(fissionSymlinkPath); os.IsNotExist(err) {
-		zapLogger.Info("symlink path not exist, create it",
+		logger.Info("symlink path not exist, create it",
 			zap.String("fissionSymlinkPath", fissionSymlinkPath))
 		err = os.Mkdir(fissionSymlinkPath, 0755)
 		if err != nil {
-			zapLogger.Fatal("error creating fissionSymlinkPath", zap.Error(err))
+			logger.Fatal("error creating fissionSymlinkPath", zap.Error(err))
 		}
 	}
-	go symlinkReaper(zapLogger)
+	go symlinkReaper(logger)
 	_, kubernetesClient, _, _, err := crd.MakeFissionClient()
 	if err != nil {
 		log.Fatalf("Error starting pod watcher: %v", err)
 	}
 	informerFactory := k8sInformers.NewSharedInformerFactory(kubernetesClient, time.Minute*30)
 	podInformer := informerFactory.Core().V1().Pods().Informer()
-	podInformer.AddEventHandler(podInformerHandlers(zapLogger))
+	podInformer.AddEventHandler(podInformerHandlers(logger))
 	podInformer.Run(make(chan struct{}))
-	zapLogger.Fatal("Stop watching pod changes")
+	logger.Fatal("Stop watching pod changes")
 }

pkg/utils/loggerfactory/loggerfactory.go

@@ -0,0 +1,38 @@
+/*
+Copyright 2021 The Fission Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package loggerfactory
+
+import (
+	"os"
+	"strconv"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	kzap "sigs.k8s.io/controller-runtime/pkg/log/zap"
+)
+
+func GetLogger() *zap.Logger {
+	encConfOpt := func(o *kzap.Options) {
+		encTimeFunc := func(encConfig *zapcore.EncoderConfig) {
+			encConfig.EncodeTime = zapcore.ISO8601TimeEncoder
+		}
+		o.EncoderConfigOptions = append(o.EncoderConfigOptions, encTimeFunc)
+		o.ZapOpts = append(o.ZapOpts, zap.AddCaller())
+	}
+	isDebugEnv, _ := strconv.ParseBool(os.Getenv("DEBUG_ENV"))
+	return kzap.NewRaw(kzap.UseDevMode(isDebugEnv), encConfOpt)
+}

pkg/utils/profile/profile.go

@@ -25,13 +25,11 @@ package profile
 
 import (
 	"fmt"
-	"log"
 	"net/http"
 	_ "net/http/pprof"
 	"os"
 
 	"go.uber.org/zap"
-	"go.uber.org/zap/zapcore"
 )
 
 func getPprofAddr() string {
@@ -46,7 +44,7 @@ func getPprofAddr() string {
 	return fmt.Sprintf("%s:%s", pprofHost, pprofPort)
 }
 
-func ProfileIfEnabled() {
+func ProfileIfEnabled(logger *zap.Logger) {
 	enablePprof := os.Getenv("PPROF_ENABLED")
 	if enablePprof != "true" {
 		return
@@ -55,18 +53,10 @@ func ProfileIfEnabled() {
 	pprofMux := http.DefaultServeMux
 	http.DefaultServeMux = http.NewServeMux()
 
-	config := zap.NewProductionConfig()
-	config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
-	logger, err := config.Build()
-	if err != nil {
-		log.Fatalf("can't initialize zap logger: %v", err)
-	}
-	defer logger.Sync()
-
 	addr := getPprofAddr()
 	logger.Info("Running pprof server", zap.String("addr", addr))
 	go func() {
-		err = http.ListenAndServe(addr, pprofMux)
+		err := http.ListenAndServe(addr, pprofMux)
 		if err != nil {
 			logger.Fatal("pprof http server failed", zap.Error(err))
 		}