fix: don't print stack trace of error for certain logs to prevent spam (#2904)

* reduce stack trace spam by wrapping errors in custom type

* differentiate logs

* move custom error to log package

* address feedback

* add uts

* address linter issues

cni/log/logger_error.go

@@ -0,0 +1,45 @@
+package log
+
+import (
+	"errors"
+	"fmt"
+	"io"
+)
+
+type ErrorWithoutStackTrace struct {
+	error
+}
+
+func (l *ErrorWithoutStackTrace) Error() string {
+	if l.error == nil {
+		return ""
+	}
+	return l.error.Error()
+}
+
+func (l *ErrorWithoutStackTrace) Format(s fmt.State, verb rune) {
+	// if the error is nil, nothing should happen
+	if l.error == nil {
+		return
+	}
+	v := verb
+	// replace uses of %v with %s
+	if v == 'v' {
+		v = 's'
+	}
+	// if the error implements formatter (which it should)
+	var formatter fmt.Formatter
+	if errors.As(l.error, &formatter) {
+		formatter.Format(s, v)
+	} else {
+		_, _ = io.WriteString(s, l.error.Error())
+	}
+}
+
+func (l *ErrorWithoutStackTrace) Unwrap() error {
+	return l.error
+}
+
+func NewErrorWithoutStackTrace(err error) *ErrorWithoutStackTrace {
+	return &ErrorWithoutStackTrace{err}
+}

cni/log/logger_test.go

@@ -0,0 +1,55 @@
+package log
+
+import (
+	"bytes"
+	"fmt"
+	"testing"
+
+	"github.com/pkg/errors"
+	"github.com/stretchr/testify/require"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+var errInternal = errors.New("internal error")
+
+func TestLoggerError(t *testing.T) {
+	require := require.New(t) //nolint:gocritic
+
+	var buf bytes.Buffer
+
+	// Create a zap core that writes logs to the buffer
+	core := zapcore.NewCore(
+		zapcore.NewJSONEncoder(zapcore.EncoderConfig{}),
+		zapcore.AddSync(&buf),
+		zapcore.DebugLevel,
+	)
+	logger := zap.New(core)
+
+	wrappedError := errors.Wrap(errInternal, "wrapped message")
+	errorNoStack := NewErrorWithoutStackTrace(wrappedError)
+
+	logger.Info("Error", zap.Error(wrappedError))
+	require.Contains(buf.String(), "errorVerbose")
+	fmt.Println(buf.String())
+	buf.Reset()
+
+	// Error verbose field should be omitted from the error without stack trace error
+	logger.Info("ErrorWithoutStackTrace", zap.Error(errorNoStack))
+	require.NotContains(buf.String(), "errorVerbose")
+	require.Contains(buf.String(), "wrapped message")
+	require.Contains(buf.String(), "internal error")
+	fmt.Println(buf.String())
+	buf.Reset()
+
+	// Even if the embedded error is nil, the error should still display an empty string and not panic
+	logger.Info("ErrorWithoutStackTrace nil internal error", zap.Error(NewErrorWithoutStackTrace(nil)))
+	require.Contains(buf.String(), "\"error\":\"\"")
+	fmt.Println(buf.String())
+	buf.Reset()
+
+	// should be able to unwrap the error without a stack trace
+	require.ErrorIs(errorNoStack, errInternal)
+	// Even if the embedded error is nil, should function properly
+	require.NotErrorIs(&ErrorWithoutStackTrace{error: nil}, errorNoStack)
+}

cni/network/invoker_cns.go

@@ -7,6 +7,7 @@ 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"
@@ -136,7 +137,6 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
 			}
 		} else {
 			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")
 		}
@@ -321,8 +321,9 @@ func (invoker *CNSIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkConf
 				if errors.As(err, &connectionErr) {
 					addErr := fsnotify.AddFile(ipConfigs.PodInterfaceID, args.ContainerID, watcherPath)
 					if addErr != nil {
-						logger.Error("Failed to add file to watcher", zap.String("podInterfaceID", ipConfigs.PodInterfaceID), zap.String("containerID", args.ContainerID), zap.Error(addErr))
-						return errors.Wrap(addErr, fmt.Sprintf("failed to add file to watcher with containerID %s and podInterfaceID %s", args.ContainerID, ipConfigs.PodInterfaceID))
+						logger.Error("Failed to add file to watcher (unsupported api path)",
+							zap.String("podInterfaceID", ipConfigs.PodInterfaceID), zap.String("containerID", args.ContainerID), zap.Error(log.NewErrorWithoutStackTrace(addErr)))
+						return errors.Wrap(addErr, fmt.Sprintf("failed to add file to watcher with containerID %s and podInterfaceID %s (unsupported api path)", args.ContainerID, ipConfigs.PodInterfaceID))
 					}
 				} else {
 					logger.Error("Failed to release IP address from CNS using ReleaseIPAddress ",
@@ -336,7 +337,8 @@ func (invoker *CNSIPAMInvoker) Delete(address *net.IPNet, nwCfg *cni.NetworkConf
 			if errors.As(err, &connectionErr) {
 				addErr := fsnotify.AddFile(ipConfigs.PodInterfaceID, args.ContainerID, watcherPath)
 				if addErr != nil {
-					logger.Error("Failed to add file to watcher", zap.String("podInterfaceID", ipConfigs.PodInterfaceID), zap.String("containerID", args.ContainerID), zap.Error(addErr))
+					logger.Error("Failed to add file to watcher", zap.String("podInterfaceID", ipConfigs.PodInterfaceID), zap.String("containerID", args.ContainerID),
+						zap.Error(log.NewErrorWithoutStackTrace(addErr)))
 					return errors.Wrap(addErr, fmt.Sprintf("failed to add file to watcher with containerID %s and podInterfaceID %s", args.ContainerID, ipConfigs.PodInterfaceID))
 				}
 			} else {

cni/network/network.go

@@ -16,6 +16,7 @@ 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"
@@ -474,7 +475,7 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
 		logger.Info("ADD command completed for",
 			zap.String("pod", k8sPodName),
 			zap.Any("IPs", cniResult.IPs),
-			zap.Error(err))
+			zap.Error(log.NewErrorWithoutStackTrace(err)))
 	}()
 
 	ipamAddResult = IPAMAddResult{interfaceInfo: make(map[string]network.InterfaceInfo)}
@@ -936,7 +937,7 @@ func (plugin *NetPlugin) Get(args *cniSkel.CmdArgs) error {
 		}
 
 		logger.Info("GET command completed", zap.Any("result", result),
-			zap.Error(err))
+			zap.Error(log.NewErrorWithoutStackTrace(err)))
 	}()
 
 	// Parse network configuration from stdin.
@@ -1025,7 +1026,7 @@ func (plugin *NetPlugin) Delete(args *cniSkel.CmdArgs) error {
 	defer func() {
 		logger.Info("DEL command completed",
 			zap.String("pod", k8sPodName),
-			zap.Error(err))
+			zap.Error(log.NewErrorWithoutStackTrace(err)))
 	}()
 
 	// Parse network configuration from stdin.
@@ -1269,7 +1270,7 @@ func (plugin *NetPlugin) Update(args *cniSkel.CmdArgs) error {
 
 		logger.Info("UPDATE command completed",
 			zap.Any("result", result),
-			zap.Error(err))
+			zap.Error(log.NewErrorWithoutStackTrace(err)))
 	}()
 
 	// Parse Pod arguments.