diff --git a/pkg/services/ngalert/logging/logging.go b/pkg/services/ngalert/logging/logging.go index 7e5b695c59c..540320e20f9 100644 --- a/pkg/services/ngalert/logging/logging.go +++ b/pkg/services/ngalert/logging/logging.go @@ -3,6 +3,8 @@ package logging import ( "strings" + "github.com/go-kit/log/level" + glog "github.com/grafana/grafana/pkg/infra/log" ) @@ -22,3 +24,40 @@ func (w *GoKitWrapper) Write(p []byte) (n int, err error) { w.logger.Info(withoutNewline) return len(p), nil } + +// Log implements interface go-kit/log/Logger. It tries to extract level and message from the context and writes to underlying message. +// To successfully extract the log level, the first pair of elements should be 'lvl' and log level. Otherwise, it falls back to info. +// The following pair should be 'msg' and message. Otherwise, it uses the empty string as message. +func (w *GoKitWrapper) Log(keyvals ...interface{}) error { + if len(keyvals) == 0 { + return nil + } + + f := w.logger.Info + startwith := 0 + if keyvals[0] == level.Key() { + startwith = 2 + switch keyvals[1] { + case level.DebugValue(): + f = w.logger.Debug + case level.InfoValue(): + f = w.logger.Info + case level.WarnValue(): + f = w.logger.Warn + case level.ErrorValue(): + f = w.logger.Error + } + } + + msg := "" + if keyvals[startwith] == "msg" { + str, ok := keyvals[startwith+1].(string) + if ok { + msg = str + startwith += 2 + } + } + + f(msg, keyvals[startwith:]...) + return nil +} diff --git a/pkg/services/ngalert/logging/logging_test.go b/pkg/services/ngalert/logging/logging_test.go new file mode 100644 index 00000000000..a4b6ad45dda --- /dev/null +++ b/pkg/services/ngalert/logging/logging_test.go @@ -0,0 +1,102 @@ +package logging + +import ( + "bytes" + "fmt" + "io" + "testing" + + gokit_log "github.com/go-kit/kit/log" + "github.com/go-kit/log" + "github.com/go-kit/log/level" + "github.com/inconshreveable/log15" + "github.com/stretchr/testify/require" +) + +func Test_GoKitWrapper(t *testing.T) { + getLogger := func(writer io.Writer) log.Logger { + log15Logger := log15.New() + log15Logger.SetHandler(log15.StreamHandler(writer, log15.LogfmtFormat())) + return NewWrapper(log15Logger) + } + + tests := []struct { + level level.Value + expectedLevel string + }{ + { + level.DebugValue(), + "dbug", + }, + { + level.InfoValue(), + "info", + }, + { + level.WarnValue(), + "warn", + }, + { + level.ErrorValue(), + "eror", + }, + } + for _, test := range tests { + t.Run(fmt.Sprintf("when level %s", test.level.String()), func(t *testing.T) { + t.Run(fmt.Sprintf("rendered message should contain the level %s", test.expectedLevel), func(t *testing.T) { + var data bytes.Buffer + gokitLogger := getLogger(&data) + _ = log.WithPrefix(gokitLogger, level.Key(), test.level).Log("msg", "test", "some", "more", "context", "data") + + str := data.String() + require.Contains(t, str, fmt.Sprintf("lvl=%s msg=test some=more context=data", test.expectedLevel)) + }) + }) + } + + t.Run("use info when level does not exist", func(t *testing.T) { + var data bytes.Buffer + gokitLogger := getLogger(&data) + _ = gokitLogger.Log("msg", "test", "some", "more", "context", "data") + str := data.String() + require.Contains(t, str, "lvl=info msg=test some=more context=data") + }) + t.Run("use empty msg when context misses msg", func(t *testing.T) { + var data bytes.Buffer + gokitLogger := getLogger(&data) + _ = gokitLogger.Log("message", "test", "some", "more", "context", "data") + str := data.String() + require.Contains(t, str, "lvl=info msg= message=test some=more context=data") + }) +} + +func Benchmark_Baseline(t *testing.B) { + log15Logger := log15.New() + var buff bytes.Buffer + log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) + + for i := 0; i < t.N; i++ { + log15Logger.Info("test", "some", "more", "context", "data") + } +} + +func Benchmark_WrapperLogger(t *testing.B) { + log15Logger := log15.New() + var buff bytes.Buffer + log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) + gokit := NewWrapper(log15Logger) + + for i := 0; i < t.N; i++ { + _ = level.Info(gokit).Log("msg", "test", "some", "more", "context", "data") + } +} + +func Benchmark_WrapperWriter(t *testing.B) { + log15Logger := log15.New() + var buff bytes.Buffer + log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) + gokit := gokit_log.NewLogfmtLogger(NewWrapper(log15Logger)) + for i := 0; i < t.N; i++ { + _ = level.Info(gokit).Log("msg", "test", "some", "more", "context", "data") + } +} diff --git a/pkg/services/ngalert/notifier/alertmanager.go b/pkg/services/ngalert/notifier/alertmanager.go index 027f976f9b7..0194a779b9e 100644 --- a/pkg/services/ngalert/notifier/alertmanager.go +++ b/pkg/services/ngalert/notifier/alertmanager.go @@ -144,7 +144,7 @@ func newAlertmanager(orgID int64, cfg *setting.Cfg, store store.AlertingStore, k decryptFn: decryptFn, } - am.gokitLogger = gokit_log.NewLogfmtLogger(logging.NewWrapper(am.logger)) + am.gokitLogger = logging.NewWrapper(am.logger) am.fileStore = NewFileStore(am.orgID, kvStore, am.WorkingDirPath()) nflogFilepath, err := am.fileStore.FilepathFor(context.TODO(), notificationLogFilename)