diff --git a/azure-ipam/logger/logger.go b/azure-ipam/logger/logger.go index 5ddaf1bed2..02b92523df 100644 --- a/azure-ipam/logger/logger.go +++ b/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() diff --git a/cni/api/api.go b/cni/api/api.go index 63d4d07b21..8c9f15e4eb 100644 --- a/cni/api/api.go +++ b/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 } diff --git a/cni/ipam/ipam.go b/cni/ipam/ipam.go index 35c6160311..b0fe1d2c57 100644 --- a/cni/ipam/ipam.go +++ b/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) diff --git a/cni/ipam/ipam_test.go b/cni/ipam/ipam_test.go index a6b14c8271..577865c649 100644 --- a/cni/ipam/ipam_test.go +++ b/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() { diff --git a/cni/ipam/plugin/main.go b/cni/ipam/plugin/main.go index e4e7812bb2..c6061150cb 100644 --- a/cni/ipam/plugin/main.go +++ b/cni/ipam/plugin/main.go @@ -4,17 +4,21 @@ 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. @@ -22,18 +26,18 @@ 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") diff --git a/cni/ipam/pluginv6/main.go b/cni/ipam/pluginv6/main.go index f206498ce7..2653a4a06f 100644 --- a/cni/ipam/pluginv6/main.go +++ b/cni/ipam/pluginv6/main.go @@ -4,17 +4,21 @@ 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. @@ -22,18 +26,18 @@ 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") diff --git a/cni/log/logger.go b/cni/log/logger.go new file mode 100644 index 0000000000..8cb79ee712 --- /dev/null +++ b/cni/log/logger.go @@ -0,0 +1,51 @@ +package log + +import ( + "context" + "fmt" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "gopkg.in/natefinch/lumberjack.v2" +) + +type Config struct { + Level zapcore.Level + LogPath string + MaxSizeInMB int + MaxBackups int + Name string +} + +var Logger *zap.Logger + +// Initializes a Zap logger and returns a cleanup function so logger can be cleaned up from caller +func Initialize(ctx context.Context, cfg *Config) { + Logger = newFileLogger(cfg) + + go func() { + <-ctx.Done() + err := Logger.Sync() + if err != nil { + fmt.Println("failed to sync logger") + } + }() +} + +func newFileLogger(cfg *Config) *zap.Logger { + logFileWriter := zapcore.AddSync(&lumberjack.Logger{ + Filename: cfg.LogPath, + MaxSize: cfg.MaxSizeInMB, + MaxBackups: cfg.MaxBackups, + }) + + encoderConfig := zap.NewProductionEncoderConfig() + encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder + jsonEncoder := zapcore.NewJSONEncoder(encoderConfig) + logLevel := cfg.Level + + core := zapcore.NewCore(jsonEncoder, logFileWriter, logLevel) + Logger = zap.New(core) + + return Logger.Named(cfg.Name) +} diff --git a/cni/log/logger_linux.go b/cni/log/logger_linux.go new file mode 100644 index 0000000000..123c0fa0cd --- /dev/null +++ b/cni/log/logger_linux.go @@ -0,0 +1,6 @@ +package log + +const ( + // LogPath is the path where log files are stored. + LogPath = "/var/log/" +) diff --git a/cni/log/logger_mock.go b/cni/log/logger_mock.go new file mode 100644 index 0000000000..d547db865d --- /dev/null +++ b/cni/log/logger_mock.go @@ -0,0 +1,7 @@ +package log + +import "go.uber.org/zap" + +func InitializeMock() { + Logger = zap.NewNop() +} diff --git a/cni/log/logger_windows.go b/cni/log/logger_windows.go new file mode 100644 index 0000000000..207b740037 --- /dev/null +++ b/cni/log/logger_windows.go @@ -0,0 +1,6 @@ +package log + +const ( + // LogPath is the path where log files are stored. + LogPath = "" +) diff --git a/cni/network/invoker_azure.go b/cni/network/invoker_azure.go index 360aab0f76..e0f653a993 100644 --- a/cni/network/invoker_azure.go +++ b/cni/network/invoker_azure.go @@ -8,14 +8,15 @@ import ( "strings" "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/network" "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 ( @@ -103,7 +104,9 @@ func (invoker *AzureIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, er func (invoker *AzureIPAMInvoker) deleteIpamState() { cniStateExists, err := platform.CheckIfFileExists(platform.CNIStateFilePath) if err != nil { - log.Printf("[cni] Error checking CNI state exist: %v", err) + log.Logger.Error("Error checking CNI state exist", + zap.Error(err), + zap.String("component", "cni")) return } @@ -113,15 +116,15 @@ func (invoker *AzureIPAMInvoker) deleteIpamState() { ipamStateExists, err := platform.CheckIfFileExists(platform.CNIIpamStatePath) if err != nil { - log.Printf("[cni] Error checking IPAM state exist: %v", err) + log.Logger.Error("Error checking IPAM state exist", zap.Error(err), zap.String("component", "cni")) return } if ipamStateExists { - log.Printf("[cni] Deleting IPAM state file") + log.Logger.Info("Deleting IPAM state file", zap.String("component", "cni")) err = os.Remove(platform.CNIIpamStatePath) if err != nil { - log.Printf("[cni] Error deleting state file %v", err) + log.Logger.Error("Error deleting state file", zap.Error(err), zap.String("component", "cni")) return } } @@ -142,10 +145,12 @@ func (invoker *AzureIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkCo } } else if len(address.IP.To4()) == bytesSize4 { //nolint:gocritic nwCfg.IPAM.Address = address.IP.String() - log.Printf("Releasing ipv4 address :%s pool: %s", nwCfg.IPAM.Address, nwCfg.IPAM.Subnet) + log.Logger.Info("Releasing ipv4", + zap.String("address", nwCfg.IPAM.Address), + zap.String("pool", nwCfg.IPAM.Subnet)) if err := invoker.plugin.DelegateDel(nwCfg.IPAM.Type, nwCfg); err != nil { - log.Printf("Failed to release ipv4 address: %v", err) - return invoker.plugin.Errorf("Failed to release ipv4 address: %v with error: ", nwCfg.IPAM.Address, err) + log.Logger.Error("Failed to release ipv4 address", zap.Error(err)) + return invoker.plugin.Errorf("Failed to release ipv4 address: %v", err) } } else if len(address.IP.To16()) == bytesSize16 { nwCfgIpv6 := *nwCfg @@ -161,9 +166,11 @@ func (invoker *AzureIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkCo } } - log.Printf("Releasing ipv6 address :%s pool: %s", nwCfgIpv6.IPAM.Address, nwCfgIpv6.IPAM.Subnet) + log.Logger.Info("Releasing ipv6", + zap.String("address", nwCfgIpv6.IPAM.Address), + zap.String("pool", nwCfgIpv6.IPAM.Subnet)) if err := invoker.plugin.DelegateDel(nwCfgIpv6.IPAM.Type, &nwCfgIpv6); err != nil { - log.Printf("Failed to release ipv6 address: %v", err) + log.Logger.Error("Failed to release ipv6 address", zap.Error(err)) return invoker.plugin.Errorf("Failed to release ipv6 address: %v", err) } } else { diff --git a/cni/network/invoker_azure_test.go b/cni/network/invoker_azure_test.go index 68d96a4b66..ad9e76b76d 100644 --- a/cni/network/invoker_azure_test.go +++ b/cni/network/invoker_azure_test.go @@ -7,6 +7,7 @@ import ( "testing" "github.com/Azure/azure-container-networking/cni" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/ipam" "github.com/Azure/azure-container-networking/network" cniSkel "github.com/containernetworking/cni/pkg/skel" @@ -207,6 +208,9 @@ func TestAzureIPAMInvoker_Add(t *testing.T) { wantErr: true, }, } + + log.InitializeMock() + for _, tt := range tests { tt := tt t.Run(tt.name, func(t *testing.T) { diff --git a/cni/network/invoker_cns.go b/cni/network/invoker_cns.go index e2a7bdf474..1734b09749 100644 --- a/cni/network/invoker_cns.go +++ b/cni/network/invoker_cns.go @@ -7,17 +7,18 @@ import ( "net" "github.com/Azure/azure-container-networking/cni" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cni/util" "github.com/Azure/azure-container-networking/cns" cnscli "github.com/Azure/azure-container-networking/cns/client" "github.com/Azure/azure-container-networking/iptables" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/network" "github.com/Azure/azure-container-networking/network/networkutils" cniSkel "github.com/containernetworking/cni/pkg/skel" cniTypes "github.com/containernetworking/cni/pkg/types" cniTypesCurr "github.com/containernetworking/cni/pkg/types/100" "github.com/pkg/errors" + "go.uber.org/zap" ) var ( @@ -62,7 +63,7 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro PodNamespace: invoker.podNamespace, } - log.Printf(podInfo.PodName) + log.Logger.Info(podInfo.PodName) orchestratorContext, err := json.Marshal(podInfo) if err != nil { return IPAMAddResult{}, errors.Wrap(err, "Failed to unmarshal orchestrator context during add: %w") @@ -78,12 +79,15 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro InfraContainerID: addConfig.args.ContainerID, } - log.Printf("Requesting IP for pod %+v using ipconfigs %+v", podInfo, ipconfigs) + log.Logger.Info("Requesting IP for pod using ipconfig", + zap.Any("pod", podInfo), + zap.Any("ipconfig", ipconfigs)) response, err := invoker.cnsClient.RequestIPs(context.TODO(), ipconfigs) if err != nil { if cnscli.IsUnsupportedAPI(err) { // If RequestIPs is not supported by CNS, use RequestIPAddress API - log.Errorf("RequestIPs not supported by CNS. Invoking RequestIPAddress API with infracontainerid %s", ipconfigs.InfraContainerID) + log.Logger.Error("RequestIPs not supported by CNS. Invoking RequestIPAddress API", + zap.Any("infracontainerid", ipconfigs.InfraContainerID)) ipconfig := cns.IPConfigRequest{ OrchestratorContext: orchestratorContext, PodInterfaceID: GetEndpointID(addConfig.args), @@ -93,7 +97,9 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro res, errRequestIP := invoker.cnsClient.RequestIPAddress(context.TODO(), ipconfig) if errRequestIP != nil { // if the old API fails as well then we just return the error - log.Errorf("Failed to request IP address from CNS using RequestIPAddress with infracontainerid %s. error: %v", ipconfig.InfraContainerID, errRequestIP) + log.Logger.Error("Failed to request IP address from CNS using RequestIPAddress", + zap.Any("infracontainerid", ipconfig.InfraContainerID), + zap.Error(errRequestIP)) return IPAMAddResult{}, errors.Wrap(errRequestIP, "Failed to get IP address from CNS") } response = &cns.IPConfigsResponse{ @@ -103,7 +109,9 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro }, } } else { - log.Printf("Failed to get IP address from CNS with error %v, response: %v", err, response) + log.Logger.Info("Failed to get IP address from CNS", + zap.Error(err), + zap.Any("response", response)) return IPAMAddResult{}, errors.Wrap(err, "Failed to get IP address from CNS") } } @@ -127,7 +135,10 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro addConfig.options[network.SNATIPKey] = info.ncPrimaryIP } - log.Printf("[cni-invoker-cns] Received info %+v for pod %v", info, podInfo) + log.Logger.Info("Received info for pod", + zap.Any("ipv4info", info), + zap.Any("podInfo", podInfo), + zap.String("component", "cni-invoker-cns")) ip, ncIPNet, err := net.ParseCIDR(info.podIPAddress + "/" + fmt.Sprint(info.ncSubnetPrefix)) if ip == nil { return IPAMAddResult{}, errors.Wrap(err, "Unable to parse IP from response: "+info.podIPAddress+" with err %w") @@ -292,13 +303,15 @@ func (invoker *CNSIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkConf if address != nil { ipConfigs.DesiredIPAddresses = append(ipConfigs.DesiredIPAddresses, address.IP.String()) } else { - log.Printf("CNS invoker called with empty IP address") + log.Logger.Info("CNS invoker called with empty IP address") } if err := invoker.cnsClient.ReleaseIPs(context.TODO(), ipConfigs); err != nil { if cnscli.IsUnsupportedAPI(err) { // If ReleaseIPs is not supported by CNS, use ReleaseIPAddress API - log.Errorf("ReleaseIPs not supported by CNS. Invoking ReleaseIPAddress API. Request: %v", ipConfigs) + log.Logger.Error("ReleaseIPs not supported by CNS. Invoking ReleaseIPAddress API", + zap.Any("ipconfigs", ipConfigs)) + ipConfig := cns.IPConfigRequest{ OrchestratorContext: orchestratorContext, PodInterfaceID: GetEndpointID(args), @@ -307,11 +320,15 @@ func (invoker *CNSIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkConf if err = invoker.cnsClient.ReleaseIPAddress(context.TODO(), ipConfig); err != nil { // if the old API fails as well then we just return the error - log.Errorf("Failed to release IP address from CNS using ReleaseIPAddress with infracontainerid %s. error: %v", ipConfigs.InfraContainerID, err) + log.Logger.Error("Failed to release IP address from CNS using ReleaseIPAddress ", + zap.String("infracontainerid", ipConfigs.InfraContainerID), + zap.Error(err)) return errors.Wrap(err, fmt.Sprintf("failed to release IP %v using ReleaseIPAddress with err ", ipConfig.DesiredIPAddress)+"%w") } } else { - log.Errorf("Failed to release IP address with infracontainerid %s from CNS error: %v", ipConfigs.InfraContainerID, err) + log.Logger.Error("Failed to release IP address", + zap.String("infracontainerid", ipConfigs.InfraContainerID), + zap.Error(err)) return errors.Wrap(err, fmt.Sprintf("failed to release IP %v using ReleaseIPs with err ", ipConfigs.DesiredIPAddresses)+"%w") } } diff --git a/cni/network/multitenancy.go b/cni/network/multitenancy.go index 242d01254e..0f9d6a0711 100644 --- a/cni/network/multitenancy.go +++ b/cni/network/multitenancy.go @@ -13,13 +13,14 @@ import ( "time" "github.com/Azure/azure-container-networking/cni" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cns" "github.com/Azure/azure-container-networking/cns/client" "github.com/Azure/azure-container-networking/common" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/network" cniTypes "github.com/containernetworking/cni/pkg/types" cniTypesCurr "github.com/containernetworking/cni/pkg/types/100" + "go.uber.org/zap" ) const ( @@ -87,8 +88,9 @@ func (m *Multitenancy) DetermineSnatFeatureOnHost(snatFile, nmAgentSupportedApis bytes, _ := io.ReadAll(jsonFile) jsonFile.Close() if retrieveSnatConfigErr = json.Unmarshal(bytes, &snatConfig); retrieveSnatConfigErr != nil { - log.Errorf("[cni-net] failed to unmarshal to snatConfig with error %v", - retrieveSnatConfigErr) + log.Logger.Error("failed to unmarshal to snatConfig with error %v", + zap.Error(retrieveSnatConfigErr), + zap.String("component", "cni-net")) } } @@ -97,10 +99,10 @@ func (m *Multitenancy) DetermineSnatFeatureOnHost(snatFile, nmAgentSupportedApis var resp *http.Response req, err := http.NewRequestWithContext(context.TODO(), http.MethodGet, nmAgentSupportedApisURL, nil) if err != nil { - log.Errorf("failed creating http request:%+v", err) + log.Logger.Error("failed creating http request", zap.Error(err)) return false, false, fmt.Errorf("%w", err) } - log.Printf("Query nma for dns snat support: %s", nmAgentSupportedApisURL) + log.Logger.Info("Query nma for dns snat support", zap.String("query", nmAgentSupportedApisURL)) resp, retrieveSnatConfigErr = httpClient.Do(req) if retrieveSnatConfigErr == nil { defer resp.Body.Close() @@ -120,11 +122,14 @@ func (m *Multitenancy) DetermineSnatFeatureOnHost(snatFile, nmAgentSupportedApis if err == nil { _, err = fp.Write(jsonStr) if err != nil { - log.Errorf("DetermineSnatFeatureOnHost: Write to json failed:%+v", err) + log.Logger.Error("DetermineSnatFeatureOnHost: Write to json failed", zap.Error(err)) } fp.Close() } else { - log.Errorf("[cni-net] failed to save snat settings to %s with error: %+v", snatConfigFile, err) + log.Logger.Error("failed to save snat settings", + zap.String("snatConfgFile", snatConfigFile), + zap.Error(err), + zap.String("component", "cni-net")) } } } else { @@ -135,20 +140,27 @@ func (m *Multitenancy) DetermineSnatFeatureOnHost(snatFile, nmAgentSupportedApis // Log and return the error when we fail acquire snat configuration for host and dns if retrieveSnatConfigErr != nil { - log.Errorf("[cni-net] failed to acquire SNAT configuration with error %v", - retrieveSnatConfigErr) + log.Logger.Error("failed to acquire SNAT configuration with error %v", + zap.Error(retrieveSnatConfigErr), + zap.String("component", "cni-net")) return snatConfig.EnableSnatForDns, snatConfig.EnableSnatOnHost, retrieveSnatConfigErr } - log.Printf("[cni-net] saved snat settings %+v to %s", snatConfig, snatConfigFile) + log.Logger.Info("saved snat settings", + zap.Any("snatConfig", snatConfig), + zap.String("snatConfigfile", snatConfigFile), + zap.String("component", "cni-net")) if snatConfig.EnableSnatOnHost { - log.Printf("[cni-net] enabling SNAT on container host for outbound connectivity") + log.Logger.Info("enabling SNAT on container host for outbound connectivity", + zap.String("component", "cni-net")) } if snatConfig.EnableSnatForDns { - log.Printf("[cni-net] enabling SNAT on container host for DNS traffic") + log.Logger.Info("enabling SNAT on container host for DNS traffic", + zap.String("component", "cni-net")) } if !snatConfig.EnableSnatForDns && !snatConfig.EnableSnatOnHost { - log.Printf("[cni-net] disabling SNAT on container host") + log.Logger.Info("disabling SNAT on container host", + zap.String("component", "cni-net")) } return snatConfig.EnableSnatForDns, snatConfig.EnableSnatOnHost, nil @@ -164,7 +176,7 @@ func (m *Multitenancy) SetupRoutingForMultitenancy( // Adding default gateway // if snat enabled, add 169.254.128.1 as default gateway if nwCfg.EnableSnatOnHost { - log.Printf("add default route for multitenancy.snat on host enabled") + log.Logger.Info("add default route for multitenancy.snat on host enabled") addDefaultRoute(cnsNetworkConfig.LocalIPConfiguration.GatewayIPAddress, epInfo, result) } else { _, defaultIPNet, _ := net.ParseCIDR("0.0.0.0/0") @@ -174,7 +186,7 @@ func (m *Multitenancy) SetupRoutingForMultitenancy( result.Routes = append(result.Routes, &cniTypes.Route{Dst: dstIP, GW: gwIP}) if epInfo.EnableSnatForDns { - log.Printf("add SNAT for DNS enabled") + log.Logger.Info("add SNAT for DNS enabled") addSnatForDNS(cnsNetworkConfig.LocalIPConfiguration.GatewayIPAddress, epInfo, result) } } @@ -194,7 +206,7 @@ func (m *Multitenancy) GetAllNetworkContainers( podNameWithoutSuffix = podName } - log.Printf("Podname without suffix %v", podNameWithoutSuffix) + log.Logger.Info("Podname without suffix", zap.String("podName", podNameWithoutSuffix)) ncResponses, hostSubnetPrefixes, err := m.getNetworkContainersInternal(ctx, podNamespace, podNameWithoutSuffix) if err != nil { @@ -204,7 +216,8 @@ func (m *Multitenancy) GetAllNetworkContainers( for i := 0; i < len(ncResponses); i++ { if nwCfg.EnableSnatOnHost { if ncResponses[i].LocalIPConfiguration.IPSubnet.IPAddress == "" { - log.Printf("Snat IP is not populated for ncs %+v. Got empty string", ncResponses) + log.Logger.Info("Snat IP is not populated for ncs. Got empty string", + zap.Any("response", ncResponses)) return []IPAMAddResult{}, errSnatIP } } @@ -232,7 +245,7 @@ func (m *Multitenancy) getNetworkContainersInternal( orchestratorContext, err := json.Marshal(podInfo) if err != nil { - log.Printf("Marshalling KubernetesPodInfo failed with %v", err) + log.Logger.Error("Marshalling KubernetesPodInfo failed", zap.Error(err)) return nil, []net.IPNet{}, fmt.Errorf("%w", err) } @@ -249,13 +262,14 @@ func (m *Multitenancy) getNetworkContainersInternal( return nil, []net.IPNet{}, fmt.Errorf("%w", err) } - log.Printf("Network config received from cns %+v", ncConfigs) + log.Logger.Info("Network config received from cns", zap.Any("nconfig", ncConfigs)) subnetPrefixes := []net.IPNet{} for i := 0; i < len(ncConfigs); i++ { subnetPrefix := m.netioshim.GetInterfaceSubnetWithSpecificIP(ncConfigs[i].PrimaryInterfaceIdentifier) if subnetPrefix == nil { - log.Printf("%w %s", errIfaceNotFound, ncConfigs[i].PrimaryInterfaceIdentifier) + log.Logger.Error(errIfaceNotFound.Error(), + zap.String("nodeIP", ncConfigs[i].PrimaryInterfaceIdentifier)) return nil, []net.IPNet{}, errIfaceNotFound } subnetPrefixes = append(subnetPrefixes, *subnetPrefix) diff --git a/cni/network/network.go b/cni/network/network.go index 3f7e02054a..5f3928d054 100644 --- a/cni/network/network.go +++ b/cni/network/network.go @@ -14,12 +14,12 @@ import ( "github.com/Azure/azure-container-networking/aitelemetry" "github.com/Azure/azure-container-networking/cni" "github.com/Azure/azure-container-networking/cni/api" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cni/util" "github.com/Azure/azure-container-networking/cns" cnscli "github.com/Azure/azure-container-networking/cns/client" "github.com/Azure/azure-container-networking/common" "github.com/Azure/azure-container-networking/iptables" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/netio" "github.com/Azure/azure-container-networking/netlink" "github.com/Azure/azure-container-networking/network" @@ -32,6 +32,7 @@ import ( cniTypes "github.com/containernetworking/cni/pkg/types" cniTypesCurr "github.com/containernetworking/cni/pkg/types/100" "github.com/pkg/errors" + "go.uber.org/zap" ) const ( @@ -139,34 +140,36 @@ func (plugin *NetPlugin) Start(config *common.PluginConfig) error { // Initialize base plugin. err := plugin.Initialize(config) if err != nil { - log.Printf("[cni-net] Failed to initialize base plugin, err:%v.", err) + log.Logger.Error("[cni-net] Failed to initialize base plugin", zap.Error(err)) return err } // Log platform information. - log.Printf("[cni-net] Plugin %v version %v.", plugin.Name, plugin.Version) - log.Printf("[cni-net] Running on %v", platform.GetOSInfo()) + log.Logger.Info("Plugin Info", + zap.String("name", plugin.Name), + zap.String("version", plugin.Version), + zap.String("component", "cni-net")) + + log.Logger.Info("Os Info", + zap.String("platform", platform.GetOSInfo()), + zap.String("component", "cni-net")) platform.PrintDependencyPackageDetails() common.LogNetworkInterfaces() // Initialize network manager. rehyrdration not required on reboot for cni plugin err = plugin.nm.Initialize(config, false) if err != nil { - log.Printf("[cni-net] Failed to initialize network manager, err:%v.", err) + log.Logger.Error("Failed to initialize network manager", + zap.Error(err), + zap.String("component", "cni-net")) return err } - log.Printf("[cni-net] Plugin started.") + log.Logger.Info("Plugin started", zap.String("component", "cni-net")) return nil } -// This function for sending CNI metrics to telemetry service -func logAndSendEvent(plugin *NetPlugin, msg string) { - log.Printf(msg) - sendEvent(plugin, msg) -} - func sendEvent(plugin *NetPlugin, msg string) { eventMsg := fmt.Sprintf("[%d] %s", os.Getpid(), msg) plugin.report.Version = plugin.Version @@ -181,7 +184,7 @@ func (plugin *NetPlugin) GetAllEndpointState(networkid string) (*api.AzureCNISta eps, err := plugin.nm.GetAllEndpoints(networkid) if err == store.ErrStoreEmpty { - log.Printf("failed to retrieve endpoint state with err %v", err) + log.Logger.Error("failed to retrieve endpoint state", zap.Error(err)) } else if err != nil { return nil, err } @@ -206,7 +209,7 @@ func (plugin *NetPlugin) GetAllEndpointState(networkid string) (*api.AzureCNISta func (plugin *NetPlugin) Stop() { plugin.nm.Uninitialize() plugin.Uninitialize() - log.Printf("[cni-net] Plugin stopped.") + log.Logger.Info("Plugin stopped", zap.String("component", "cni-net")) } // FindMasterInterface returns the name of the master interface. @@ -247,21 +250,21 @@ func GetEndpointID(args *cniSkel.CmdArgs) string { func (plugin *NetPlugin) getPodInfo(args string) (name, ns string, err error) { podCfg, err := cni.ParseCniArgs(args) if err != nil { - log.Printf("Error while parsing CNI Args %v", err) + log.Logger.Error("Error while parsing CNI Args", zap.Error(err)) return "", "", err } k8sNamespace := string(podCfg.K8S_POD_NAMESPACE) if len(k8sNamespace) == 0 { errMsg := "Pod Namespace not specified in CNI Args" - log.Printf(errMsg) + log.Logger.Error(errMsg) return "", "", plugin.Errorf(errMsg) } k8sPodName := string(podCfg.K8S_POD_NAME) if len(k8sPodName) == 0 { errMsg := "Pod Name not specified in CNI Args" - log.Printf(errMsg) + log.Logger.Error(errMsg) return "", "", plugin.Errorf(errMsg) } @@ -270,7 +273,8 @@ func (plugin *NetPlugin) getPodInfo(args string) (name, ns string, err error) { func SetCustomDimensions(cniMetric *telemetry.AIMetric, nwCfg *cni.NetworkConfig, err error) { if cniMetric == nil { - log.Errorf("[CNI] Unable to set custom dimension. Report is nil") + log.Logger.Error("Unable to set custom dimension. Report is nil", + zap.String("component", "cni")) return } @@ -311,7 +315,8 @@ func addNatIPV6SubnetInfo(nwCfg *cni.NetworkConfig, Prefix: ipv6Subnet, Gateway: resultV6.IPs[0].Gateway, } - log.Printf("[net] ipv6 subnet info:%+v", ipv6SubnetInfo) + log.Logger.Info("ipv6 subnet info", + zap.Any("ipv6SubnetInfo", ipv6SubnetInfo), zap.String("component", "net")) nwInfo.Subnets = append(nwInfo.Subnets, ipv6SubnetInfo) } } @@ -333,7 +338,14 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { startTime := time.Now() - logAndSendEvent(plugin, fmt.Sprintf("[cni-net] Processing ADD command with args {ContainerID:%v Netns:%v IfName:%v Args:%v Path:%v StdinData:%s}.", + log.Logger.Info("[cni-net] Processing ADD command", + zap.String("containerId", args.ContainerID), + zap.String("netNS", args.Netns), + zap.String("ifName", args.IfName), + zap.Any("args", args.Args), + zap.String("path", args.Path), + zap.ByteString("stdinData", args.StdinData)) + sendEvent(plugin, fmt.Sprintf("[cni-net] 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)) // Parse network configuration from stdin. @@ -376,7 +388,7 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { // Convert result to the requested CNI version. res, vererr := ipamAddResult.ipv4Result.GetAsVersion(nwCfg.CNIVersion) if vererr != nil { - log.Printf("GetAsVersion failed with error %v", vererr) + log.Logger.Error("GetAsVersion failed", zap.Error(vererr)) plugin.Error(vererr) } @@ -385,7 +397,10 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { res.Print() } - log.Printf("[cni-net] ADD command completed for pod %v with IPs:%+v err:%v.", k8sPodName, ipamAddResult.ipv4Result.IPs, err) + log.Logger.Info("[cni-net] ADD command completed for pod %v with IPs:%+v err:%v.", + zap.String("pod", k8sPodName), + zap.Any("IPs", ipamAddResult.ipv4Result.IPs), + zap.Error(err)) }() // Parse Pod arguments. @@ -399,21 +414,21 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { k8sContainerID := args.ContainerID if len(k8sContainerID) == 0 { errMsg := "Container ID not specified in CNI Args" - log.Printf(errMsg) + log.Logger.Error(errMsg) return plugin.Errorf(errMsg) } k8sIfName := args.IfName if len(k8sIfName) == 0 { errMsg := "Interfacename not specified in CNI Args" - log.Printf(errMsg) + log.Logger.Error(errMsg) return plugin.Errorf(errMsg) } platformInit(nwCfg) if nwCfg.ExecutionMode == string(util.Baremetal) { var res *nnscontracts.ConfigureContainerNetworkingResponse - log.Printf("Baremetal mode. Calling vnet agent for ADD") + log.Logger.Info("Baremetal mode. Calling vnet agent for ADD") res, err = plugin.nnsClient.AddContainerNetworking(context.Background(), k8sPodName, args.Netns) if err == nil { @@ -425,7 +440,9 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { for _, ns := range nwCfg.PodNamespaceForDualNetwork { if k8sNamespace == ns { - log.Printf("Enable infravnet for this pod %v in namespace %v", k8sPodName, k8sNamespace) + log.Logger.Info("Enable infravnet for pod", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace)) enableInfraVnet = true break } @@ -449,13 +466,17 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { ipamAddResults, err = plugin.multitenancyClient.GetAllNetworkContainers(context.TODO(), nwCfg, k8sPodName, k8sNamespace, args.IfName) if err != nil { err = fmt.Errorf("GetAllNetworkContainers failed for podname %s namespace %s. error: %w", k8sPodName, k8sNamespace, err) - log.Printf("%+v", err) + log.Logger.Error("GetAllNetworkContainers failed", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace), + zap.Error(err)) return err } if len(ipamAddResults) > 1 && !plugin.isDualNicFeatureSupported(args.Netns) { errMsg := fmt.Sprintf("received multiple NC results %+v from CNS while dualnic feature is not supported", ipamAddResults) - log.Printf(errMsg) + log.Logger.Error("received multiple NC results from CNS while dualnic feature is not supported", + zap.Any("results", ipamAddResult)) return plugin.Errorf(errMsg) } } else { @@ -484,14 +505,16 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { // Issue link: https://github.com/kubernetes/kubernetes/issues/57253 if nwInfoErr == nil { - log.Printf("[cni-net] Found network %v with subnet %v.", networkID, nwInfo.Subnets[0].Prefix.String()) + log.Logger.Info("[cni-net] Found network with subnet", + zap.String("network", networkID), + zap.String("subnet", nwInfo.Subnets[0].Prefix.String())) nwInfo.IPAMType = nwCfg.IPAM.Type options = nwInfo.Options var resultSecondAdd *cniTypesCurr.Result resultSecondAdd, err = plugin.handleConsecutiveAdd(args, endpointID, networkID, &nwInfo, nwCfg) if err != nil { - log.Printf("handleConsecutiveAdd failed with error %v", err) + log.Logger.Error("handleConsecutiveAdd failed", zap.Error(err)) return err } @@ -530,14 +553,17 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { // Create network if nwInfoErr != nil { // Network does not exist. - logAndSendEvent(plugin, fmt.Sprintf("[cni-net] Creating network %v.", networkID)) + log.Logger.Info("[cni-net] Creating network", zap.String("networkID", networkID)) + sendEvent(plugin, fmt.Sprintf("[cni-net] Creating network %v.", networkID)) // opts map needs to get passed in here if nwInfo, err = plugin.createNetworkInternal(networkID, policies, ipamAddConfig, ipamAddResult); err != nil { - log.Errorf("Create network failed: %w", err) + log.Logger.Error("Create network failed", zap.Error(err)) return err } - - logAndSendEvent(plugin, fmt.Sprintf("[cni-net] Created network %v with subnet %v.", networkID, ipamAddResult.hostSubnetPrefix.String())) + log.Logger.Info("[cni-net] Created network", + zap.String("networkId", networkID), + zap.String("subnet", ipamAddResult.hostSubnetPrefix.String())) + sendEvent(plugin, fmt.Sprintf("[cni-net] Created network %v with subnet %v.", networkID, ipamAddResult.hostSubnetPrefix.String())) } natInfo := getNATInfo(nwCfg, options[network.SNATIPKey], enableSnatForDNS) @@ -562,7 +588,7 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error { var epInfo network.EndpointInfo epInfo, err = plugin.createEndpointInternal(&createEndpointInternalOpt) if err != nil { - log.Errorf("Endpoint creation failed:%w", err) + log.Logger.Error("Endpoint creation failed", zap.Error(err)) return err } @@ -582,12 +608,12 @@ func (plugin *NetPlugin) cleanupAllocationOnError( ) { if result != nil && len(result.IPs) > 0 { if er := plugin.ipamInvoker.Delete(&result.IPs[0].Address, nwCfg, args, options); er != nil { - log.Errorf("Failed to cleanup ip allocation on failure: %v", er) + log.Logger.Error("Failed to cleanup ip allocation on failure", zap.Error(er)) } } if resultV6 != nil && len(resultV6.IPs) > 0 { if er := plugin.ipamInvoker.Delete(&resultV6.IPs[0].Address, nwCfg, args, options); er != nil { - log.Errorf("Failed to cleanup ipv6 allocation on failure: %v", er) + log.Logger.Error("Failed to cleanup ipv6 allocation on failure", zap.Error(er)) } } } @@ -607,7 +633,7 @@ func (plugin *NetPlugin) createNetworkInternal( err := plugin.Errorf("Failed to find the master interface") return nwInfo, err } - log.Printf("[cni-net] Found master interface %v.", masterIfName) + log.Logger.Info("[cni-net] Found master interface", zap.String("ifname", masterIfName)) // Add the master as an external interface. err := plugin.nm.AddExternalInterface(masterIfName, ipamAddResult.hostSubnetPrefix.String()) @@ -622,7 +648,7 @@ func (plugin *NetPlugin) createNetworkInternal( return nwInfo, err } - log.Printf("[cni-net] nwDNSInfo: %v", nwDNSInfo) + log.Logger.Info("[cni-net] DNS Info", zap.Any("info", nwDNSInfo)) // Create the network. nwInfo = network.NetworkInfo{ @@ -644,7 +670,8 @@ func (plugin *NetPlugin) createNetworkInternal( } if err = addSubnetToNetworkInfo(ipamAddResult, &nwInfo); err != nil { - log.Printf("[cni-net] Failed to add subnets to networkInfo due to %+v", err) + log.Logger.Info("[cni-net] Failed to add subnets to networkInfo", + zap.Error(err)) return nwInfo, err } setNetworkOptions(ipamAddResult.ncResponse, &nwInfo) @@ -726,7 +753,7 @@ func (plugin *NetPlugin) createEndpointInternal(opt *createEndpointInternalOpt) } endpointPolicies, err := getEndpointPolicies(policyArgs) if err != nil { - log.Errorf("Failed to get endpoint policies:%v", err) + log.Logger.Error("Failed to get endpoint policies", zap.Error(err)) return epInfo, err } @@ -796,12 +823,14 @@ func (plugin *NetPlugin) createEndpointInternal(opt *createEndpointInternalOpt) cnsclient, err := cnscli.New(opt.nwCfg.CNSUrl, defaultRequestTimeout) if err != nil { - log.Printf("failed to initialized cns client with URL %s: %v", opt.nwCfg.CNSUrl, err.Error()) + log.Logger.Error("failed to initialized cns client", zap.String("url", opt.nwCfg.CNSUrl), + zap.String("error", err.Error())) return epInfo, plugin.Errorf(err.Error()) } // Create the endpoint. - logAndSendEvent(plugin, fmt.Sprintf("[cni-net] Creating endpoint %s.", epInfo.PrettyString())) + log.Logger.Info("[cni-net] Creating endpoint", zap.String("endpointInfo", epInfo.PrettyString())) + sendEvent(plugin, fmt.Sprintf("[cni-net] Creating endpoint %s.", epInfo.PrettyString())) err = plugin.nm.CreateEndpoint(cnsclient, opt.nwInfo.Id, &epInfo) if err != nil { err = plugin.Errorf("Failed to create endpoint: %v", err) @@ -821,8 +850,12 @@ func (plugin *NetPlugin) Get(args *cniSkel.CmdArgs) error { networkID string ) - log.Printf("[cni-net] Processing GET command with args {ContainerID:%v Netns:%v IfName:%v Args:%v Path:%v}.", - args.ContainerID, args.Netns, args.IfName, args.Args, args.Path) + log.Logger.Info("[cni-net] Processing GET command", + zap.String("container", args.ContainerID), + zap.String("netns", args.Netns), + zap.String("ifname", args.IfName), + zap.String("args", args.Args), + zap.String("path", args.Path)) defer func() { // Add Interfaces to result. @@ -834,7 +867,7 @@ func (plugin *NetPlugin) Get(args *cniSkel.CmdArgs) error { // Convert result to the requested CNI version. res, vererr := result.GetAsVersion(nwCfg.CNIVersion) if vererr != nil { - log.Printf("GetAsVersion failed with error %v", vererr) + log.Logger.Error("GetAsVersion failed", zap.Error(vererr)) plugin.Error(vererr) } @@ -843,7 +876,8 @@ func (plugin *NetPlugin) Get(args *cniSkel.CmdArgs) error { res.Print() } - log.Printf("[cni-net] GET command completed with result:%+v err:%v.", result, err) + log.Logger.Info("[cni-net] GET command completed", zap.Any("result", result), + zap.Error(err)) }() // Parse network configuration from stdin. @@ -852,14 +886,15 @@ func (plugin *NetPlugin) Get(args *cniSkel.CmdArgs) error { return err } - log.Printf("[cni-net] Read network configuration %+v.", nwCfg) + log.Logger.Info("[cni-net] Read network configuration", zap.Any("config", nwCfg)) iptables.DisableIPTableLock = nwCfg.DisableIPTableLock // Initialize values from network config. if networkID, err = plugin.getNetworkName(args.Netns, nil, nwCfg); err != nil { // TODO: Ideally we should return from here only. - log.Printf("[cni-net] Failed to extract network name from network config. error: %v", err) + log.Logger.Error("[cni-net] Failed to extract network name from network config", + zap.Error(err)) } endpointID := GetEndpointID(args) @@ -914,11 +949,20 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { startTime := time.Now() - logAndSendEvent(plugin, fmt.Sprintf("[cni-net] Processing DEL command with args {ContainerID:%v Netns:%v IfName:%v Args:%v Path:%v, StdinData:%s}.", + log.Logger.Info("[cni-net] Processing DEL command", + zap.String("containerId", args.ContainerID), + zap.String("netNS", args.Netns), + zap.String("ifName", args.IfName), + zap.Any("args", args.Args), + zap.String("path", args.Path), + zap.ByteString("stdinData", args.StdinData)) + sendEvent(plugin, fmt.Sprintf("[cni-net] 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)) defer func() { - log.Printf("[cni-net] DEL command completed for pod %v with err:%v.", k8sPodName, err) + log.Logger.Info("[cni-net] DEL command completed", + zap.String("pod", k8sPodName), + zap.Error(err)) }() // Parse network configuration from stdin. @@ -929,7 +973,7 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { // Parse Pod arguments. if k8sPodName, k8sNamespace, err = plugin.getPodInfo(args.Args); err != nil { - log.Printf("[cni-net] Failed to get POD info due to error: %v", err) + log.Logger.Error("[cni-net] Failed to get POD info", zap.Error(err)) } plugin.setCNIReportDetails(nwCfg, CNI_DEL, "") @@ -951,10 +995,10 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { platformInit(nwCfg) - log.Printf("Execution mode :%s", nwCfg.ExecutionMode) + log.Logger.Info("Execution mode", zap.String("mode", nwCfg.ExecutionMode)) if nwCfg.ExecutionMode == string(util.Baremetal) { - log.Printf("Baremetal mode. Calling vnet agent for delete container") + log.Logger.Info("Baremetal mode. Calling vnet agent for delete container") // schedule send metric before attempting delete defer sendMetricFunc() @@ -969,7 +1013,7 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { case network.AzureCNS: cnsClient, cnsErr := cnscli.New("", defaultRequestTimeout) if cnsErr != nil { - log.Printf("[cni-net] failed to create cns client:%v", cnsErr) + log.Logger.Error("[cni-net] failed to create cns client", zap.Error(cnsErr)) return errors.Wrap(cnsErr, "failed to create cns client") } plugin.ipamInvoker = NewCNSInvoker(k8sPodName, k8sNamespace, cnsClient, util.ExecutionMode(nwCfg.ExecutionMode), util.IpamMode(nwCfg.IPAM.Mode)) @@ -990,7 +1034,7 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { numEndpointsToDelete = plugin.nm.GetNumEndpointsByContainerID(args.ContainerID) } - log.Printf("[cni-net] number of endpoints to be deleted %d", numEndpointsToDelete) + log.Logger.Info("[cni-net] Endpoints to be deleted", zap.Int("count", numEndpointsToDelete)) for i := 0; i < numEndpointsToDelete; i++ { // Initialize values from network config. networkID, err = plugin.getNetworkName(args.Netns, nil, nwCfg) @@ -1001,28 +1045,40 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { return err } - log.Printf("[cni-net] Failed to extract network name from network config. error: %v", err) + log.Logger.Error("[cni-net] Failed to extract network name from network config", zap.Error(err)) err = plugin.Errorf("Failed to extract network name from network config. error: %v", err) return err } // Query the network. if nwInfo, err = plugin.nm.GetNetworkInfo(networkID); err != nil { - // Log the error but return success if the network is not found. - // if cni hits this, mostly state file would be missing and it can be reboot scenario where - // container runtime tries to delete and create pods which existed before reboot. - log.Printf("[cni-net] Failed to query network:%s: %v", networkID, err) - err = nil - return err + if !nwCfg.MultiTenancy { + log.Logger.Error("[cni-net] Failed to query network", + zap.String("network", networkID), + zap.Error(err)) + // Log the error but return success if the network is not found. + // if cni hits this, mostly state file would be missing and it can be reboot scenario where + // container runtime tries to delete and create pods which existed before reboot. + err = nil + return err + } } endpointID := GetEndpointID(args) // Query the endpoint. if epInfo, err = plugin.nm.GetEndpointInfo(networkID, endpointID); err != nil { - log.Printf("[cni-net] GetEndpoint for endpointID: %s returns: %v", endpointID, err) + log.Logger.Info("[cni-net] GetEndpoint", + zap.String("endpoint", endpointID), + zap.Error(err)) if !nwCfg.MultiTenancy { // attempt to release address associated with this Endpoint id // This is to ensure clean up is done even in failure cases - logAndSendEvent(plugin, fmt.Sprintf("Release ip by ContainerID (endpoint not found):%v", args.ContainerID)) + + log.Logger.Error("[cni-net] Failed to query endpoint", + zap.String("endpoint", endpointID), + zap.Error(err)) + log.Logger.Error("Release ip by ContainerID (endpoint not found)", + zap.String("containerID", args.ContainerID)) + sendEvent(plugin, fmt.Sprintf("Release ip by ContainerID (endpoint not found):%v", args.ContainerID)) if err = plugin.ipamInvoker.Delete(nil, nwCfg, args, nwInfo.Options); err != nil { return plugin.RetriableError(fmt.Errorf("failed to release address(no endpoint): %w", err)) } @@ -1034,7 +1090,9 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { // schedule send metric before attempting delete defer sendMetricFunc() //nolint:gocritic - logAndSendEvent(plugin, fmt.Sprintf("Deleting endpoint:%v", endpointID)) + log.Logger.Info("Deleting endpoint", + zap.String("endpointID", endpointID)) + sendEvent(plugin, fmt.Sprintf("Deleting endpoint:%v", endpointID)) // Delete the endpoint. if err = plugin.nm.DeleteEndpoint(networkID, endpointID); err != nil { // return a retriable error so the container runtime will retry this DEL later @@ -1046,7 +1104,8 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error { if !nwCfg.MultiTenancy { // Call into IPAM plugin to release the endpoint's addresses. for i := range epInfo.IPAddresses { - logAndSendEvent(plugin, fmt.Sprintf("Release ip:%s", epInfo.IPAddresses[i].IP.String())) + log.Logger.Info("Release ip", zap.String("ip", epInfo.IPAddresses[i].IP.String())) + sendEvent(plugin, fmt.Sprintf("Release ip:%s", epInfo.IPAddresses[i].IP.String())) err = plugin.ipamInvoker.Delete(&epInfo.IPAddresses[i], nwCfg, args, nwInfo.Options) if err != nil { return plugin.RetriableError(fmt.Errorf("failed to release address: %w", err)) @@ -1082,8 +1141,10 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { startTime := time.Now() - log.Printf("[cni-net] Processing UPDATE command with args {Netns:%v Args:%v Path:%v}.", - args.Netns, args.Args, args.Path) + log.Logger.Info("[cni-net] Processing UPDATE command", + zap.String("netns", args.Netns), + zap.String("args", args.Args), + zap.String("path", args.Path)) // Parse network configuration from stdin. if nwCfg, err = cni.ParseNetworkConfig(args.StdinData); err != nil { @@ -1091,7 +1152,7 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { return err } - log.Printf("[cni-net] Read network configuration %+v.", nwCfg) + log.Logger.Info("[cni-net] Read network configuration", zap.Any("config", nwCfg)) iptables.DisableIPTableLock = nwCfg.DisableIPTableLock plugin.setCNIReportDetails(nwCfg, CNI_UPDATE, "") @@ -1114,7 +1175,7 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { // Convert result to the requested CNI version. res, vererr := result.GetAsVersion(nwCfg.CNIVersion) if vererr != nil { - log.Printf("GetAsVersion failed with error %v", vererr) + log.Logger.Error("GetAsVersion failed", zap.Error(vererr)) plugin.Error(vererr) } @@ -1123,26 +1184,29 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { res.Print() } - log.Printf("[cni-net] UPDATE command completed with result:%+v err:%v.", result, err) + log.Logger.Info("[cni-net] UPDATE command completed", + zap.Any("result", result), + zap.Error(err)) }() // Parse Pod arguments. if podCfg, err = cni.ParseCniArgs(args.Args); err != nil { - log.Printf("[cni-net] Error while parsing CNI Args during UPDATE %v", err) + log.Logger.Error("[cni-net] Error while parsing CNI Args during UPDATE", + zap.Error(err)) return err } k8sNamespace := string(podCfg.K8S_POD_NAMESPACE) if len(k8sNamespace) == 0 { errMsg := "Required parameter Pod Namespace not specified in CNI Args during UPDATE" - log.Printf(errMsg) + log.Logger.Error(errMsg) return plugin.Errorf(errMsg) } k8sPodName := string(podCfg.K8S_POD_NAME) if len(k8sPodName) == 0 { errMsg := "Required parameter Pod Name not specified in CNI Args during UPDATE" - log.Printf(errMsg) + log.Logger.Error(errMsg) return plugin.Errorf(errMsg) } @@ -1152,7 +1216,7 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { // Query the network. if _, err = plugin.nm.GetNetworkInfo(networkID); err != nil { errMsg := fmt.Sprintf("Failed to query network during CNI UPDATE: %v", err) - log.Printf(errMsg) + log.Logger.Error(errMsg) return plugin.Errorf(errMsg) } @@ -1164,10 +1228,13 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { return err } - log.Printf("Retrieved existing endpoint from state that may get update: %+v", existingEpInfo) + log.Logger.Info("Retrieved existing endpoint from state that may get update", + zap.Any("info", existingEpInfo)) // now query CNS to get the target routes that should be there in the networknamespace (as a result of update) - log.Printf("Going to collect target routes for [name=%v, namespace=%v] from CNS.", k8sPodName, k8sNamespace) + log.Logger.Info("Going to collect target routes from CNS", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace)) // create struct with info for target POD podInfo := cns.KubernetesPodInfo{ @@ -1175,61 +1242,77 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error { PodNamespace: k8sNamespace, } if orchestratorContext, err = json.Marshal(podInfo); err != nil { - log.Printf("Marshalling KubernetesPodInfo failed with %v", err) + log.Logger.Error("Marshalling KubernetesPodInfo failed", + zap.Error(err)) return plugin.Errorf(err.Error()) } cnsclient, err := cnscli.New(nwCfg.CNSUrl, defaultRequestTimeout) if err != nil { - log.Printf("failed to initialized cns client with URL %s: %v", nwCfg.CNSUrl, err.Error()) + log.Logger.Error("failed to initialized cns client", + zap.String("url", nwCfg.CNSUrl), + zap.String("error", err.Error())) return plugin.Errorf(err.Error()) } if targetNetworkConfig, err = cnsclient.GetNetworkContainer(context.TODO(), orchestratorContext); err != nil { - log.Printf("GetNetworkContainer failed with %v", err) + log.Logger.Info("GetNetworkContainer failed", + zap.Error(err)) return plugin.Errorf(err.Error()) } - log.Printf("Network config received from cns for [name=%v, namespace=%v] is as follows -> %+v", k8sPodName, k8sNamespace, targetNetworkConfig) + log.Logger.Info("Network config received from cns", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace), + zap.Any("config", targetNetworkConfig)) targetEpInfo := &network.EndpointInfo{} // get the target routes that should replace existingEpInfo.Routes inside the network namespace - log.Printf("Going to collect target routes for [name=%v, namespace=%v] from targetNetworkConfig.", k8sPodName, k8sNamespace) + log.Logger.Info("Going to collect target routes for from targetNetworkConfig", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace)) if targetNetworkConfig.Routes != nil && len(targetNetworkConfig.Routes) > 0 { for _, route := range targetNetworkConfig.Routes { - log.Printf("Adding route from routes to targetEpInfo %+v", route) + log.Logger.Info("Adding route from routes to targetEpInfo", zap.Any("route", route)) _, dstIPNet, _ := net.ParseCIDR(route.IPAddress) gwIP := net.ParseIP(route.GatewayIPAddress) targetEpInfo.Routes = append(targetEpInfo.Routes, network.RouteInfo{Dst: *dstIPNet, Gw: gwIP, DevName: existingEpInfo.IfName}) - log.Printf("Successfully added route from routes to targetEpInfo %+v", route) + log.Logger.Info("Successfully added route from routes to targetEpInfo", zap.Any("route", route)) } } - log.Printf("Going to collect target routes based on Cnetaddressspace for [name=%v, namespace=%v] from targetNetworkConfig.", k8sPodName, k8sNamespace) + log.Logger.Info("Going to collect target routes based on Cnetaddressspace from targetNetworkConfig", + zap.String("pod", k8sPodName), + zap.String("namespace", k8sNamespace)) + ipconfig := targetNetworkConfig.IPConfiguration for _, ipRouteSubnet := range targetNetworkConfig.CnetAddressSpace { - log.Printf("Adding route from cnetAddressspace to targetEpInfo %+v", ipRouteSubnet) + log.Logger.Info("Adding route from cnetAddressspace to targetEpInfo", zap.Any("subnet", ipRouteSubnet)) dstIPNet := net.IPNet{IP: net.ParseIP(ipRouteSubnet.IPAddress), Mask: net.CIDRMask(int(ipRouteSubnet.PrefixLength), 32)} gwIP := net.ParseIP(ipconfig.GatewayIPAddress) route := network.RouteInfo{Dst: dstIPNet, Gw: gwIP, DevName: existingEpInfo.IfName} targetEpInfo.Routes = append(targetEpInfo.Routes, route) - log.Printf("Successfully added route from cnetAddressspace to targetEpInfo %+v", ipRouteSubnet) + log.Logger.Info("Successfully added route from cnetAddressspace to targetEpInfo", zap.Any("subnet", ipRouteSubnet)) } - log.Printf("Finished collecting new routes in targetEpInfo as follows: %+v", targetEpInfo.Routes) - log.Printf("Now saving existing infravnetaddress space if needed.") + log.Logger.Info("Finished collecting new routes in targetEpInfo", zap.Any("route", targetEpInfo.Routes)) + log.Logger.Info("Now saving existing infravnetaddress space if needed.") for _, ns := range nwCfg.PodNamespaceForDualNetwork { if k8sNamespace == ns { targetEpInfo.EnableInfraVnet = true targetEpInfo.InfraVnetAddressSpace = nwCfg.InfraVnetAddressSpace - log.Printf("Saving infravnet address space %s for [%s-%s]", - targetEpInfo.InfraVnetAddressSpace, existingEpInfo.PODNameSpace, existingEpInfo.PODName) + log.Logger.Info("Saving infravnet address space", + zap.String("space", targetEpInfo.InfraVnetAddressSpace), + zap.String("namespace", existingEpInfo.PODNameSpace), + zap.String("pod", existingEpInfo.PODName)) break } } // Update the endpoint. - log.Printf("Now updating existing endpoint %v with targetNetworkConfig %+v.", existingEpInfo.Id, targetNetworkConfig) + log.Logger.Info("Now updating existing endpoint with targetNetworkConfig", + zap.String("endpoint", existingEpInfo.Id), + zap.Any("config", targetNetworkConfig)) if err = plugin.nm.UpdateEndpoint(networkID, existingEpInfo, targetEpInfo); err != nil { err = plugin.Errorf("Failed to update endpoint: %v", err) return err @@ -1262,8 +1345,10 @@ func convertNnsToCniResult( ipWithPrefix := fmt.Sprintf("%s/%s", ip.Ip, ip.PrefixLength) _, ipNet, err := net.ParseCIDR(ipWithPrefix) if err != nil { - log.Printf("Error while converting to cni result for %s operation on pod %s. %s", - operationName, podName, err) + log.Logger.Error("Error while converting to cni result", + zap.String("operation", operationName), + zap.String("pod", podName), + zap.Error(err)) continue } diff --git a/cni/network/network_linux.go b/cni/network/network_linux.go index 86cda418c1..4ed4648481 100644 --- a/cni/network/network_linux.go +++ b/cni/network/network_linux.go @@ -5,8 +5,8 @@ import ( "strconv" "github.com/Azure/azure-container-networking/cni" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cns" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/network" "github.com/Azure/azure-container-networking/network/policy" cniSkel "github.com/containernetworking/cni/pkg/skel" @@ -52,7 +52,7 @@ func addInfraRoutes(azIpamResult *cniTypesCurr.Result, result *cniTypesCurr.Resu func setNetworkOptions(cnsNwConfig *cns.GetNetworkContainerResponse, nwInfo *network.NetworkInfo) { if cnsNwConfig != nil && cnsNwConfig.MultiTenancyInfo.ID != 0 { - log.Printf("Setting Network Options") + log.Logger.Info("Setting Network Options") vlanMap := make(map[string]interface{}) vlanMap[network.VlanIDKey] = strconv.Itoa(cnsNwConfig.MultiTenancyInfo.ID) vlanMap[network.SnatBridgeIPKey] = cnsNwConfig.LocalIPConfiguration.GatewayIPAddress + "/" + strconv.Itoa(int(cnsNwConfig.LocalIPConfiguration.IPSubnet.PrefixLength)) @@ -62,7 +62,7 @@ func setNetworkOptions(cnsNwConfig *cns.GetNetworkContainerResponse, nwInfo *net func setEndpointOptions(cnsNwConfig *cns.GetNetworkContainerResponse, epInfo *network.EndpointInfo, vethName string) { if cnsNwConfig != nil && cnsNwConfig.MultiTenancyInfo.ID != 0 { - log.Printf("Setting Endpoint Options") + log.Logger.Info("Setting Endpoint Options") epInfo.Data[network.VlanIDKey] = cnsNwConfig.MultiTenancyInfo.ID epInfo.Data[network.LocalIPKey] = cnsNwConfig.LocalIPConfiguration.IPSubnet.IPAddress + "/" + strconv.Itoa(int(cnsNwConfig.LocalIPConfiguration.IPSubnet.PrefixLength)) epInfo.Data[network.SnatBridgeIPKey] = cnsNwConfig.LocalIPConfiguration.GatewayIPAddress + "/" + strconv.Itoa(int(cnsNwConfig.LocalIPConfiguration.IPSubnet.PrefixLength)) diff --git a/cni/network/network_windows.go b/cni/network/network_windows.go index e2bbb74015..c33e2cc227 100644 --- a/cni/network/network_windows.go +++ b/cni/network/network_windows.go @@ -11,9 +11,9 @@ import ( "strings" "github.com/Azure/azure-container-networking/cni" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cni/util" "github.com/Azure/azure-container-networking/cns" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/network" "github.com/Azure/azure-container-networking/network/networkutils" "github.com/Azure/azure-container-networking/network/policy" @@ -23,6 +23,7 @@ import ( cniTypes "github.com/containernetworking/cni/pkg/types" cniTypesCurr "github.com/containernetworking/cni/pkg/types/100" "github.com/pkg/errors" + "go.uber.org/zap" "golang.org/x/sys/windows/registry" ) @@ -52,15 +53,24 @@ func (plugin *NetPlugin) handleConsecutiveAdd(args *cniSkel.CmdArgs, endpointId hnsEndpoint, err := network.Hnsv1.GetHNSEndpointByName(endpointId) if hnsEndpoint != nil { - log.Printf("[net] Found existing endpoint through hcsshim: %+v", hnsEndpoint) + log.Logger.Info("Found existing endpoint through hcsshim", + zap.Any("endpoint", hnsEndpoint), + zap.String("component", "net")) endpoint, _ := network.Hnsv1.GetHNSEndpointByID(hnsEndpoint.Id) isAttached, _ := network.Hnsv1.IsAttached(endpoint, args.ContainerID) // Attach endpoint if it's not attached yet. if !isAttached { - log.Printf("[net] Attaching ep %v to container %v", hnsEndpoint.Id, args.ContainerID) + log.Logger.Info("Attaching endpoint to container", + zap.String("endpoint", hnsEndpoint.Id), + zap.String("container", args.ContainerID), + zap.String("component", "net")) err := network.Hnsv1.HotAttachEndpoint(args.ContainerID, hnsEndpoint.Id) if err != nil { - log.Printf("[cni-net] Failed to hot attach shared endpoint[%v] to container [%v], err:%v.", hnsEndpoint.Id, args.ContainerID, err) + log.Logger.Error("Failed to hot attach shared endpoint to container", + zap.String("endpoint", hnsEndpoint.Id), + zap.String("container", args.ContainerID), + zap.Error(err), + zap.String("component", "cni-net")) return nil, err } } @@ -115,7 +125,7 @@ func addInfraRoutes(azIpamResult *cniTypesCurr.Result, result *cniTypesCurr.Resu func setNetworkOptions(cnsNwConfig *cns.GetNetworkContainerResponse, nwInfo *network.NetworkInfo) { if cnsNwConfig != nil && cnsNwConfig.MultiTenancyInfo.ID != 0 { - log.Printf("Setting Network Options") + log.Logger.Info("Setting Network Options") vlanMap := make(map[string]interface{}) vlanMap[network.VlanIDKey] = strconv.Itoa(cnsNwConfig.MultiTenancyInfo.ID) nwInfo.Options[dockerNetworkOption] = vlanMap @@ -124,7 +134,7 @@ func setNetworkOptions(cnsNwConfig *cns.GetNetworkContainerResponse, nwInfo *net func setEndpointOptions(cnsNwConfig *cns.GetNetworkContainerResponse, epInfo *network.EndpointInfo, vethName string) { if cnsNwConfig != nil && cnsNwConfig.MultiTenancyInfo.ID != 0 { - log.Printf("Setting Endpoint Options") + log.Logger.Info("Setting Endpoint Options") var cnetAddressMap []string for _, ipSubnet := range cnsNwConfig.CnetAddressSpace { cnetAddressMap = append(cnetAddressMap, ipSubnet.IPAddress+"/"+strconv.Itoa(int(ipSubnet.PrefixLength))) @@ -158,7 +168,9 @@ func (plugin *NetPlugin) getNetworkName(netNs string, ipamAddResult *IPAMAddResu ipAddrNet := ipamAddResult.ipv4Result.IPs[0].Address prefix, err := netip.ParsePrefix(ipAddrNet.String()) if err != nil { - log.Printf("Error parsing %s network CIDR: %v.", ipAddrNet.String(), err) + log.Logger.Error("Error parsing network CIDR", + zap.String("cidr", ipAddrNet.String()), + zap.Error(err)) return "", errors.Wrapf(err, "cns returned invalid CIDR %s", ipAddrNet.String()) } networkName := strings.ReplaceAll(prefix.Masked().String(), ".", "-") @@ -171,7 +183,9 @@ func (plugin *NetPlugin) getNetworkName(netNs string, ipamAddResult *IPAMAddResu // This will happen during DEL call networkName, err := plugin.nm.FindNetworkIDFromNetNs(netNs) if err != nil { - log.Printf("No endpoint available with netNs: %s: %v.", netNs, err) + log.Logger.Error("No endpoint available", + zap.String("netns", netNs), + zap.Error(err)) return "", fmt.Errorf("No endpoint available with netNs: %s: %w", netNs, err) } @@ -239,7 +253,9 @@ func getEndpointDNSSettings(nwCfg *cni.NetworkConfig, result *cniTypesCurr.Resul // getPoliciesFromRuntimeCfg returns network policies from network config. func getPoliciesFromRuntimeCfg(nwCfg *cni.NetworkConfig, isIPv6Enabled bool) []policy.Policy { - log.Printf("[net] RuntimeConfigs: %+v", nwCfg.RuntimeConfig) + log.Logger.Info("Runtime Info", + zap.Any("config", nwCfg.RuntimeConfig), + zap.String("component", "net")) var policies []policy.Policy var protocol uint32 @@ -273,7 +289,9 @@ func getPoliciesFromRuntimeCfg(nwCfg *cni.NetworkConfig, isIPv6Enabled bool) []p Data: hnsv2Policy, } - log.Printf("[net] Creating port mapping policy: %+v", policyv4) + log.Logger.Info("Creating port mapping policyv4", + zap.Any("policy", policyv4), + zap.String("component", "net")) policies = append(policies, policyv4) // add port mapping policy for v6 if we have IPV6 enabled @@ -298,7 +316,9 @@ func getPoliciesFromRuntimeCfg(nwCfg *cni.NetworkConfig, isIPv6Enabled bool) []p Data: hnsv2Policyv6, } - log.Printf("[net] Creating port mapping policy v6: %+v", policyv6) + log.Logger.Info("Creating port mapping policyv6", + zap.Any("policy", policyv6), + zap.String("component", "net")) policies = append(policies, policyv6) } } @@ -372,7 +392,7 @@ func getIPV6EndpointPolicy(nwInfo *network.NetworkInfo) (policy.Policy, error) { Data: rawPolicy, } - log.Printf("[net] ipv6 outboundnat policy: %+v", eppolicy) + log.Logger.Info("[net] ipv6 outboundnat policy", zap.Any("policy", eppolicy)) return eppolicy, nil } @@ -404,7 +424,7 @@ func determineWinVer() { } if err != nil { - log.Errorf(err.Error()) + log.Logger.Error(err.Error()) } } @@ -426,7 +446,8 @@ func getNATInfo(nwCfg *cni.NetworkConfig, ncPrimaryIPIface interface{}, enableSn func platformInit(cniConfig *cni.NetworkConfig) { if cniConfig.WindowsSettings.HnsTimeoutDurationInSeconds > 0 { - log.Printf("Enabling timeout for Hns calls with a timeout value of : %v", cniConfig.WindowsSettings.HnsTimeoutDurationInSeconds) + log.Logger.Info("Enabling timeout for Hns calls", + zap.Int("timeout", cniConfig.WindowsSettings.HnsTimeoutDurationInSeconds)) network.EnableHnsV1Timeout(cniConfig.WindowsSettings.HnsTimeoutDurationInSeconds) network.EnableHnsV2Timeout(cniConfig.WindowsSettings.HnsTimeoutDurationInSeconds) } @@ -438,12 +459,12 @@ func (plugin *NetPlugin) isDualNicFeatureSupported(netNs string) bool { if useHnsV2 && err == nil { return true } - log.Errorf("DualNicFeature is not supported") + log.Logger.Error("DualNicFeature is not supported") return false } func getOverlayGateway(podsubnet *net.IPNet) (net.IP, error) { - log.Printf("WARN: No gateway specified for Overlay NC. CNI will choose one, but connectivity may break.") + log.Logger.Warn("No gateway specified for Overlay NC. CNI will choose one, but connectivity may break") ncgw := podsubnet.IP ncgw[3]++ ncgw = net.ParseIP(ncgw.String()) diff --git a/cni/network/plugin/main.go b/cni/network/plugin/main.go index a9c9e5ce83..f736015d65 100644 --- a/cni/network/plugin/main.go +++ b/cni/network/plugin/main.go @@ -4,6 +4,7 @@ package main import ( + "context" "encoding/json" "fmt" "io" @@ -14,9 +15,9 @@ import ( "github.com/Azure/azure-container-networking/aitelemetry" "github.com/Azure/azure-container-networking/cni" "github.com/Azure/azure-container-networking/cni/api" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/cni/network" "github.com/Azure/azure-container-networking/common" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/nns" "github.com/Azure/azure-container-networking/platform" "github.com/Azure/azure-container-networking/store" @@ -24,6 +25,8 @@ import ( "github.com/containernetworking/cni/pkg/skel" cniTypes "github.com/containernetworking/cni/pkg/types" "github.com/pkg/errors" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) const ( @@ -33,6 +36,8 @@ const ( telemetryNumRetries = 5 telemetryWaitTimeInMilliseconds = 200 name = "azure-vnet" + maxLogFileSizeInMb = 5 + maxLogFileCount = 8 ) // Version is populated by make during build. @@ -56,11 +61,11 @@ func printVersion() { // send error report to hostnetagent if CNI encounters any error. func reportPluginError(reportManager *telemetry.ReportManager, tb *telemetry.TelemetryBuffer, err error) { - log.Printf("Report plugin error") + log.Logger.Error("Report plugin error") reflect.ValueOf(reportManager.Report).Elem().FieldByName("ErrorMessage").SetString(err.Error()) if err := reportManager.SendReport(tb); err != nil { - log.Errorf("SendReport failed due to %v", err) + log.Logger.Error("SendReport failed", zap.Error(err)) } } @@ -78,7 +83,7 @@ func validateConfig(jsonBytes []byte) error { } func getCmdArgsFromEnv() (string, *skel.CmdArgs, error) { - log.Printf("Going to read from stdin") + log.Logger.Info("Going to read from stdin") stdinData, err := io.ReadAll(os.Stdin) if err != nil { return "", nil, fmt.Errorf("error reading from stdin: %v", err) @@ -104,24 +109,24 @@ func handleIfCniUpdate(update func(*skel.CmdArgs) error) (bool, error) { return false, nil } - log.Printf("CNI UPDATE received.") + log.Logger.Info("CNI UPDATE received") _, cmdArgs, err := getCmdArgsFromEnv() if err != nil { - log.Printf("Received error while retrieving cmds from environment: %+v", err) + log.Logger.Error("Received error while retrieving cmds from environment", zap.Error(err)) return isupdate, err } - log.Printf("Retrieved command args for update +%v", cmdArgs) + log.Logger.Info("Retrieved command args for update", zap.Any("args", cmdArgs)) err = validateConfig(cmdArgs.StdinData) if err != nil { - log.Printf("Failed to handle CNI UPDATE, err:%v.", err) + log.Logger.Error("Failed to handle CNI UPDATE", zap.Error(err)) return isupdate, err } err = update(cmdArgs) if err != nil { - log.Printf("Failed to handle CNI UPDATE, err:%v.", err) + log.Logger.Error("Failed to handle CNI UPDATE", zap.Error(err)) return isupdate, err } @@ -129,7 +134,7 @@ func handleIfCniUpdate(update func(*skel.CmdArgs) error) (bool, error) { } func printCNIError(msg string) { - log.Errorf(msg) + log.Logger.Error(msg) cniErr := &cniTypes.Error{ Code: cniTypes.ErrTryAgainLater, Msg: msg, @@ -173,7 +178,7 @@ func rootExecute() error { cniCmd := os.Getenv(cni.Cmd) if cniCmd != cni.CmdVersion { - log.Printf("CNI_COMMAND environment variable set to %s", cniCmd) + log.Logger.Info("Environment variable set", zap.String("CNI_COMMAND", cniCmd)) cniReport.GetReport(pluginName, version, ipamQueryURL) @@ -189,7 +194,7 @@ func rootExecute() error { tb = telemetry.NewTelemetryBuffer() if tberr := tb.Connect(); tberr != nil { - log.Errorf("Cannot connect to telemetry service:%v", tberr) + log.Logger.Error("Cannot connect to telemetry service", zap.Error(tberr)) return errors.Wrap(err, "lock acquire error") } @@ -204,7 +209,7 @@ func rootExecute() error { } sendErr := telemetry.SendCNIMetric(&cniMetric, tb) if sendErr != nil { - log.Errorf("Couldn't send cnilocktimeout metric: %v", sendErr) + log.Logger.Error("Couldn't send cnilocktimeout metric", zap.Error(sendErr)) } } @@ -214,7 +219,7 @@ func rootExecute() error { defer func() { if errUninit := netPlugin.Plugin.UninitializeKeyValueStore(); errUninit != nil { - log.Errorf("Failed to uninitialize key-value store of network plugin, err:%v.\n", errUninit) + log.Logger.Error("Failed to uninitialize key-value store of network plugin", zap.Error(errUninit)) } if recover() != nil { @@ -241,17 +246,17 @@ func rootExecute() error { // used to dump state if cniCmd == cni.CmdGetEndpointsState { - log.Printf("Retrieving state") + log.Logger.Debug("Retrieving state") var simpleState *api.AzureCNIState simpleState, err = netPlugin.GetAllEndpointState("azure") if err != nil { - log.Errorf("Failed to get Azure CNI state, err:%v.\n", err) + log.Logger.Error("Failed to get Azure CNI state", zap.Error(err)) return errors.Wrap(err, "Get all endpoints error") } err = simpleState.PrintResult() if err != nil { - log.Errorf("Failed to print state result to stdout with err %v\n", err) + log.Logger.Error("Failed to print state result to stdout", zap.Error(err)) } return errors.Wrap(err, "Get cni state printresult error") @@ -260,9 +265,9 @@ func rootExecute() error { handled, _ := handleIfCniUpdate(netPlugin.Update) if handled { - log.Printf("CNI UPDATE finished.") + log.Logger.Info("CNI UPDATE finished.") } else if err = netPlugin.Execute(cni.PluginApi(netPlugin)); err != nil { - log.Errorf("Failed to execute network plugin, err:%v.\n", err) + log.Logger.Error("Failed to execute network plugin", zap.Error(err)) } if cniCmd == cni.CmdVersion { @@ -281,6 +286,7 @@ func rootExecute() error { // Main is the entry point for CNI network plugin. func main() { // Initialize and parse command line arguments. + ctx, cancel := context.WithCancel(context.Background()) common.ParseArgs(&args, printVersion) vers := common.GetArg(common.OptVersion).(bool) @@ -289,17 +295,18 @@ func main() { os.Exit(0) } - log.SetName(name) - log.SetLevel(log.LevelInfo) - if err := log.SetTargetLogDirectory(log.TargetLogfile, ""); err != nil { - fmt.Printf("Failed to setup cni logging: %v\n", err) - return + loggerCfg := &log.Config{ + Level: zapcore.DebugLevel, + LogPath: log.LogPath + name + ".log", + MaxSizeInMB: maxLogFileSizeInMb, + MaxBackups: maxLogFileCount, + Name: name, } + log.Initialize(ctx, loggerCfg) - err := rootExecute() - - log.Close() - if err != nil { + if rootExecute() != nil { os.Exit(1) } + + cancel() } diff --git a/cni/plugin.go b/cni/plugin.go index 75b578a463..07a78dba43 100644 --- a/cni/plugin.go +++ b/cni/plugin.go @@ -10,8 +10,8 @@ import ( "runtime" "time" + "github.com/Azure/azure-container-networking/cni/log" "github.com/Azure/azure-container-networking/common" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/platform" "github.com/Azure/azure-container-networking/processlock" "github.com/Azure/azure-container-networking/store" @@ -21,6 +21,7 @@ import ( cniTypesCurr "github.com/containernetworking/cni/pkg/types/100" cniVers "github.com/containernetworking/cni/pkg/version" "github.com/pkg/errors" + "go.uber.org/zap" ) var errEmptyContent = errors.New("read content is zero bytes") @@ -74,7 +75,10 @@ func (plugin *Plugin) Execute(api PluginApi) (err error) { cniErr.Print() err = cniErr - log.Printf("[cni] Recovered panic: %v %v\n", cniErr.Msg, cniErr.Details) + log.Logger.Info("Recovered panic", + zap.String("error", cniErr.Msg), + zap.String("details", cniErr.Details), + zap.String("component", "cni")) } }() @@ -96,8 +100,14 @@ func (plugin *Plugin) DelegateAdd(pluginName string, nwCfg *NetworkConfig) (*cni var result *cniTypesCurr.Result var err error - log.Printf("[cni] Calling plugin %v ADD", pluginName) - defer func() { log.Printf("[cni] Plugin %v returned result:%+v, err:%v.", pluginName, result, err) }() + log.Logger.Info("Calling ADD", zap.String("plugin", pluginName), zap.String("component", "cni")) + defer func() { + log.Logger.Info("Plugin returned", + zap.String("plugin", pluginName), + zap.Any("result", result), + zap.Error(err), + zap.String("component", "cni")) + }() os.Setenv(Cmd, CmdAdd) @@ -118,8 +128,16 @@ func (plugin *Plugin) DelegateAdd(pluginName string, nwCfg *NetworkConfig) (*cni func (plugin *Plugin) DelegateDel(pluginName string, nwCfg *NetworkConfig) error { var err error - log.Printf("[cni] Calling plugin %v DEL nwCfg:%+v.", pluginName, nwCfg) - defer func() { log.Printf("[cni] Plugin %v returned err:%v.", pluginName, err) }() + log.Logger.Info("Calling DEL", + zap.String("plugin", pluginName), + zap.Any("config", nwCfg), + zap.String("component", "cni")) + defer func() { + log.Logger.Info("Plugin eturned", + zap.String("plugin", pluginName), + zap.Error(err), + zap.String("component", "cni")) + }() os.Setenv(Cmd, CmdDel) @@ -141,7 +159,9 @@ func (plugin *Plugin) Error(err error) *cniTypes.Error { cniErr = &cniTypes.Error{Code: 100, Msg: err.Error()} } - log.Printf("[%v] %+v.", plugin.Name, cniErr.Error()) + log.Logger.Error("", + zap.String("plugin", plugin.Name), + zap.String("error", cniErr.Error())) return cniErr } @@ -154,7 +174,9 @@ func (plugin *Plugin) Errorf(format string, args ...interface{}) *cniTypes.Error // RetriableError logs and returns a CNI error with the TryAgainLater error code func (plugin *Plugin) RetriableError(err error) *cniTypes.Error { tryAgainErr := cniTypes.NewError(cniTypes.ErrTryAgainLater, err.Error(), "") - log.Printf("[%v] %+v.", plugin.Name, tryAgainErr.Error()) + log.Logger.Error("", + zap.String("name", plugin.Name), + zap.String("error", tryAgainErr.Error())) return tryAgainErr } @@ -164,13 +186,14 @@ func (plugin *Plugin) InitializeKeyValueStore(config *common.PluginConfig) error if plugin.Store == nil { lockclient, err := processlock.NewFileLock(platform.CNILockPath + plugin.Name + store.LockExtension) if err != nil { - log.Printf("[cni] Error initializing file lock:%v", err) + log.Logger.Error("Error initializing file lock", + zap.Error(err), zap.String("component", "cni")) return errors.Wrap(err, "error creating new filelock") } plugin.Store, err = store.NewJsonFileStore(platform.CNIRuntimePath+plugin.Name+".json", lockclient) if err != nil { - log.Printf("[cni] Failed to create store: %v.", err) + log.Logger.Error("Failed to create store", zap.Error(err), zap.String("component", "cni")) return err } } @@ -180,8 +203,9 @@ func (plugin *Plugin) InitializeKeyValueStore(config *common.PluginConfig) error if runtime.GOOS == "windows" { lockTimeoutValue = store.DefaultLockTimeoutWindows } + // Acquire store lock. if err := plugin.Store.Lock(lockTimeoutValue); err != nil { - log.Printf("[cni] Failed to lock store: %v.", err) + log.Logger.Error("[cni] Failed to lock store", zap.Error(err)) return errors.Wrap(err, "error Acquiring store lock") } @@ -195,7 +219,7 @@ func (plugin *Plugin) UninitializeKeyValueStore() error { if plugin.Store != nil { err := plugin.Store.Unlock() if err != nil { - log.Printf("[cni] Failed to unlock store: %v.", err) + log.Logger.Error("Failed to unlock store", zap.Error(err), zap.String("component", "cni")) return err } } diff --git a/cni/telemetry/service/telemetrymain.go b/cni/telemetry/service/telemetrymain.go index 386369b316..e6ea2f9d1e 100644 --- a/cni/telemetry/service/telemetrymain.go +++ b/cni/telemetry/service/telemetrymain.go @@ -10,9 +10,11 @@ import ( "time" "github.com/Azure/azure-container-networking/aitelemetry" + "github.com/Azure/azure-container-networking/cni/log" acn "github.com/Azure/azure-container-networking/common" - "github.com/Azure/azure-container-networking/log" "github.com/Azure/azure-container-networking/telemetry" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) const ( @@ -25,6 +27,8 @@ const ( pluginName = "AzureCNI" azureVnetTelemetry = "azure-vnet-telemetry" configExtension = ".config" + maxLogFileSizeInMb = 5 + maxLogFileCount = 8 ) var version string @@ -37,22 +41,8 @@ var args = acn.ArgumentList{ Type: "int", DefaultValue: acn.OptLogLevelInfo, ValueMap: map[string]interface{}{ - acn.OptLogLevelInfo: log.LevelInfo, - acn.OptLogLevelDebug: log.LevelDebug, - }, - }, - { - Name: acn.OptLogTarget, - Shorthand: acn.OptLogTargetAlias, - Description: "Set the logging target", - Type: "int", - DefaultValue: acn.OptLogTargetFile, - ValueMap: map[string]interface{}{ - acn.OptLogTargetSyslog: log.TargetSyslog, - acn.OptLogTargetStderr: log.TargetStderr, - acn.OptLogTargetFile: log.TargetLogfile, - acn.OptLogStdout: log.TargetStdout, - acn.OptLogMultiWrite: log.TargetStdOutAndLogFile, + acn.OptLogLevelInfo: zapcore.InfoLevel, + acn.OptLogLevelError: zapcore.ErrorLevel, }, }, { @@ -115,11 +105,10 @@ func main() { var config telemetry.TelemetryConfig var configPath string var err error + ctx, cancel := context.WithCancel(context.Background()) acn.ParseArgs(&args, printVersion) - logTarget := acn.GetArg(acn.OptLogTarget).(int) - logDirectory := acn.GetArg(acn.OptLogLocation).(string) - logLevel := acn.GetArg(acn.OptLogLevel).(int) + logLevel := acn.GetArg(acn.OptLogLevel).(zapcore.Level) configDirectory := acn.GetArg(acn.OptTelemetryConfigDir).(string) vers := acn.GetArg(acn.OptVersion).(bool) @@ -128,15 +117,16 @@ func main() { os.Exit(0) } - log.SetName(azureVnetTelemetry) - log.SetLevel(logLevel) - err = log.SetTargetLogDirectory(logTarget, logDirectory) - if err != nil { - fmt.Printf("Failed to configure logging: %v\n", err) - return + loggerCfg := &log.Config{ + Level: logLevel, + LogPath: log.LogPath + azureVnetTelemetry + ".log", + MaxSizeInMB: maxLogFileSizeInMb, + MaxBackups: maxLogFileCount, + Name: azureVnetTelemetry, } + log.Initialize(ctx, loggerCfg) - log.Logf("args %+v", os.Args) + log.Logger.Info("Telemetry invocation info", zap.Any("arguments", os.Args)) if runtime.GOOS == "linux" { configPath = fmt.Sprintf("%s/%s%s", configDirectory, azureVnetTelemetry, configExtension) @@ -144,18 +134,21 @@ func main() { configPath = fmt.Sprintf("%s\\%s%s", configDirectory, azureVnetTelemetry, configExtension) } - log.Logf("[Telemetry] Config path: %s", configPath) + log.Logger.Info("Config path", + zap.String("path", configPath), zap.String("component", "telemetry")) config, err = telemetry.ReadConfigFile(configPath) if err != nil { - log.Logf("[Telemetry] Error reading telemetry config: %v", err) + log.Logger.Error("Error reading telemetry config", + zap.Error(err), + zap.String("component", "telemetry")) } - log.Logf("read config returned %+v", config) + log.Logger.Info("read config returned", zap.Any("config", config)) setTelemetryDefaults(&config) - log.Logf("Config after setting defaults %+v", config) + log.Logger.Info("Config after setting defaults", zap.Any("config", config)) // Cleaning up orphan socket if present tbtemp := telemetry.NewTelemetryBuffer() @@ -164,13 +157,14 @@ func main() { for { tb = telemetry.NewTelemetryBuffer() - log.Logf("[Telemetry] Starting telemetry server") + log.Logger.Info("Starting telemetry server", zap.String("component", "telemetry")) err = tb.StartServer() if err == nil || tb.FdExists { break } - log.Logf("[Telemetry] Telemetry service starting failed: %v", err) + log.Logger.Error("Telemetry service starting failed", + zap.Error(err), zap.String("component", "telemetry")) tb.Cleanup(telemetry.FdName) time.Sleep(time.Millisecond * 200) } @@ -187,11 +181,12 @@ func main() { GetEnvRetryWaitTimeInSecs: config.GetEnvRetryWaitTimeInSecs, } - err = telemetry.CreateAITelemetryHandle(aiConfig, config.DisableAll, config.DisableTrace, config.DisableMetric) - log.Printf("[Telemetry] AI Handle creation status:%v", err) - log.Logf("[Telemetry] Report to host for an interval of %d seconds", config.ReportToHostIntervalInSeconds) + if telemetry.CreateAITelemetryHandle(aiConfig, config.DisableAll, config.DisableTrace, config.DisableMetric) != nil { + log.Logger.Error("[Telemetry] AI Handle creation error", zap.Error(err)) + } + log.Logger.Info("[Telemetry] Report to host interval", zap.Duration("seconds", config.ReportToHostIntervalInSeconds)) tb.PushData(context.Background()) telemetry.CloseAITelemetryHandle() - log.Close() + cancel() } diff --git a/common/config.go b/common/config.go index bbcbcc752d..ababe24d1e 100644 --- a/common/config.go +++ b/common/config.go @@ -24,6 +24,7 @@ const ( OptLogLevelAlias = "l" OptLogLevelInfo = "info" OptLogLevelDebug = "debug" + OptLogLevelError = "error" // Logging target. OptLogTarget = "log-target" diff --git a/go.mod b/go.mod index 4151a6fc99..0e4cab4a6a 100644 --- a/go.mod +++ b/go.mod @@ -37,6 +37,7 @@ require ( golang.org/x/sys v0.6.0 google.golang.org/grpc v1.52.0 google.golang.org/protobuf v1.28.1 + gopkg.in/natefinch/lumberjack.v2 v2.0.0 k8s.io/api v0.26.3 k8s.io/apiextensions-apiserver v0.26.1 k8s.io/apimachinery v0.26.3 diff --git a/go.sum b/go.sum index cba6acdc8e..e6001a58ea 100644 --- a/go.sum +++ b/go.sum @@ -1248,6 +1248,7 @@ gopkg.in/inf.v0 v0.9.1 h1:73M5CoZyi3ZLMOyDlQh031Cx6N9NDJ2Vvfl76EDAgDc= gopkg.in/inf.v0 v0.9.1/go.mod h1:cWUDdTG/fYaXco+Dcufb5Vnc6Gp2YChqWtbxRZE0mXw= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= +gopkg.in/natefinch/lumberjack.v2 v2.0.0 h1:1Lc07Kr7qY4U2YPouBjpCLxpiyxIVoxqXgkXLknAOE8= gopkg.in/natefinch/lumberjack.v2 v2.0.0/go.mod h1:l0ndWWf7gzL7RNwBG7wST/UCcT4T24xpD6X8LsfU/+k= gopkg.in/resty.v1 v1.12.0/go.mod h1:mDo4pnntr5jdWRML875a/NmxYqAlA73dVijT2AXvQQo= gopkg.in/square/go-jose.v2 v2.2.2/go.mod h1:M9dMgbHiYLoDGQrXy7OpJDJWiKiU//h+vD76mk0e1AI=