implement zap for cni (#1933)

* feat: added logger package and replaced old log initialization for the new one

* feat: changed all log lines to new zap logger

* fix: typo

* Update azure-ipam/logger/logger.go

Co-authored-by: Timothy J. Raymond <[email protected]>

* fix: adding constants to describe logger rotations constraints

* Renamed logger New method

* Replaced logAndSend method by log 1st and send then so we can use zap fields

* minor fixes

* added logger init for tests

* replaced Any by Error

* gci ipam_test

* fixed govet errors

* moved component to a zap field

* fixed linit issues

* added log mock

* fix: gci

* fix: added context for logger teardown

* Update cni/log/logger.go

Co-authored-by: Evan Baker <[email protected]>

* moved logger init mock function

* fix: lint findings

---------

Co-authored-by: Esteban Capillo <[email protected]>
Co-authored-by: Timothy J. Raymond <[email protected]>
Co-authored-by: Evan Baker <[email protected]>

Author: 4 people

azure-ipam/logger/logger.go

@@ -12,10 +12,10 @@ const (
 )
 
 type Config struct {
-	Level           string // Debug by default
-	Filepath        string // default /var/log/azure-ipam.log
-	MaxSizeInMB     int    // MegaBytes
-	MaxBackups      int    // # of backups, no limitation by default
+	Level       string // Debug by default
+	Filepath    string // default /var/log/azure-ipam.log
+	MaxSizeInMB int    // MegaBytes
+	MaxBackups  int    // # of backups, no limitation by default
 }
 
 // NewLogger creates and returns a zap logger and a clean up function
@@ -34,13 +34,13 @@ func New(cfg *Config) (*zap.Logger, func(), error) {
 	return logger, cleanup, nil
 }
 
-// create and return a zap logger via lumbejack with rotation
-func newFileLogger(cfg *Config, logLevel zapcore.Level) (*zap.Logger) {
+// create and return a zap logger via lumberjack with rotation
+func newFileLogger(cfg *Config, logLevel zapcore.Level) *zap.Logger {
 	// define a lumberjack fileWriter
 	logFileWriter := zapcore.AddSync(&lumberjack.Logger{
-		Filename:    cfg.Filepath,
-		MaxSize:     cfg.MaxSizeInMB, // MegaBytes
-		MaxBackups:  cfg.MaxBackups,
+		Filename:   cfg.Filepath,
+		MaxSize:    cfg.MaxSizeInMB, // MegaBytes
+		MaxBackups: cfg.MaxBackups,
 	})
 	// define the log encoding
 	encoderConfig := zap.NewProductionEncoderConfig()

cni/api/api.go

@@ -5,7 +5,8 @@ import (
 	"net"
 	"os"
 
-	"github.com/Azure/azure-container-networking/log"
+	"github.com/Azure/azure-container-networking/cni/log"
+	"go.uber.org/zap"
 )
 
 type PodNetworkInterfaceInfo struct {
@@ -23,13 +24,13 @@ type AzureCNIState struct {
 func (a *AzureCNIState) PrintResult() error {
 	b, err := json.MarshalIndent(a, "", "    ")
 	if err != nil {
-		log.Errorf("Failed to unmarshall Azure CNI state, err:%v.\n", err)
+		log.Logger.Error("Failed to unmarshall Azure CNI state", zap.Error(err))
 	}
 
 	// write result to stdout to be captured by caller
 	_, err = os.Stdout.Write(b)
 	if err != nil {
-		log.Printf("Failed to write response to stdout %v", err)
+		log.Logger.Error("Failed to write response to stdout", zap.Error(err))
 		return err
 	}
 

cni/ipam/ipam.go

@@ -9,13 +9,14 @@ import (
 	"strconv"
 
 	"github.com/Azure/azure-container-networking/cni"
+	"github.com/Azure/azure-container-networking/cni/log"
 	"github.com/Azure/azure-container-networking/common"
 	"github.com/Azure/azure-container-networking/ipam"
-	"github.com/Azure/azure-container-networking/log"
 	"github.com/Azure/azure-container-networking/platform"
 	cniSkel "github.com/containernetworking/cni/pkg/skel"
 	cniTypes "github.com/containernetworking/cni/pkg/types"
 	cniTypesCurr "github.com/containernetworking/cni/pkg/types/100"
+	"go.uber.org/zap"
 )
 
 const ipamV6 = "azure-vnet-ipamv6"
@@ -61,22 +62,29 @@ func (plugin *ipamPlugin) Start(config *common.PluginConfig) error {
 	// Initialize base plugin.
 	err := plugin.Initialize(config)
 	if err != nil {
-		log.Printf("[cni-ipam] Failed to initialize base plugin, err:%v.", err)
+		log.Logger.Error("Failed to initialize base plugin.",
+			zap.Error(err), zap.String("component", "cni-ipam"))
 		return err
 	}
 
 	// Log platform information.
-	log.Printf("[cni-ipam] Plugin %v version %v.", plugin.Name, plugin.Version)
-	log.Printf("[cni-ipam] Running on %v", platform.GetOSInfo())
+	log.Logger.Info("Plugin version.", zap.String("name", plugin.Name),
+		zap.String("version", plugin.Version),
+		zap.String("component", "cni-ipam"))
+	log.Logger.Info("Running on",
+		zap.String("platform", platform.GetOSInfo()),
+		zap.String("component", "cni-ipam"))
 
 	// Initialize address manager. rehyrdration not required on reboot for cni ipam plugin
 	err = plugin.am.Initialize(config, false, plugin.Options)
 	if err != nil {
-		log.Printf("[cni-ipam] Failed to initialize address manager, err:%v.", err)
+		log.Logger.Error("Failed to initialize address manager",
+			zap.String("error", err.Error()),
+			zap.String("component", "cni-ipam"))
 		return err
 	}
 
-	log.Printf("[cni-ipam] Plugin started.")
+	log.Logger.Info("Plugin started", zap.String("component", "cni-ipam"))
 
 	return nil
 }
@@ -85,7 +93,7 @@ func (plugin *ipamPlugin) Start(config *common.PluginConfig) error {
 func (plugin *ipamPlugin) Stop() {
 	plugin.am.Uninitialize()
 	plugin.Uninitialize()
-	log.Printf("[cni-ipam] Plugin stopped.")
+	log.Logger.Info("Plugin stopped", zap.String("component", "cni-ipam"))
 }
 
 // Configure parses and applies the given network configuration.
@@ -96,7 +104,9 @@ func (plugin *ipamPlugin) Configure(stdinData []byte) (*cni.NetworkConfig, error
 		return nil, err
 	}
 
-	log.Printf("[cni-ipam] Read network configuration %+v.", nwCfg)
+	log.Logger.Info("Read network configuration",
+		zap.Any("config", nwCfg),
+		zap.String("component", "cni-ipam"))
 
 	// Apply IPAM configuration.
 
@@ -135,10 +145,21 @@ func (plugin *ipamPlugin) Add(args *cniSkel.CmdArgs) error {
 	var result *cniTypesCurr.Result
 	var err error
 
-	log.Printf("[cni-ipam] Processing ADD command with args {ContainerID:%v Netns:%v IfName:%v Args:%v Path:%v StdinData:%s}.",
-		args.ContainerID, args.Netns, args.IfName, args.Args, args.Path, args.StdinData)
+	log.Logger.Info("Processing ADD command",
+		zap.String("ContainerId", args.ContainerID),
+		zap.String("Netns", args.Netns),
+		zap.String("IfName", args.IfName),
+		zap.String("Args", args.Args),
+		zap.String("Path", args.Path),
+		zap.ByteString("StdinData", args.StdinData),
+		zap.String("component", "cni-ipam"))
 
-	defer func() { log.Printf("[cni-ipam] ADD command completed with result:%+v err:%v.", result, err) }()
+	defer func() {
+		log.Logger.Info("ADD command completed",
+			zap.Any("result", result),
+			zap.Any("error:", err),
+			zap.String("component", "cni-ipam"))
+	}()
 
 	// Parse network configuration from stdin.
 	nwCfg, err := plugin.Configure(args.StdinData)
@@ -174,13 +195,18 @@ func (plugin *ipamPlugin) Add(args *cniSkel.CmdArgs) error {
 		// On failure, release the address pool.
 		defer func() {
 			if err != nil && poolID != "" {
-				log.Printf("[cni-ipam] Releasing pool %v.", poolID)
+				log.Logger.Info("Releasing pool",
+					zap.String("poolId", poolID),
+					zap.String("component", "cni-ipam"))
 				_ = plugin.am.ReleasePool(nwCfg.IPAM.AddrSpace, poolID)
 			}
 		}()
 
 		nwCfg.IPAM.Subnet = subnet
-		log.Printf("[cni-ipam] Allocated address poolID %v with subnet %v.", poolID, subnet)
+		log.Logger.Info("Allocated address with subnet",
+			zap.String("poolId", poolID),
+			zap.String("subnet", subnet),
+			zap.String("component", "cni-ipam"))
 	}
 
 	// Allocate an address for the endpoint.
@@ -193,12 +219,16 @@ func (plugin *ipamPlugin) Add(args *cniSkel.CmdArgs) error {
 	// On failure, release the address.
 	defer func() {
 		if err != nil && address != "" {
-			log.Printf("[cni-ipam] Releasing address %v.", address)
+			log.Logger.Info("Releasing address",
+				zap.String("address", address),
+				zap.String("component", "cni-ipam"))
 			_ = plugin.am.ReleaseAddress(nwCfg.IPAM.AddrSpace, nwCfg.IPAM.Subnet, address, options)
 		}
 	}()
 
-	log.Printf("[cni-ipam] Allocated address %v.", address)
+	log.Logger.Info("Allocated address",
+		zap.String("address", address),
+		zap.String("component", "cni-ipam"))
 
 	// Parse IP address.
 	ipAddress, err := platform.ConvertStringToIPNet(address)
@@ -263,10 +293,18 @@ func (plugin *ipamPlugin) Get(args *cniSkel.CmdArgs) error {
 func (plugin *ipamPlugin) Delete(args *cniSkel.CmdArgs) error {
 	var err error
 
-	log.Printf("[cni-ipam] Processing DEL command with args {ContainerID:%v Netns:%v IfName:%v Args:%v Path:%v StdinData:%s}.",
-		args.ContainerID, args.Netns, args.IfName, args.Args, args.Path, args.StdinData)
+	log.Logger.Info("[cni-ipam] Processing DEL command",
+		zap.String("ContainerId", args.ContainerID),
+		zap.String("Netns", args.Netns),
+		zap.String("IfName", args.IfName),
+		zap.String("Args", args.Args),
+		zap.String("Path", args.Path),
+		zap.ByteString("StdinData", args.StdinData))
 
-	defer func() { log.Printf("[cni-ipam] DEL command completed with err:%v.", err) }()
+	defer func() {
+		log.Logger.Info("[cni-ipam] DEL command completed",
+			zap.Error(err))
+	}()
 
 	// Parse network configuration from stdin.
 	nwCfg, err := plugin.Configure(args.StdinData)

cni/ipam/ipam_test.go

@@ -12,13 +12,13 @@ import (
 	"testing"
 	"time"
 
+	"github.com/Azure/azure-container-networking/cni/log"
+	"github.com/Azure/azure-container-networking/common"
 	cniSkel "github.com/containernetworking/cni/pkg/skel"
 	cniTypesCurr "github.com/containernetworking/cni/pkg/types/100"
 	"github.com/google/uuid"
 	. "github.com/onsi/ginkgo"
 	. "github.com/onsi/gomega"
-
-	"github.com/Azure/azure-container-networking/common"
 )
 
 var (
@@ -97,6 +97,8 @@ var (
 		Expect(err).NotTo(HaveOccurred())
 
 		arg = &cniSkel.CmdArgs{}
+
+		log.InitializeMock()
 	})
 
 	_ = AfterSuite(func() {

cni/ipam/plugin/main.go

@@ -4,36 +4,40 @@
 package main
 
 import (
+	"context"
 	"fmt"
 	"os"
 
 	"github.com/Azure/azure-container-networking/cni"
 	"github.com/Azure/azure-container-networking/cni/ipam"
+	"github.com/Azure/azure-container-networking/cni/log"
 	"github.com/Azure/azure-container-networking/common"
-	"github.com/Azure/azure-container-networking/log"
+	"go.uber.org/zap/zapcore"
 )
 
 const (
-	name = "azure-vnet-ipam"
+	name               = "azure-vnet-ipam"
+	maxLogFileSizeInMb = 5
+	maxLogFileCount    = 8
 )
 
 // Version is populated by make during build.
 var version string
 
 // Main is the entry point for CNI IPAM plugin.
 func main() {
+	ctx, cancel := context.WithCancel(context.Background())
 	var config common.PluginConfig
 	config.Version = version
-	logDirectory := "" // Sets the current location as log directory
 
-	log.SetName(name)
-	log.SetLevel(log.LevelInfo)
-	if err := log.SetTargetLogDirectory(log.TargetLogfile, logDirectory); err != nil {
-		fmt.Printf("Failed to setup cni logging: %v\n", err)
-		return
+	loggerCfg := &log.Config{
+		Level:       zapcore.DebugLevel,
+		LogPath:     log.LogPath + "azure-ipam.log",
+		MaxSizeInMB: maxLogFileSizeInMb,
+		MaxBackups:  maxLogFileCount,
+		Name:        name,
 	}
-
-	defer log.Close()
+	log.Initialize(ctx, loggerCfg)
 
 	ipamPlugin, err := ipam.NewPlugin(name, &config)
 	if err != nil {
@@ -65,6 +69,7 @@ func main() {
 	err = ipamPlugin.Execute(cni.PluginApi(ipamPlugin))
 
 	ipamPlugin.Stop()
+	cancel()
 
 	if err != nil {
 		panic("ipam plugin fatal error")

cni/ipam/pluginv6/main.go

@@ -4,36 +4,40 @@
 package main
 
 import (
+	"context"
 	"fmt"
 	"os"
 
 	"github.com/Azure/azure-container-networking/cni"
 	"github.com/Azure/azure-container-networking/cni/ipam"
+	"github.com/Azure/azure-container-networking/cni/log"
 	"github.com/Azure/azure-container-networking/common"
-	"github.com/Azure/azure-container-networking/log"
+	"go.uber.org/zap/zapcore"
 )
 
 const (
-	name = "azure-vnet-ipamv6"
+	name               = "azure-vnet-ipamv6"
+	maxLogFileSizeInMb = 5
+	maxLogFileCount    = 8
 )
 
 // Version is populated by make during build.
 var version string
 
 // Main is the entry point for CNI IPAM plugin.
 func main() {
+	ctx, cancel := context.WithCancel(context.Background())
 	var config common.PluginConfig
 	config.Version = version
-	logDirectory := "" // Sets the current location as log directory
 
-	log.SetName(name)
-	log.SetLevel(log.LevelInfo)
-	if err := log.SetTargetLogDirectory(log.TargetLogfile, logDirectory); err != nil {
-		fmt.Printf("Failed to setup cni logging: %v\n", err)
-		return
+	loggerCfg := &log.Config{
+		Level:       zapcore.DebugLevel,
+		LogPath:     log.LogPath + "azure-ipam.log",
+		MaxSizeInMB: maxLogFileSizeInMb,
+		MaxBackups:  maxLogFileCount,
+		Name:        name,
 	}
-
-	defer log.Close()
+	log.Initialize(ctx, loggerCfg)
 
 	ipamPlugin, err := ipam.NewPlugin(name, &config)
 	if err != nil {
@@ -65,6 +69,7 @@ func main() {
 	err = ipamPlugin.Execute(cni.PluginApi(ipamPlugin))
 
 	ipamPlugin.Stop()
+	cancel()
 
 	if err != nil {
 		panic("ipam plugin fatal error")