From 6a7de761f4f66523eb8fcbd2c751451f78076572 Mon Sep 17 00:00:00 2001 From: Roman Khavronenko <roman@victoriametrics.com> Date: Mon, 20 Mar 2023 16:08:30 +0100 Subject: [PATCH] vmalert: support logs suppressing during config reloads (#3973) * vmalert: support logs suppressing during config reloads The change is mostly required for ENT version of vmalert, since it supports object-storage for config files. Reading data from object storage could be time-consuming, so vmalert emits logs to track the progress. However, these logs are mostly needed on start or on manual config reload. Printing these logs each time `rule.configCheckInterval` is triggered would too verbose. So the change allows to control logs emitting during config reloads. Now, logs are emitted during start up or when SIGHUP is receieved. For periodicall config checks logs emitted by config pkg are suppressed. Signed-off-by: hagen1778 <roman@victoriametrics.com> * vmalert: review fixes Signed-off-by: hagen1778 <roman@victoriametrics.com> --------- Signed-off-by: hagen1778 <roman@victoriametrics.com> --- app/vmalert/config/config.go | 16 ++++++-- app/vmalert/config/fs.go | 12 +++--- app/vmalert/config/log/logger.go | 59 +++++++++++++++++++++++++++ app/vmalert/config/log/logger_test.go | 54 ++++++++++++++++++++++++ app/vmalert/main.go | 7 +++- 5 files changed, 137 insertions(+), 11 deletions(-) create mode 100644 app/vmalert/config/log/logger.go create mode 100644 app/vmalert/config/log/logger_test.go diff --git a/app/vmalert/config/config.go b/app/vmalert/config/config.go index 2de93fc555..35e00978f2 100644 --- a/app/vmalert/config/config.go +++ b/app/vmalert/config/config.go @@ -10,9 +10,9 @@ import ( "gopkg.in/yaml.v2" + "github.com/VictoriaMetrics/VictoriaMetrics/app/vmalert/config/log" "github.com/VictoriaMetrics/VictoriaMetrics/app/vmalert/utils" "github.com/VictoriaMetrics/VictoriaMetrics/lib/envtemplate" - "github.com/VictoriaMetrics/VictoriaMetrics/lib/logger" "github.com/VictoriaMetrics/VictoriaMetrics/lib/promutils" ) @@ -199,9 +199,17 @@ func (r *Rule) Validate() error { // ValidateTplFn must validate the given annotations type ValidateTplFn func(annotations map[string]string) error +// cLogger is a logger with support of logs suppressing. +// it is used when logs emitted by config package needs +// to be suppressed. +var cLogger = &log.Logger{} + // ParseSilent parses rule configs from given file patterns without emitting logs func ParseSilent(pathPatterns []string, validateTplFn ValidateTplFn, validateExpressions bool) ([]Group, error) { - files, err := readFromFS(pathPatterns, true) + cLogger.Suppress(true) + defer cLogger.Suppress(false) + + files, err := readFromFS(pathPatterns) if err != nil { return nil, fmt.Errorf("failed to read from the config: %s", err) } @@ -210,7 +218,7 @@ func ParseSilent(pathPatterns []string, validateTplFn ValidateTplFn, validateExp // Parse parses rule configs from given file patterns func Parse(pathPatterns []string, validateTplFn ValidateTplFn, validateExpressions bool) ([]Group, error) { - files, err := readFromFS(pathPatterns, false) + files, err := readFromFS(pathPatterns) if err != nil { return nil, fmt.Errorf("failed to read from the config: %s", err) } @@ -219,7 +227,7 @@ func Parse(pathPatterns []string, validateTplFn ValidateTplFn, validateExpressio return nil, fmt.Errorf("failed to parse %s: %s", pathPatterns, err) } if len(groups) < 1 { - logger.Warnf("no groups found in %s", strings.Join(pathPatterns, ";")) + cLogger.Warnf("no groups found in %s", strings.Join(pathPatterns, ";")) } return groups, nil } diff --git a/app/vmalert/config/fs.go b/app/vmalert/config/fs.go index f1aa8f5115..372d8066fa 100644 --- a/app/vmalert/config/fs.go +++ b/app/vmalert/config/fs.go @@ -4,9 +4,9 @@ import ( "fmt" "strings" "sync" + "time" "github.com/VictoriaMetrics/VictoriaMetrics/app/vmalert/config/fslocal" - "github.com/VictoriaMetrics/VictoriaMetrics/lib/logger" ) // FS represent a file system abstract for reading files. @@ -36,10 +36,9 @@ var ( // readFromFS returns an error if at least one FS failed to init. // The function can be called multiple times but each unique path // will be inited only once. -// If silent == true, readFromFS will not emit any logs. // // It is allowed to mix different FS types in path list. -func readFromFS(paths []string, silent bool) (map[string][]byte, error) { +func readFromFS(paths []string) (map[string][]byte, error) { var err error result := make(map[string][]byte) for _, path := range paths { @@ -65,18 +64,19 @@ func readFromFS(paths []string, silent bool) (map[string][]byte, error) { return nil, fmt.Errorf("failed to list files from %q", fs) } - if !silent { - logger.Infof("found %d files to read from %q", len(list), fs) - } + cLogger.Infof("found %d files to read from %q", len(list), fs) if len(list) < 1 { continue } + ts := time.Now() files, err := fs.Read(list) if err != nil { return nil, fmt.Errorf("error while reading files from %q: %w", fs, err) } + cLogger.Infof("finished reading %d files in %v from %q", len(list), time.Since(ts), fs) + for k, v := range files { if _, ok := result[k]; ok { return nil, fmt.Errorf("duplicate found for file name %q: file names must be unique", k) diff --git a/app/vmalert/config/log/logger.go b/app/vmalert/config/log/logger.go new file mode 100644 index 0000000000..8b79e55ac6 --- /dev/null +++ b/app/vmalert/config/log/logger.go @@ -0,0 +1,59 @@ +package log + +import ( + "sync" + + "github.com/VictoriaMetrics/VictoriaMetrics/lib/logger" +) + +// Logger is using lib/logger for logging +// but can be suppressed via Suppress method +type Logger struct { + mu sync.RWMutex + disabled bool +} + +// Suppress whether to ignore message logging. +// Once suppressed, logging continues to be ignored +// until logger is un-suppressed. +func (l *Logger) Suppress(v bool) { + l.mu.Lock() + l.disabled = v + l.mu.Unlock() +} + +func (l *Logger) isDisabled() bool { + l.mu.RLock() + defer l.mu.RUnlock() + return l.disabled +} + +// Errorf logs error message. +func (l *Logger) Errorf(format string, args ...interface{}) { + if l.isDisabled() { + return + } + logger.Errorf(format, args...) +} + +// Warnf logs warning message. +func (l *Logger) Warnf(format string, args ...interface{}) { + if l.isDisabled() { + return + } + logger.Warnf(format, args...) +} + +// Infof logs info message. +func (l *Logger) Infof(format string, args ...interface{}) { + if l.isDisabled() { + return + } + logger.Infof(format, args...) +} + +// Panicf logs panic message and panics. +// Panicf can't be suppressed +func (l *Logger) Panicf(format string, args ...interface{}) { + logger.Panicf(format, args...) +} diff --git a/app/vmalert/config/log/logger_test.go b/app/vmalert/config/log/logger_test.go new file mode 100644 index 0000000000..ea0f4fe6f7 --- /dev/null +++ b/app/vmalert/config/log/logger_test.go @@ -0,0 +1,54 @@ +package log + +import ( + "bytes" + "fmt" + "strings" + "testing" + + "github.com/VictoriaMetrics/VictoriaMetrics/lib/logger" +) + +func TestOutput(t *testing.T) { + testOutput := &bytes.Buffer{} + logger.SetOutputForTests(testOutput) + defer logger.ResetOutputForTest() + + log := &Logger{} + + mustMatch := func(exp string) { + t.Helper() + if exp == "" { + if testOutput.String() != "" { + t.Errorf("expected output to be empty; got %q", testOutput.String()) + return + } + } + if !strings.Contains(testOutput.String(), exp) { + t.Errorf("output %q should contain %q", testOutput.String(), exp) + } + fmt.Println(testOutput.String()) + testOutput.Reset() + } + + log.Warnf("foo") + mustMatch("foo") + + log.Infof("info %d", 2) + mustMatch("info 2") + + log.Errorf("error %s %d", "baz", 5) + mustMatch("error baz 5") + + log.Suppress(true) + + log.Warnf("foo") + mustMatch("") + + log.Infof("info %d", 2) + mustMatch("") + + log.Errorf("error %q %d", "baz", 5) + mustMatch("") + +} diff --git a/app/vmalert/main.go b/app/vmalert/main.go index 2d32a5d3b5..28d4f5c175 100644 --- a/app/vmalert/main.go +++ b/app/vmalert/main.go @@ -319,6 +319,7 @@ func configReload(ctx context.Context, m *manager, groupsCfg []config.Group, sig // init reload metrics with positive values to improve alerting conditions configSuccess.Set(1) configTimestamp.Set(fasttime.UnixTimestamp()) + parseFn := config.Parse for { select { case <-ctx.Done(): @@ -330,7 +331,11 @@ func configReload(ctx context.Context, m *manager, groupsCfg []config.Group, sig } logger.Infof("SIGHUP received. Going to reload rules %q %s...", *rulePath, tmplMsg) configReloads.Inc() + // allow logs emitting during manual config reload + parseFn = config.Parse case <-configCheckCh: + // disable logs emitting during per-interval config reload + parseFn = config.ParseSilent } if err := notifier.Reload(); err != nil { configReloadErrors.Inc() @@ -345,7 +350,7 @@ func configReload(ctx context.Context, m *manager, groupsCfg []config.Group, sig logger.Errorf("failed to load new templates: %s", err) continue } - newGroupsCfg, err := config.ParseSilent(*rulePath, validateTplFn, *validateExpressions) + newGroupsCfg, err := parseFn(*rulePath, validateTplFn, *validateExpressions) if err != nil { configReloadErrors.Inc() configSuccess.Set(0)