From 99f273f9afd901cd4c3b9de555cfdf1c17b1dcb3 Mon Sep 17 00:00:00 2001 From: Pavel Pogodaev Date: Fri, 20 Sep 2024 14:34:05 +0300 Subject: [PATCH] [#461] Configure logger sampling policy Signed-off-by: Pavel Pogodaev --- cmd/s3-gw/app_settings.go | 76 +++++++++++++++++++++++++++------------ config/config.env | 4 +++ config/config.yaml | 5 +++ docs/configuration.md | 17 ++++++--- 4 files changed, 76 insertions(+), 26 deletions(-) diff --git a/cmd/s3-gw/app_settings.go b/cmd/s3-gw/app_settings.go index 0cc067e..94db37d 100644 --- a/cmd/s3-gw/app_settings.go +++ b/cmd/s3-gw/app_settings.go @@ -41,6 +41,8 @@ const ( defaultStreamTimeout = 10 * time.Second defaultShutdownTimeout = 15 * time.Second + defaultLoggerSamplerInterval = 1 * time.Second + defaultGracefulCloseOnSwitchTimeout = 10 * time.Second defaultPoolErrorThreshold uint32 = 100 @@ -81,6 +83,11 @@ const ( // Settings. cfgLoggerLevel = "logger.level" cfgLoggerDestination = "logger.destination" + cfgLoggerSamplingEnabled = "logger.sampling.enabled" + cfgLoggerSamplingInitial = "logger.sampling.initial" + cfgLoggerSamplingThereafter = "logger.sampling.thereafter" + cfgLoggerSamplingInterval = "logger.sampling.interval" + // HttpLogging. cfgHTTPLoggingEnabled = "http_logging.enabled" cfgHTTPLoggingMaxBody = "http_logging.max_body" @@ -788,6 +795,10 @@ func newSettings() *viper.Viper { // logger: v.SetDefault(cfgLoggerLevel, "debug") v.SetDefault(cfgLoggerDestination, "stdout") + v.SetDefault(cfgLoggerSamplingEnabled, false) + v.SetDefault(cfgLoggerSamplingThereafter, 100) + v.SetDefault(cfgLoggerSamplingInitial, 100) + v.SetDefault(cfgLoggerSamplingInterval, defaultLoggerSamplerInterval) // http logger v.SetDefault(cfgHTTPLoggingEnabled, false) @@ -1031,9 +1042,9 @@ func pickLogger(v *viper.Viper) *Logger { switch dest { case destinationStdout: - return newStdoutLogger(lvl) + return newStdoutLogger(v, lvl) case destinationJournald: - return newJournaldLogger(lvl) + return newJournaldLogger(v, lvl) default: panic(fmt.Sprintf("wrong destination for logger: %s", dest)) } @@ -1046,53 +1057,74 @@ func pickLogger(v *viper.Viper) *Logger { // - parameterized level (debug by default) // - console encoding // - ISO8601 time encoding +// - sampling intervals // // and atomic log level to dynamically change it. // // Logger records a stack trace for all messages at or above fatal level. // // See also zapcore.Level, zap.NewProductionConfig, zap.AddStacktrace. -func newStdoutLogger(lvl zapcore.Level) *Logger { - c := zap.NewProductionConfig() - c.Level = zap.NewAtomicLevelAt(lvl) - c.Encoding = "console" - c.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder +func newStdoutLogger(v *viper.Viper, lvl zapcore.Level) *Logger { + stdout := zapcore.AddSync(os.Stderr) + level := zap.NewAtomicLevelAt(lvl) - l, err := c.Build( - zap.AddStacktrace(zap.NewAtomicLevelAt(zap.FatalLevel)), - ) - if err != nil { - panic(fmt.Sprintf("build zap logger instance: %v", err)) - } + consoleOutCore := zapcore.NewCore(newLogEncoder(), stdout, level) + + consoleOutCore = samplingEnabling(v, consoleOutCore) return &Logger{ - logger: l, - lvl: c.Level, + logger: zap.New(consoleOutCore, zap.AddStacktrace(zap.NewAtomicLevelAt(zap.FatalLevel))), + lvl: level, } } -func newJournaldLogger(lvl zapcore.Level) *Logger { - c := zap.NewProductionConfig() - c.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder - c.Level = zap.NewAtomicLevelAt(lvl) +func newJournaldLogger(v *viper.Viper, lvl zapcore.Level) *Logger { + level := zap.NewAtomicLevelAt(lvl) - encoder := zapjournald.NewPartialEncoder(zapcore.NewConsoleEncoder(c.EncoderConfig), zapjournald.SyslogFields) + encoder := zapjournald.NewPartialEncoder(newLogEncoder(), zapjournald.SyslogFields) - core := zapjournald.NewCore(c.Level, encoder, &journald.Journal{}, zapjournald.SyslogFields) + core := zapjournald.NewCore(level, encoder, &journald.Journal{}, zapjournald.SyslogFields) coreWithContext := core.With([]zapcore.Field{ zapjournald.SyslogFacility(zapjournald.LogDaemon), zapjournald.SyslogIdentifier(), zapjournald.SyslogPid(), }) + coreWithContext = samplingEnabling(v, coreWithContext) + l := zap.New(coreWithContext, zap.AddStacktrace(zap.NewAtomicLevelAt(zap.FatalLevel))) return &Logger{ logger: l, - lvl: c.Level, + lvl: level, } } +func newLogEncoder() zapcore.Encoder { + c := zap.NewProductionEncoderConfig() + c.EncodeTime = zapcore.ISO8601TimeEncoder + + return zapcore.NewConsoleEncoder(c) +} + +func samplingEnabling(v *viper.Viper, core zapcore.Core) zapcore.Core { + // Zap samples by logging the first cgfLoggerSamplingInitial entries with a given level + // and message within the specified time interval. + // In the above config, only the first cgfLoggerSamplingInitial log entries with the same level and message + // are recorded in cfgLoggerSamplingInterval interval. Every other log entry will be dropped within the interval since + // cfgLoggerSamplingThereafter is specified here. + if v.GetBool(cfgLoggerSamplingEnabled) { + core = zapcore.NewSamplerWithOptions( + core, + v.GetDuration(cfgLoggerSamplingInterval), + v.GetInt(cfgLoggerSamplingInitial), + v.GetInt(cfgLoggerSamplingThereafter), + ) + } + + return core +} + func getLogLevel(v *viper.Viper) (zapcore.Level, error) { var lvl zapcore.Level lvlStr := v.GetString(cfgLoggerLevel) diff --git a/config/config.env b/config/config.env index 64d433c..510dcd2 100644 --- a/config/config.env +++ b/config/config.env @@ -51,6 +51,10 @@ S3_GW_CONFIG=/path/to/config/yaml # Logger S3_GW_LOGGER_LEVEL=debug +S3_GW_LOGGER_SAMPLING_ENABLED=false +S3_GW_LOGGER_SAMPLING_INITIAL=100 +S3_GW_LOGGER_SAMPLING_THEREAFTER=100 +S3_GW_LOGGER_SAMPLING_INTERVAL=1s # HTTP logger S3_GW_HTTP_LOGGING_ENABLED=false diff --git a/config/config.yaml b/config/config.yaml index 63768e0..c3dccac 100644 --- a/config/config.yaml +++ b/config/config.yaml @@ -55,6 +55,11 @@ vhs: logger: level: debug destination: stdout + sampling: + enabled: false + initial: 100 + thereafter: 100 + interval: 1s # log http request data (URI, headers, query, etc) http_logging: diff --git a/docs/configuration.md b/docs/configuration.md index b7c1b71..df3d022 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -370,12 +370,21 @@ server: logger: level: debug destination: stdout + sampling: + enabled: false + initial: 100 + thereafter: 100 + interval: 1s ``` -| Parameter | Type | SIGHUP reload | Default value | Description | -|---------------|----------|---------------|---------------|----------------------------------------------------------------------------------------------------| -| `level` | `string` | yes | `debug` | Logging level.
Possible values: `debug`, `info`, `warn`, `error`, `dpanic`, `panic`, `fatal`. | -| `destination` | `string` | no | `stdout` | Destination for logger: `stdout` or `journald` | +| Parameter | Type | SIGHUP reload | Default value | Description | +|-----------------------|------------|---------------|---------------|----------------------------------------------------------------------------------------------------| +| `level` | `string` | yes | `debug` | Logging level.
Possible values: `debug`, `info`, `warn`, `error`, `dpanic`, `panic`, `fatal`. | +| `destination` | `string` | no | `stdout` | Destination for logger: `stdout` or `journald` | +| `sampling.enabled` | `bool` | no | false | Sampling enabling flag. | +| `sampling.initial` | `int` | no | '100' | Sampling count of first log entries. | +| `sampling.thereafter` | `int` | no | '100' | Sampling count of entries after an `interval`. | +| `sampling.interval` | `duration` | no | '1s' | Sampling interval of messaging similar entries. | ### `http_logging` section