Improve bridge for Alertmanager logger (#42958)

* Implement go-kit/log.Logger for internal logger.

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
+}

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")
+	}
+}

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)