From 4c789705ecefbce10a0833f2be840962135d1f0e Mon Sep 17 00:00:00 2001 From: Chiranjeewee Koirala Date: Wed, 31 Jul 2024 17:45:49 -0400 Subject: [PATCH] Use zap logger through the components and support zap logger level configuration through environment variable (#33) * Use zap logger through the components and support zap logger level configuration through environment variable --- service/cmd/main.go | 36 ++++----- service/go.mod | 2 +- service/logging/logging.go | 76 +++++++++++++++++++ .../controller/controller.go | 30 ++++---- .../controller/tratconfigcontroller.go | 6 +- .../controller/tratcontroller.go | 6 +- service/tratteriacontroller/setup.go | 18 ++--- service/websocketserver/clientmanager.go | 2 - 8 files changed, 122 insertions(+), 54 deletions(-) create mode 100644 service/logging/logging.go diff --git a/service/cmd/main.go b/service/cmd/main.go index 8077981..c8965a5 100644 --- a/service/cmd/main.go +++ b/service/cmd/main.go @@ -3,7 +3,6 @@ package main import ( "context" "fmt" - "log" "os" "os/signal" "syscall" @@ -12,6 +11,7 @@ import ( "github.com/spiffe/go-spiffe/v2/spiffeid" "github.com/spiffe/go-spiffe/v2/workloadapi" "github.com/tratteria/tconfigd/config" + "github.com/tratteria/tconfigd/logging" "github.com/tratteria/tconfigd/spiffe" "github.com/tratteria/tconfigd/tratteriacontroller" "github.com/tratteria/tconfigd/webhook" @@ -27,26 +27,22 @@ func main() { setupSignalHandler(cancel) - logger, err := zap.NewProduction() - if err != nil { - log.Fatalf("Cannot initialize Zap logger: %v.", err) + if err := logging.InitLogger(); err != nil { + panic(err) } + defer logging.Sync() - defer func() { - if err := logger.Sync(); err != nil { - log.Printf("Error syncing logger: %v", err) - } - }() + mainLogger := logging.GetLogger("main") if len(os.Args) < 2 { - logger.Fatal(fmt.Sprintf("No configuration file provided. Please specify the configuration path as an argument when running the service.\nUsage: %s ", os.Args[0])) + mainLogger.Fatal(fmt.Sprintf("No configuration file provided. Please specify the configuration path as an argument when running the service.\nUsage: %s ", os.Args[0])) } configPath := os.Args[1] config, err := config.GetConfig(configPath) if err != nil { - logger.Fatal("Error reading configuration.", zap.Error(err)) + mainLogger.Fatal("Error reading configuration.", zap.Error(err)) } x509SrcCtx, cancel := context.WithTimeout(context.Background(), X509_SOURCE_TIMEOUT) @@ -54,29 +50,29 @@ func main() { x509Source, err := workloadapi.NewX509Source(x509SrcCtx) if err != nil { - logger.Fatal("Failed to create X.509 source", zap.Error(err)) + mainLogger.Fatal("Failed to create X.509 source", zap.Error(err)) } defer x509Source.Close() tconfigdSpiffeId, err := spiffe.FetchSpiffeIdFromX509(x509Source) if err != nil { - logger.Fatal("Error getting tconfigd spiffe id.", zap.Error(err)) + mainLogger.Fatal("Error getting tconfigd spiffe id.", zap.Error(err)) } - tratteriaController := tratteriacontroller.NewTratteriaController() + tratteriaController := tratteriacontroller.NewTratteriaController(logging.GetLogger("controller")) if err := tratteriaController.Run(); err != nil { - logger.Fatal("Failed to start TraT Controller server.", zap.Error(err)) + mainLogger.Fatal("Failed to start TraT Controller server.", zap.Error(err)) } - webSocketServer := websocketserver.NewWebSocketServer(tratteriaController.Controller, x509Source, spiffeid.ID(config.TratteriaSpiffeId), logger) + webSocketServer := websocketserver.NewWebSocketServer(tratteriaController.Controller, x509Source, spiffeid.ID(config.TratteriaSpiffeId), logging.GetLogger("websocket-server")) tratteriaController.SetClientsRetriever(webSocketServer) go func() { if err := webSocketServer.Run(); err != nil { - logger.Fatal("Failed to start websocket server.", zap.Error(err)) + mainLogger.Fatal("Failed to start websocket server.", zap.Error(err)) } }() @@ -87,17 +83,17 @@ func main() { AgentInterceptorPort: int(config.AgentInterceptorPort), SpireAgentHostDir: config.SpireAgentHostDir, TconfigdSpiffeId: tconfigdSpiffeId, - Logger: logger, + Logger: logging.GetLogger("webhook"), } if err := webhook.Run(); err != nil { - logger.Fatal("Failed to start Webhook server.", zap.Error(err)) + mainLogger.Fatal("Failed to start Webhook server.", zap.Error(err)) } }() <-ctx.Done() - logger.Info("Shutting down tconfigd...") + mainLogger.Info("Shutting down tconfigd...") } func setupSignalHandler(cancel context.CancelFunc) { diff --git a/service/go.mod b/service/go.mod index 156afd9..2d7b252 100644 --- a/service/go.mod +++ b/service/go.mod @@ -17,7 +17,6 @@ require ( k8s.io/apimachinery v0.0.0-20240620180412-04fe5186a7b1 k8s.io/client-go v0.0.0-20240620181025-b9309ac26b16 k8s.io/code-generator v0.0.0-20240620181745-569cc2f167a3 - k8s.io/klog/v2 v2.130.1 ) require ( @@ -70,6 +69,7 @@ require ( gopkg.in/inf.v0 v0.9.1 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect k8s.io/gengo/v2 v2.0.0-20240228010128-51d4e06bde70 // indirect + k8s.io/klog/v2 v2.130.1 // indirect k8s.io/kube-openapi v0.0.0-20240228011516-70dd3763d340 // indirect k8s.io/utils v0.0.0-20230726121419-3b25d923346b // indirect sigs.k8s.io/json v0.0.0-20221116044647-bc3834ca7abd // indirect diff --git a/service/logging/logging.go b/service/logging/logging.go new file mode 100644 index 0000000..9e96475 --- /dev/null +++ b/service/logging/logging.go @@ -0,0 +1,76 @@ +package logging + +import ( + "os" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +var globalLogger *zap.Logger + +func InitLogger() error { + logLevel := os.Getenv("LOG_LEVEL") + if logLevel == "" { + logLevel = "info" + } + + config := zap.Config{ + Encoding: "json", + Level: zap.NewAtomicLevelAt(getLogLevel(logLevel)), + OutputPaths: []string{"stdout"}, + ErrorOutputPaths: []string{"stderr"}, + EncoderConfig: zapcore.EncoderConfig{ + TimeKey: "timestamp", + LevelKey: "level", + NameKey: "logger", + CallerKey: "caller", + FunctionKey: zapcore.OmitKey, + MessageKey: "message", + StacktraceKey: "stacktrace", + LineEnding: zapcore.DefaultLineEnding, + EncodeLevel: zapcore.LowercaseLevelEncoder, + EncodeTime: zapcore.ISO8601TimeEncoder, + EncodeDuration: zapcore.SecondsDurationEncoder, + EncodeCaller: zapcore.ShortCallerEncoder, + }, + } + + logger, err := config.Build() + if err != nil { + return err + } + + globalLogger = logger + + return nil +} + +func GetLogger(component string) *zap.Logger { + if globalLogger == nil { + InitLogger() + } + + return globalLogger.Named(component) +} + +func getLogLevel(level string) zapcore.Level { + switch level { + case "debug": + return zapcore.DebugLevel + case "info": + return zapcore.InfoLevel + case "warn": + return zapcore.WarnLevel + case "error": + return zapcore.ErrorLevel + default: + return zapcore.InfoLevel + } +} + +func Sync() { + if globalLogger != nil { + globalLogger.Sync() + } +} diff --git a/service/tratteriacontroller/controller/controller.go b/service/tratteriacontroller/controller/controller.go index e6b94c7..b79aad8 100644 --- a/service/tratteriacontroller/controller/controller.go +++ b/service/tratteriacontroller/controller/controller.go @@ -9,6 +9,7 @@ import ( "sync/atomic" "time" + "go.uber.org/zap" "golang.org/x/time/rate" "github.com/tratteria/tconfigd/common" @@ -23,7 +24,6 @@ import ( "k8s.io/client-go/tools/cache" "k8s.io/client-go/tools/record" "k8s.io/client-go/util/workqueue" - "k8s.io/klog/v2" tratteria1alpha1 "github.com/tratteria/tconfigd/tratteriacontroller/pkg/apis/tratteria/v1alpha1" clientset "github.com/tratteria/tconfigd/tratteriacontroller/pkg/generated/clientset/versioned" @@ -92,6 +92,7 @@ type Controller struct { ruleDispatcher *ruledispatcher.RuleDispatcher ruleVersionNumber int64 allRulesHashes *AllRulesHashes + logger *zap.Logger } func NewController( @@ -100,12 +101,12 @@ func NewController( tratteriaclientset clientset.Interface, traTInformer informers.TraTInformer, tratteriaConfigInformer informers.TratteriaConfigInformer, - ruleDispatcher *ruledispatcher.RuleDispatcher) *Controller { - logger := klog.FromContext(ctx) + ruleDispatcher *ruledispatcher.RuleDispatcher, + logger *zap.Logger) *Controller { utilruntime.Must(tratteriascheme.AddToScheme(scheme.Scheme)) - logger.V(4).Info("Creating event broadcaster") + logger.Info("Creating event broadcaster") eventBroadcaster := record.NewBroadcaster(record.WithContext(ctx)) @@ -130,6 +131,7 @@ func NewController( ruleDispatcher: ruleDispatcher, ruleVersionNumber: 0, allRulesHashes: NewAllRulesHashes(), + logger: logger, } logger.Info("Setting up event handlers") @@ -177,32 +179,33 @@ func (c *Controller) enqueueObject(obj interface{}, versionNumber int64) { c.workqueue.Add(fmt.Sprintf("%s/%s/%d", resourceType, key, versionNumber)) - klog.V(4).Infof("Enqueued %s '%s' with new rule version %d", resourceType, key, versionNumber) + c.logger.Info("Enqueued resource with new rule version.", + zap.String("resource-type", resourceType), + zap.String("key", key), + zap.Int64("version-number", versionNumber)) } func (c *Controller) Run(ctx context.Context, workers int) error { defer utilruntime.HandleCrash() defer c.workqueue.ShutDown() - logger := klog.FromContext(ctx) + c.logger.Info("Starting TraT controller") - logger.Info("Starting TraT controller") - - logger.Info("Waiting for informer caches to sync") + c.logger.Info("Waiting for informer caches to sync") if ok := cache.WaitForCacheSync(ctx.Done(), c.traTsSynced); !ok { return fmt.Errorf("failed to wait for caches to sync") } - logger.Info("Starting workers", "count", workers) + c.logger.Info("Starting workers", zap.Int("count", workers)) for i := 0; i < workers; i++ { go wait.UntilWithContext(ctx, c.runWorker, time.Second) } - logger.Info("Started workers") + c.logger.Info("Started workers") <-ctx.Done() - logger.Info("Shutting down workers") + c.logger.Info("Shutting down workers") return nil } @@ -214,7 +217,6 @@ func (c *Controller) runWorker(ctx context.Context) { func (c *Controller) processNextWorkItem(ctx context.Context) bool { obj, shutdown := c.workqueue.Get() - logger := klog.FromContext(ctx) if shutdown { return false @@ -231,7 +233,7 @@ func (c *Controller) processNextWorkItem(ctx context.Context) bool { c.workqueue.Forget(obj) - logger.Info("Successfully applied", "resourceName", obj) + c.logger.Info("Successfully applied.", zap.String("resourceName", obj)) return nil }() diff --git a/service/tratteriacontroller/controller/tratconfigcontroller.go b/service/tratteriacontroller/controller/tratconfigcontroller.go index d4c7929..bb7db7e 100644 --- a/service/tratteriacontroller/controller/tratconfigcontroller.go +++ b/service/tratteriacontroller/controller/tratconfigcontroller.go @@ -4,13 +4,13 @@ import ( "context" "fmt" + "go.uber.org/zap" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/labels" utilruntime "k8s.io/apimachinery/pkg/util/runtime" "k8s.io/client-go/tools/cache" - "k8s.io/klog/v2" tratteria1alpha1 "github.com/tratteria/tconfigd/tratteriacontroller/pkg/apis/tratteria/v1alpha1" ) @@ -132,7 +132,7 @@ func (c *Controller) updateSuccessTratteriaConfigStatus(ctx context.Context, tra func (c *Controller) GetActiveTratteriaConfigVerificationRule(namespace string) (*tratteria1alpha1.TratteriaConfigVerificationRule, error) { tratteriaConfigs, err := c.tratteriaConfigsLister.TratteriaConfigs(namespace).List(labels.Everything()) if err != nil { - klog.Error("Failed to list TratteriaConfigs in namespace:", namespace, err) + c.logger.Error("Failed to list TratteriaConfigs in namespace.", zap.String("namespace", namespace), zap.Error(err)) return nil, err } @@ -152,7 +152,7 @@ func (c *Controller) GetActiveTratteriaConfigVerificationRule(namespace string) func (c *Controller) GetActiveGenerationTokenRule(namespace string) (*tratteria1alpha1.TratteriaConfigGenerationRule, error) { tratteriaConfigs, err := c.tratteriaConfigsLister.TratteriaConfigs(namespace).List(labels.Everything()) if err != nil { - klog.Error("Failed to list TratteriaConfigs in namespace:", namespace, err) + c.logger.Error("Failed to list TratteriaConfigs in namespace.", zap.String("namespace", namespace), zap.Error(err)) return nil, err } diff --git a/service/tratteriacontroller/controller/tratcontroller.go b/service/tratteriacontroller/controller/tratcontroller.go index e2dd4ef..5a1e489 100644 --- a/service/tratteriacontroller/controller/tratcontroller.go +++ b/service/tratteriacontroller/controller/tratcontroller.go @@ -4,13 +4,13 @@ import ( "context" "fmt" + "go.uber.org/zap" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/labels" utilruntime "k8s.io/apimachinery/pkg/util/runtime" "k8s.io/client-go/tools/cache" - "k8s.io/klog/v2" tratteria1alpha1 "github.com/tratteria/tconfigd/tratteriacontroller/pkg/apis/tratteria/v1alpha1" ) @@ -135,7 +135,7 @@ func (c *Controller) updateSuccessTratStatus(ctx context.Context, trat *tratteri func (c *Controller) GetActiveTraTVerificationRules(serviceName string, namespace string) ([]*tratteria1alpha1.TraTVerificationRule, error) { traTs, err := c.traTsLister.TraTs(namespace).List(labels.Everything()) if err != nil { - klog.Error("Failed to list TraTs in namespace:", namespace, err) + c.logger.Error("Failed to list TraTs in namespace.", zap.String("namespace", namespace), zap.Error(err)) return nil, err } @@ -158,7 +158,7 @@ func (c *Controller) GetActiveTraTVerificationRules(serviceName string, namespac func (c *Controller) GetActiveGenerationEndpointRules(namespace string) ([]*tratteria1alpha1.TraTGenerationRule, error) { traTs, err := c.traTsLister.TraTs(namespace).List(labels.Everything()) if err != nil { - klog.Error("Failed to list TraTs in namespace:", namespace, err) + c.logger.Error("Failed to list TraTs in namespace.", zap.String("namespace", namespace), zap.Error(err)) return nil, err } diff --git a/service/tratteriacontroller/setup.go b/service/tratteriacontroller/setup.go index 7f3b9ad..b9b4fa0 100644 --- a/service/tratteriacontroller/setup.go +++ b/service/tratteriacontroller/setup.go @@ -1,17 +1,16 @@ package tratteriacontroller import ( - "flag" "fmt" "time" "github.com/tratteria/tconfigd/ruledispatcher" + "go.uber.org/zap" "github.com/tratteria/tconfigd/tratteriacontroller/pkg/signals" "github.com/tratteria/tconfigd/websocketserver" "k8s.io/client-go/kubernetes" "k8s.io/client-go/rest" - "k8s.io/klog/v2" "github.com/tratteria/tconfigd/tratteriacontroller/controller" clientset "github.com/tratteria/tconfigd/tratteriacontroller/pkg/generated/clientset/versioned" @@ -21,11 +20,13 @@ import ( type TratteriaController struct { RuleDispatcher *ruledispatcher.RuleDispatcher Controller *controller.Controller + Logger *zap.Logger } -func NewTratteriaController() *TratteriaController { +func NewTratteriaController(logger *zap.Logger) *TratteriaController { return &TratteriaController{ RuleDispatcher: ruledispatcher.NewRuleDispatcher(), + Logger: logger, } } @@ -34,11 +35,6 @@ func (tc *TratteriaController) SetClientsRetriever(clientsRetriever websocketser } func (tc *TratteriaController) Run() error { - klog.InitFlags(nil) - defer klog.Flush() - - flag.Parse() - ctx := signals.SetupSignalHandler() cfg, err := rest.InClusterConfig() @@ -60,15 +56,15 @@ func (tc *TratteriaController) Run() error { tratInformer := tratteriaInformerFactory.Tratteria().V1alpha1().TraTs() tratteriaConfigInformer := tratteriaInformerFactory.Tratteria().V1alpha1().TratteriaConfigs() - tc.Controller = controller.NewController(ctx, kubeClient, tratteriaClient, tratInformer, tratteriaConfigInformer, tc.RuleDispatcher) + tc.Controller = controller.NewController(ctx, kubeClient, tratteriaClient, tratInformer, tratteriaConfigInformer, tc.RuleDispatcher, tc.Logger) go func() { - klog.Info("Starting TraT Controller...") + tc.Logger.Info("Starting TraT Controller...") tratteriaInformerFactory.Start(ctx.Done()) if err := tc.Controller.Run(ctx, 2); err != nil { - klog.Errorf("error running controller: %v", err) + tc.Logger.Error("Error running controller.", zap.Error(err)) } }() diff --git a/service/websocketserver/clientmanager.go b/service/websocketserver/clientmanager.go index 8b8f855..748d87d 100644 --- a/service/websocketserver/clientmanager.go +++ b/service/websocketserver/clientmanager.go @@ -184,8 +184,6 @@ func (cm *ClientManager) compareAndReconcileRule(appData string) { lateshHash, activeRuleVersionNumber, _ = cm.Server.ruleRetriever.GetActiveVerificationRulesHash(cm.Service, cm.Namespace) } - cm.Server.Logger.Info("Central and remote hash", zap.String("central", lateshHash), zap.String("remote", pingData.RuleHash)) - if lateshHash != pingData.RuleHash { cm.Server.Logger.Warn("Received ping with incorrect rule hash, triggering reconciliation...", zap.String("service", cm.Service),