From 1eed84ef612c121be5d8a9e3df8af23d32f33981 Mon Sep 17 00:00:00 2001 From: sivakami-projects <126191544+sivakami-projects@users.noreply.github.com> Date: Thu, 18 Apr 2024 11:17:18 -0700 Subject: [PATCH] ETW logging implementation in CNI (#2668) * Add ETW support in zap logger for CNI Added a zap WriteSyncer to enable direct ETW logging through zap core, maintaining existing logging structure while to ETW from CNI. * Transform 'zapetw' package into a standalone module for external use * Revert "Transform 'zapetw' package into a standalone module for external use" This reverts commit 63050ed68d353e43ae1b1fedd11b8e99259b7a28. * Relocate EtwWriteSyncer.go to zapetw module for improved organization - Renamed and moved cni/log/ETWZapCore/EtwWriteSyncer.go to zapetw/write_syncer.go. * Applied gofumpt formatting to adhere to style guidelines. * 1. Implemented platform-specific ETW logging enhancements. 2. Refactor ETW initialization into dedicated method and zapetw package. * Changed InitETWLogger method signature for Linux. * Wrapped error messages at each level of the call hierarchy. * Removed punctuation marks from error messages. * Wrapped error messages with errors.wrap method. * Added comments for clarity. * implemented zap.core for ETW. * Fixed lint issues. * Catch errors from etw.writeEvent method. * Renamed provider. * Abstracted etw core creation in logger_windows. Removed unsupported error from logger_linux to keep the behaviour uniform. * renamed unused parameter. * Renamed variable to lower camel case as it is private. Removed additional local reference. * fixed variable name. * Added comment. * Renamed ETW provider, removed application names from the provider name. --------- Co-authored-by: Sivakami Subramaniam --- cni/log/logger.go | 18 +++++--- cni/log/logger_linux.go | 8 ++++ cni/log/logger_windows.go | 28 ++++++++++++ zapetw/core_windows.go | 92 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 140 insertions(+), 6 deletions(-) create mode 100644 zapetw/core_windows.go diff --git a/cni/log/logger.go b/cni/log/logger.go index 6ee40b6e1..1f47a4ec9 100644 --- a/cni/log/logger.go +++ b/cni/log/logger.go @@ -17,6 +17,8 @@ var ( const ( maxLogFileSizeInMb = 5 maxLogFileCount = 8 + etwCNIEventName = "Azure-CNI" + loggingLevel = zapcore.DebugLevel ) func initZapLog(logFile string) *zap.Logger { @@ -30,13 +32,17 @@ func initZapLog(logFile string) *zap.Logger { encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder jsonEncoder := zapcore.NewJSONEncoder(encoderConfig) - core := zapcore.NewCore(jsonEncoder, logFileCNIWriter, zapcore.DebugLevel) - Logger := zap.New(core) - return Logger + textFileCore := zapcore.NewCore(jsonEncoder, logFileCNIWriter, loggingLevel) + core, err := JoinPlatformCores(textFileCore, loggingLevel) + if err != nil { + // If we fail to join the platform cores, fallback to the original core. + core = textFileCore + } + return zap.New(core, zap.AddCaller()).With(zap.Int("pid", os.Getpid())) } var ( - CNILogger = initZapLog(zapCNILogFile).With(zap.Int("pid", os.Getpid())) - IPamLogger = initZapLog(zapIpamLogFile).With(zap.Int("pid", os.Getpid())) - TelemetryLogger = initZapLog(zapTelemetryLogFile).With(zap.Int("pid", os.Getpid())) + CNILogger = initZapLog(zapCNILogFile) + IPamLogger = initZapLog(zapIpamLogFile) + TelemetryLogger = initZapLog(zapTelemetryLogFile) ) diff --git a/cni/log/logger_linux.go b/cni/log/logger_linux.go index 123c0fa0c..3fb9433f1 100644 --- a/cni/log/logger_linux.go +++ b/cni/log/logger_linux.go @@ -1,6 +1,14 @@ package log +import ( + "go.uber.org/zap/zapcore" +) + const ( // LogPath is the path where log files are stored. LogPath = "/var/log/" ) + +func JoinPlatformCores(c zapcore.Core, _ zapcore.Level) (zapcore.Core, error) { + return c, nil +} diff --git a/cni/log/logger_windows.go b/cni/log/logger_windows.go index 207b74003..2ac46204f 100644 --- a/cni/log/logger_windows.go +++ b/cni/log/logger_windows.go @@ -1,6 +1,34 @@ package log +import ( + "github.com/Azure/azure-container-networking/zapetw" + "github.com/pkg/errors" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + const ( // LogPath is the path where log files are stored. LogPath = "" ) + +func JoinPlatformCores(core zapcore.Core, loggingLevel zapcore.Level) (zapcore.Core, error) { + etwcore, err := etwCore(loggingLevel) + if err != nil { + return core, err + } + teecore := zapcore.NewTee(core, etwcore) + return teecore, nil +} + +func etwCore(loggingLevel zapcore.Level) (zapcore.Core, error) { + encoderConfig := zap.NewProductionEncoderConfig() + encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder + jsonEncoder := zapcore.NewJSONEncoder(encoderConfig) + + etwcore, err := zapetw.NewETWCore(etwCNIEventName, jsonEncoder, loggingLevel) + if err != nil { + return nil, errors.Wrap(err, "failed to create ETW core") + } + return etwcore, nil +} diff --git a/zapetw/core_windows.go b/zapetw/core_windows.go new file mode 100644 index 000000000..955b1149f --- /dev/null +++ b/zapetw/core_windows.go @@ -0,0 +1,92 @@ +package zapetw + +import ( + "github.com/Microsoft/go-winio/pkg/etw" + "github.com/pkg/errors" + "go.uber.org/zap/zapcore" +) + +// - +const providername = "ACN-Monitoring" + +type ETWCore struct { + provider *etw.Provider + eventName string + encoder zapcore.Encoder + fields []zapcore.Field + zapcore.LevelEnabler +} + +func NewETWCore(eventName string, encoder zapcore.Encoder, levelEnabler zapcore.LevelEnabler) (*ETWCore, error) { + provider, err := etw.NewProviderWithOptions(providername) + if err != nil { + return nil, errors.Wrap(err, "failed to create ETW provider") + } + return &ETWCore{ + provider: provider, + eventName: eventName, + encoder: encoder, + LevelEnabler: levelEnabler, + }, nil +} + +func (core *ETWCore) With(fields []zapcore.Field) zapcore.Core { + return &ETWCore{ + provider: core.provider, + eventName: core.eventName, + encoder: core.encoder, + LevelEnabler: core.LevelEnabler, + fields: append(core.fields, fields...), + } +} + +// Check is an implementation of the zapcore.Core interface's Check method. +// Check determines whether the logger core is enabled at the supplied zapcore.Entry's Level. +// If enabled, it adds the core to the CheckedEntry and returns it, otherwise returns the CheckedEntry unchanged. +func (core *ETWCore) Check(entry zapcore.Entry, checkedEntry *zapcore.CheckedEntry) *zapcore.CheckedEntry { + if core.Enabled(entry.Level) { + return checkedEntry.AddCore(entry, core) + } + return checkedEntry +} + +func (core *ETWCore) Write(entry zapcore.Entry, fields []zapcore.Field) error { + etwLevel := zapLevelToETWLevel(entry.Level) + + buffer, err := core.encoder.EncodeEntry(entry, fields) + if err != nil { + return errors.Wrap(err, "failed to encode entry") + } + + err = core.provider.WriteEvent( + core.eventName, + []etw.EventOpt{etw.WithLevel(etwLevel)}, + []etw.FieldOpt{etw.StringField("Message", buffer.String())}, + ) + if err != nil { + return errors.Wrap(err, "failed to write event") + } + + return nil +} + +func (core *ETWCore) Sync() error { + return nil +} + +func zapLevelToETWLevel(level zapcore.Level) etw.Level { + switch level { + case zapcore.DebugLevel: + return etw.LevelVerbose // ETW doesn't have a Debug level, so Verbose is used instead. + case zapcore.InfoLevel: + return etw.LevelInfo + case zapcore.WarnLevel: + return etw.LevelWarning + case zapcore.ErrorLevel: + return etw.LevelError + case zapcore.DPanicLevel, zapcore.PanicLevel, zapcore.FatalLevel, zapcore.InvalidLevel: + return etw.LevelCritical + default: + return etw.LevelAlways + } +}