From a8eef45a441c5bd7d9be472850cdd02574437f74 Mon Sep 17 00:00:00 2001 From: ying-jeanne <74549700+ying-jeanne@users.noreply.github.com> Date: Thu, 6 Jan 2022 15:28:05 +0100 Subject: [PATCH] Logger migration from log15 to gokit/log (#41636) * migrate log15 to gokit/log * fix console log * update some unittest * fix all unittest * fix the build * Update pkg/infra/log/log.go Co-authored-by: Yuriy Tseretyan * general type vector * correct the level key Co-authored-by: Yuriy Tseretyan --- pkg/api/frontend_logging.go | 8 +- pkg/api/frontend_logging_test.go | 101 +++--- pkg/api/frontendlogging/sentry.go | 24 +- pkg/infra/log/file.go | 67 ++-- pkg/infra/log/file_test.go | 8 +- pkg/infra/log/interface.go | 11 +- pkg/infra/log/level/level.go | 205 +++++++++++ pkg/infra/log/log.go | 340 ++++++++++++------ pkg/infra/log/syslog.go | 85 +++-- pkg/infra/log/syslog_windows.go | 7 +- pkg/infra/remotecache/remotecache.go | 5 +- pkg/infra/usagestats/service/service.go | 2 +- pkg/login/social/generic_oauth_test.go | 31 +- pkg/middleware/recovery.go | 3 +- .../loader/initializer/initializer_test.go | 7 +- .../login/loginservice/loginservice_test.go | 14 +- pkg/services/ngalert/logging/logging_test.go | 31 +- 17 files changed, 628 insertions(+), 321 deletions(-) create mode 100644 pkg/infra/log/level/level.go diff --git a/pkg/api/frontend_logging.go b/pkg/api/frontend_logging.go index fd57fcb7a5a..5a3dc71d733 100644 --- a/pkg/api/frontend_logging.go +++ b/pkg/api/frontend_logging.go @@ -34,13 +34,13 @@ func NewFrontendLogMessageHandler(store *frontendlogging.SourceMapStore) fronten switch event.Level { case sentry.LevelError: - frontendLogger.Error(msg, ctx) + frontendLogger.Error(msg, ctx...) case sentry.LevelWarning: - frontendLogger.Warn(msg, ctx) + frontendLogger.Warn(msg, ctx...) case sentry.LevelDebug: - frontendLogger.Debug(msg, ctx) + frontendLogger.Debug(msg, ctx...) default: - frontendLogger.Info(msg, ctx) + frontendLogger.Info(msg, ctx...) } return response.Success("ok") diff --git a/pkg/api/frontend_logging_test.go b/pkg/api/frontend_logging_test.go index 87130c12909..a8e204fdd25 100644 --- a/pkg/api/frontend_logging_test.go +++ b/pkg/api/frontend_logging_test.go @@ -10,13 +10,14 @@ import ( "time" "github.com/getsentry/sentry-go" + "github.com/go-kit/log" "github.com/grafana/grafana/pkg/api/frontendlogging" "github.com/grafana/grafana/pkg/api/response" "github.com/grafana/grafana/pkg/api/routing" + "github.com/grafana/grafana/pkg/infra/log/level" "github.com/grafana/grafana/pkg/models" "github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/setting" - log "github.com/inconshreveable/log15" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -27,20 +28,25 @@ type SourceMapReadRecord struct { path string } -type logScenarioFunc func(c *scenarioContext, logs []*log.Record, sourceMapReads []SourceMapReadRecord) +type logScenarioFunc func(c *scenarioContext, logs map[string]interface{}, sourceMapReads []SourceMapReadRecord) func logSentryEventScenario(t *testing.T, desc string, event frontendlogging.FrontendSentryEvent, fn logScenarioFunc) { t.Run(desc, func(t *testing.T) { - logs := []*log.Record{} - sourceMapReads := []SourceMapReadRecord{} - - origHandler := frontendLogger.GetHandler() - frontendLogger.SetHandler(log.FuncHandler(func(r *log.Record) error { - logs = append(logs, r) + var logcontent = make(map[string]interface{}) + logcontent["logger"] = "frontend" + newfrontendLogger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error { + for i := 0; i < len(keyvals); i += 2 { + logcontent[keyvals[i].(string)] = keyvals[i+1] + } return nil })) + + origHandler := frontendLogger.GetLogger() + frontendLogger.AddLogger(newfrontendLogger, "info", map[string]level.Option{}) + sourceMapReads := []SourceMapReadRecord{} + t.Cleanup(func() { - frontendLogger.SetHandler(origHandler) + frontendLogger.SetLogger(origHandler) }) sc := setupScenarioContext(t, "/log") @@ -91,7 +97,7 @@ func logSentryEventScenario(t *testing.T, desc string, event frontendlogging.Fro sc.m.Post(sc.url, handler) sc.fakeReqWithParams("POST", sc.url, map[string]string{}).exec() - fn(sc, logs, sourceMapReads) + fn(sc, logcontent, sourceMapReads) }) } @@ -148,18 +154,17 @@ func TestFrontendLoggingEndpoint(t *testing.T) { } logSentryEventScenario(t, "Should log received error event", errorEvent, - func(sc *scenarioContext, logs []*log.Record, sourceMapReads []SourceMapReadRecord) { + func(sc *scenarioContext, logs map[string]interface{}, sourceMapReads []SourceMapReadRecord) { assert.Equal(t, 200, sc.resp.Code) - assert.Len(t, logs, 1) - assertContextContains(t, logs[0], "logger", "frontend") - assertContextContains(t, logs[0], "url", errorEvent.Request.URL) - assertContextContains(t, logs[0], "user_agent", errorEvent.Request.Headers["User-Agent"]) - assertContextContains(t, logs[0], "event_id", errorEvent.EventID) - assertContextContains(t, logs[0], "original_timestamp", errorEvent.Timestamp) - assertContextContains(t, logs[0], "stacktrace", `UserError: Please replace user and try again + assertContextContains(t, logs, "logger", "frontend") + assertContextContains(t, logs, "url", errorEvent.Request.URL) + assertContextContains(t, logs, "user_agent", errorEvent.Request.Headers["User-Agent"]) + assertContextContains(t, logs, "event_id", errorEvent.EventID) + assertContextContains(t, logs, "original_timestamp", errorEvent.Timestamp) + assertContextContains(t, logs, "stacktrace", `UserError: Please replace user and try again at foofn (foo.js:123:23) at barfn (bar.js:113:231)`) - assert.NotContains(t, logs[0].Ctx, "context") + assert.NotContains(t, logs, "context") }) messageEvent := frontendlogging.FrontendSentryEvent{ @@ -175,20 +180,21 @@ func TestFrontendLoggingEndpoint(t *testing.T) { } logSentryEventScenario(t, "Should log received message event", messageEvent, - func(sc *scenarioContext, logs []*log.Record, sourceMapReads []SourceMapReadRecord) { + func(sc *scenarioContext, logs map[string]interface{}, sourceMapReads []SourceMapReadRecord) { assert.Equal(t, 200, sc.resp.Code) - assert.Len(t, logs, 1) - assert.Equal(t, "hello world", logs[0].Msg) - assert.Equal(t, log.LvlInfo, logs[0].Lvl) - assertContextContains(t, logs[0], "logger", "frontend") - assertContextContains(t, logs[0], "url", messageEvent.Request.URL) - assertContextContains(t, logs[0], "user_agent", messageEvent.Request.Headers["User-Agent"]) - assertContextContains(t, logs[0], "event_id", messageEvent.EventID) - assertContextContains(t, logs[0], "original_timestamp", messageEvent.Timestamp) - assert.NotContains(t, logs[0].Ctx, "stacktrace") - assert.NotContains(t, logs[0].Ctx, "context") - assertContextContains(t, logs[0], "user_email", user.Email) - assertContextContains(t, logs[0], "user_id", user.ID) + assert.Len(t, logs, 10) + assertContextContains(t, logs, "logger", "frontend") + assertContextContains(t, logs, "msg", "hello world") + assertContextContains(t, logs, "lvl", level.InfoValue()) + assertContextContains(t, logs, "logger", "frontend") + assertContextContains(t, logs, "url", messageEvent.Request.URL) + assertContextContains(t, logs, "user_agent", messageEvent.Request.Headers["User-Agent"]) + assertContextContains(t, logs, "event_id", messageEvent.EventID) + assertContextContains(t, logs, "original_timestamp", messageEvent.Timestamp) + assert.NotContains(t, logs, "stacktrace") + assert.NotContains(t, logs, "context") + assertContextContains(t, logs, "user_email", user.Email) + assertContextContains(t, logs, "user_id", user.ID) }) eventWithContext := frontendlogging.FrontendSentryEvent{ @@ -211,12 +217,11 @@ func TestFrontendLoggingEndpoint(t *testing.T) { } logSentryEventScenario(t, "Should log event context", eventWithContext, - func(sc *scenarioContext, logs []*log.Record, sourceMapReads []SourceMapReadRecord) { + func(sc *scenarioContext, logs map[string]interface{}, sourceMapReads []SourceMapReadRecord) { assert.Equal(t, 200, sc.resp.Code) - assert.Len(t, logs, 1) - assertContextContains(t, logs[0], "context_foo_one", "two") - assertContextContains(t, logs[0], "context_foo_three", "4") - assertContextContains(t, logs[0], "context_bar", "baz") + assertContextContains(t, logs, "context_foo_one", "two") + assertContextContains(t, logs, "context_foo_three", "4") + assertContextContains(t, logs, "context_bar", "baz") }) errorEventForSourceMapping := frontendlogging.FrontendSentryEvent{ @@ -278,10 +283,10 @@ func TestFrontendLoggingEndpoint(t *testing.T) { } logSentryEventScenario(t, "Should load sourcemap and transform stacktrace line when possible", - errorEventForSourceMapping, func(sc *scenarioContext, logs []*log.Record, sourceMapReads []SourceMapReadRecord) { + errorEventForSourceMapping, func(sc *scenarioContext, logs map[string]interface{}, sourceMapReads []SourceMapReadRecord) { assert.Equal(t, 200, sc.resp.Code) - assert.Len(t, logs, 1) - assertContextContains(t, logs[0], "stacktrace", `UserError: Please replace user and try again + assert.Len(t, logs, 9) + assertContextContains(t, logs, "stacktrace", `UserError: Please replace user and try again at ? (core|webpack:///./some_source.ts:2:2) at ? (telepathic|webpack:///./some_source.ts:3:2) at explode (http://localhost:3000/public/build/error.js:3:10) @@ -306,17 +311,7 @@ func TestFrontendLoggingEndpoint(t *testing.T) { }) } -func indexOf(arr []interface{}, item string) int { - for i, elem := range arr { - if elem == item { - return i - } - } - return -1 -} - -func assertContextContains(t *testing.T, logRecord *log.Record, label string, value interface{}) { - assert.Contains(t, logRecord.Ctx, label) - labelIdx := indexOf(logRecord.Ctx, label) - assert.Equal(t, value, logRecord.Ctx[labelIdx+1]) +func assertContextContains(t *testing.T, logRecord map[string]interface{}, label string, value interface{}) { + assert.Contains(t, logRecord, label) + assert.Equal(t, value, logRecord[label]) } diff --git a/pkg/api/frontendlogging/sentry.go b/pkg/api/frontendlogging/sentry.go index 56eff6a1e3b..c91e3a47177 100644 --- a/pkg/api/frontendlogging/sentry.go +++ b/pkg/api/frontendlogging/sentry.go @@ -7,9 +7,10 @@ import ( "github.com/getsentry/sentry-go" "github.com/grafana/grafana/pkg/infra/log" - "github.com/inconshreveable/log15" ) +type CtxVector []interface{} + var logger = log.New("frontendlogging") type FrontendSentryExceptionValue struct { @@ -65,31 +66,28 @@ func (exception *FrontendSentryException) FmtStacktraces(store *SourceMapStore) return strings.Join(stacktraces, "\n\n") } -func addEventContextToLogContext(rootPrefix string, logCtx log15.Ctx, eventCtx map[string]interface{}) { +func addEventContextToLogContext(rootPrefix string, logCtx *CtxVector, eventCtx map[string]interface{}) { for key, element := range eventCtx { prefix := fmt.Sprintf("%s_%s", rootPrefix, key) switch v := element.(type) { case map[string]interface{}: addEventContextToLogContext(prefix, logCtx, v) default: - logCtx[prefix] = fmt.Sprintf("%v", v) + *logCtx = append(*logCtx, prefix, fmt.Sprintf("%v", v)) } } } -func (event *FrontendSentryEvent) ToLogContext(store *SourceMapStore) log15.Ctx { - var ctx = make(log15.Ctx) - ctx["url"] = event.Request.URL - ctx["user_agent"] = event.Request.Headers["User-Agent"] - ctx["event_id"] = event.EventID - ctx["original_timestamp"] = event.Timestamp +func (event *FrontendSentryEvent) ToLogContext(store *SourceMapStore) []interface{} { + var ctx = CtxVector{"url", event.Request.URL, "user_agent", event.Request.Headers["User-Agent"], + "event_id", event.EventID, "original_timestamp", event.Timestamp} + if event.Exception != nil { - ctx["stacktrace"] = event.Exception.FmtStacktraces(store) + ctx = append(ctx, "stacktrace", event.Exception.FmtStacktraces(store)) } - addEventContextToLogContext("context", ctx, event.Contexts) + addEventContextToLogContext("context", &ctx, event.Contexts) if len(event.User.Email) > 0 { - ctx["user_email"] = event.User.Email - ctx["user_id"] = event.User.ID + ctx = append(ctx, "user_email", event.User.Email, "user_id", event.User.ID) } return ctx diff --git a/pkg/infra/log/file.go b/pkg/infra/log/file.go index 761d96752b2..742ec6cfab1 100644 --- a/pkg/infra/log/file.go +++ b/pkg/infra/log/file.go @@ -15,15 +15,13 @@ import ( "sync" "time" - "github.com/inconshreveable/log15" + "github.com/go-kit/log" ) // FileLogWriter implements LoggerInterface. // It writes messages by lines limit, file size limit, or time frequency. type FileLogWriter struct { - mw *MuxWriter - - Format log15.Format + Format Formatedlogger Filename string Maxlines int maxlinesCurlines int @@ -39,30 +37,28 @@ type FileLogWriter struct { Rotate bool startLock sync.Mutex -} - -// an *os.File writer with locker. -type MuxWriter struct { + logger log.Logger sync.Mutex fd *os.File } // write to os.File. -func (l *MuxWriter) Write(b []byte) (int, error) { - l.Lock() - defer l.Unlock() - return l.fd.Write(b) +func (w *FileLogWriter) Write(b []byte) (int, error) { + w.docheck(len(b)) + w.Lock() + defer w.Unlock() + return w.fd.Write(b) } // set os.File in writer. -func (l *MuxWriter) setFD(fd *os.File) error { - if l.fd != nil { - if err := l.fd.Close(); err != nil && !errors.Is(err, os.ErrClosed) { +func (w *FileLogWriter) setFD(fd *os.File) error { + if w.fd != nil { + if err := w.fd.Close(); err != nil && !errors.Is(err, os.ErrClosed) { return fmt.Errorf("closing old file in MuxWriter failed: %w", err) } } - l.fd = fd + w.fd = fd return nil } @@ -70,30 +66,31 @@ func (l *MuxWriter) setFD(fd *os.File) error { func NewFileWriter() *FileLogWriter { w := &FileLogWriter{ Filename: "", - Format: log15.LogfmtFormat(), + Format: func(w io.Writer) log.Logger { + return log.NewLogfmtLogger(w) + }, Maxlines: 1000000, Maxsize: 1 << 28, // 256 MB Daily: true, Maxdays: 7, Rotate: true, } - // use MuxWriter instead direct use os.File for lock write when rotate - w.mw = new(MuxWriter) return w } -func (w *FileLogWriter) Log(r *log15.Record) error { - data := w.Format.Format(r) - w.docheck(len(data)) - _, err := w.mw.Write(data) - return err +func (w *FileLogWriter) Log(keyvals ...interface{}) error { + return w.logger.Log(keyvals...) } func (w *FileLogWriter) Init() error { if len(w.Filename) == 0 { return errors.New("config must have filename") } - return w.StartLogger() + if err := w.StartLogger(); err != nil { + return err + } + w.logger = log.NewLogfmtLogger(log.NewSyncWriter(w)) + return nil } // start file logger. create log file and set to locker-inside file writer. @@ -102,7 +99,7 @@ func (w *FileLogWriter) StartLogger() error { if err != nil { return err } - if err := w.mw.setFD(fd); err != nil { + if err := w.setFD(fd); err != nil { return err } @@ -159,7 +156,7 @@ func (w *FileLogWriter) lineCounter() (int, error) { } func (w *FileLogWriter) initFd() error { - fd := w.mw.fd + fd := w.fd finfo, err := fd.Stat() if err != nil { return fmt.Errorf("get stat: %s", err) @@ -196,10 +193,10 @@ func (w *FileLogWriter) DoRotate() error { } // block Logger's io.Writer - w.mw.Lock() - defer w.mw.Unlock() + w.Lock() + defer w.Unlock() - fd := w.mw.fd + fd := w.fd if err := fd.Close(); err != nil { return err } @@ -244,14 +241,14 @@ func (w *FileLogWriter) deleteOldLog() { // destroy file logger, close file writer. func (w *FileLogWriter) Close() error { - return w.mw.fd.Close() + return w.fd.Close() } // flush file logger. // there are no buffering messages in file logger in memory. // flush file means sync file from disk. func (w *FileLogWriter) Flush() { - if err := w.mw.fd.Sync(); err != nil { + if err := w.fd.Sync(); err != nil { fmt.Fprintf(os.Stderr, "FileLogWriter(%q): %s\n", w.Filename, err) } } @@ -259,11 +256,11 @@ func (w *FileLogWriter) Flush() { // Reload file logger func (w *FileLogWriter) Reload() error { // block Logger's io.Writer - w.mw.Lock() - defer w.mw.Unlock() + w.Lock() + defer w.Unlock() // Close - fd := w.mw.fd + fd := w.fd if err := fd.Close(); err != nil { return err } diff --git a/pkg/infra/log/file_test.go b/pkg/infra/log/file_test.go index d8092c8f29b..f6361e152a3 100644 --- a/pkg/infra/log/file_test.go +++ b/pkg/infra/log/file_test.go @@ -10,12 +10,8 @@ import ( ) func (w *FileLogWriter) WriteLine(line string) error { - n, err := w.mw.Write([]byte(line)) - if err != nil { - return err - } - w.docheck(n) - return nil + _, err := w.Write([]byte(line)) + return err } func TestLogFile(t *testing.T) { diff --git a/pkg/infra/log/interface.go b/pkg/infra/log/interface.go index 234b1c38c5c..523f9a3bc33 100644 --- a/pkg/infra/log/interface.go +++ b/pkg/infra/log/interface.go @@ -1,7 +1,5 @@ package log -import "github.com/inconshreveable/log15" - type Lvl int const ( @@ -14,18 +12,13 @@ const ( type Logger interface { // New returns a new Logger that has this logger's context plus the given context - New(ctx ...interface{}) log15.Logger + New(ctx ...interface{}) MultiLoggers - // GetHandler gets the handler associated with the logger. - GetHandler() log15.Handler - - // SetHandler updates the logger to write records to the specified handler. - SetHandler(h log15.Handler) + Log(keyvals ...interface{}) error // Log a message at the given level with context key/value pairs Debug(msg string, ctx ...interface{}) Info(msg string, ctx ...interface{}) Warn(msg string, ctx ...interface{}) Error(msg string, ctx ...interface{}) - Crit(msg string, ctx ...interface{}) } diff --git a/pkg/infra/log/level/level.go b/pkg/infra/log/level/level.go new file mode 100644 index 00000000000..d6fdccfdaa1 --- /dev/null +++ b/pkg/infra/log/level/level.go @@ -0,0 +1,205 @@ +package level + +import "github.com/go-kit/log" + +// Error returns a logger that includes a Key/ErrorValue pair. +func Error(logger log.Logger) log.Logger { + return log.WithPrefix(logger, Key(), ErrorValue()) +} + +// Warn returns a logger that includes a Key/WarnValue pair. +func Warn(logger log.Logger) log.Logger { + return log.WithPrefix(logger, Key(), WarnValue()) +} + +// Info returns a logger that includes a Key/InfoValue pair. +func Info(logger log.Logger) log.Logger { + return log.WithPrefix(logger, Key(), InfoValue()) +} + +// Debug returns a logger that includes a Key/DebugValue pair. +func Debug(logger log.Logger) log.Logger { + return log.WithPrefix(logger, Key(), DebugValue()) +} + +// NewFilter wraps next and implements level filtering. See the commentary on +// the Option functions for a detailed description of how to configure levels. +// If no options are provided, all leveled log events created with Debug, +// Info, Warn or Error helper methods are squelched and non-leveled log +// events are passed to next unmodified. +func NewFilter(next log.Logger, options ...Option) log.Logger { + l := &logger{ + next: next, + } + for _, option := range options { + option(l) + } + return l +} + +type logger struct { + next log.Logger + allowed level + squelchNoLevel bool + errNotAllowed error + errNoLevel error +} + +func (l *logger) Log(keyvals ...interface{}) error { + var hasLevel, levelAllowed bool + for i := 1; i < len(keyvals); i += 2 { + if v, ok := keyvals[i].(*levelValue); ok { + hasLevel = true + levelAllowed = l.allowed&v.level != 0 + break + } + } + if !hasLevel && l.squelchNoLevel { + return l.errNoLevel + } + if hasLevel && !levelAllowed { + return l.errNotAllowed + } + return l.next.Log(keyvals...) +} + +// Option sets a parameter for the leveled logger. +type Option func(*logger) + +// AllowAll is an alias for AllowDebug. +func AllowAll() Option { + return AllowDebug() +} + +// AllowDebug allows error, warn, info and debug level log events to pass. +func AllowDebug() Option { + return allowed(levelError | levelWarn | levelInfo | levelDebug) +} + +// AllowInfo allows error, warn and info level log events to pass. +func AllowInfo() Option { + return allowed(levelError | levelWarn | levelInfo) +} + +// AllowWarn allows error and warn level log events to pass. +func AllowWarn() Option { + return allowed(levelError | levelWarn) +} + +// AllowError allows only error level log events to pass. +func AllowError() Option { + return allowed(levelError) +} + +// AllowNone allows no leveled log events to pass. +func AllowNone() Option { + return allowed(0) +} + +func allowed(allowed level) Option { + return func(l *logger) { l.allowed = allowed } +} + +// ErrNotAllowed sets the error to return from Log when it squelches a log +// event disallowed by the configured Allow[Level] option. By default, +// ErrNotAllowed is nil; in this case the log event is squelched with no +// error. +func ErrNotAllowed(err error) Option { + return func(l *logger) { l.errNotAllowed = err } +} + +// SquelchNoLevel instructs Log to squelch log events with no level, so that +// they don't proceed through to the wrapped logger. If SquelchNoLevel is set +// to true and a log event is squelched in this way, the error value +// configured with ErrNoLevel is returned to the caller. +func SquelchNoLevel(squelch bool) Option { + return func(l *logger) { l.squelchNoLevel = squelch } +} + +// ErrNoLevel sets the error to return from Log when it squelches a log event +// with no level. By default, ErrNoLevel is nil; in this case the log event is +// squelched with no error. +func ErrNoLevel(err error) Option { + return func(l *logger) { l.errNoLevel = err } +} + +// NewInjector wraps next and returns a logger that adds a Key/level pair to +// the beginning of log events that don't already contain a level. In effect, +// this gives a default level to logs without a level. +func NewInjector(next log.Logger, level Value) log.Logger { + return &injector{ + next: next, + level: level, + } +} + +type injector struct { + next log.Logger + level interface{} +} + +func (l *injector) Log(keyvals ...interface{}) error { + for i := 1; i < len(keyvals); i += 2 { + if _, ok := keyvals[i].(*levelValue); ok { + return l.next.Log(keyvals...) + } + } + kvs := make([]interface{}, len(keyvals)+2) + kvs[0], kvs[1] = key, l.level + copy(kvs[2:], keyvals) + return l.next.Log(kvs...) +} + +// Value is the interface that each of the canonical level values implement. +// It contains unexported methods that prevent types from other packages from +// implementing it and guaranteeing that NewFilter can distinguish the levels +// defined in this package from all other values. +type Value interface { + String() string + levelVal() +} + +// Key returns the unique key added to log events by the loggers in this +// package. +func Key() interface{} { return key } + +// ErrorValue returns the unique value added to log events by Error. +func ErrorValue() Value { return errorValue } + +// WarnValue returns the unique value added to log events by Warn. +func WarnValue() Value { return warnValue } + +// InfoValue returns the unique value added to log events by Info. +func InfoValue() Value { return infoValue } + +// DebugValue returns the unique value added to log events by Debug. +func DebugValue() Value { return debugValue } + +var ( + // key is of type interface{} so that it allocates once during package + // initialization and avoids allocating every time the value is added to a + // []interface{} later. + key interface{} = "lvl" + + errorValue = &levelValue{level: levelError, name: "eror"} + warnValue = &levelValue{level: levelWarn, name: "warn"} + infoValue = &levelValue{level: levelInfo, name: "info"} + debugValue = &levelValue{level: levelDebug, name: "dbug"} +) + +type level byte + +const ( + levelDebug level = 1 << iota + levelInfo + levelWarn + levelError +) + +type levelValue struct { + name string + level +} + +func (v *levelValue) String() string { return v.name } +func (v *levelValue) levelVal() {} diff --git a/pkg/infra/log/log.go b/pkg/infra/log/log.go index 92be0acc68c..f8d074b33dd 100644 --- a/pkg/infra/log/log.go +++ b/pkg/infra/log/log.go @@ -6,36 +6,237 @@ package log import ( "fmt" + "io" "os" "path/filepath" "strings" + "time" + gokitlog "github.com/go-kit/log" + "github.com/go-kit/log/term" "github.com/go-stack/stack" + "github.com/grafana/grafana/pkg/infra/log/level" "github.com/grafana/grafana/pkg/util" "github.com/grafana/grafana/pkg/util/errutil" - "github.com/inconshreveable/log15" - isatty "github.com/mattn/go-isatty" + "github.com/mattn/go-isatty" "gopkg.in/ini.v1" ) -var Root log15.Logger var loggersToClose []DisposableHandler var loggersToReload []ReloadableHandler -var filters map[string]log15.Lvl +var filters map[string]level.Option +var Root MultiLoggers func init() { loggersToClose = make([]DisposableHandler, 0) loggersToReload = make([]ReloadableHandler, 0) - filters = map[string]log15.Lvl{} - Root = log15.Root() - Root.SetHandler(log15.DiscardHandler()) + filters = map[string]level.Option{} + Root.AddLogger(gokitlog.NewLogfmtLogger(os.Stderr), "info", filters) } -func New(logger string, ctx ...interface{}) Logger { - params := append([]interface{}{"logger", logger}, ctx...) - return Root.New(params...) +type LogWithFilters struct { + val gokitlog.Logger + filters map[string]level.Option + maxLevel level.Option } +type MultiLoggers struct { + loggers []LogWithFilters +} + +func (ml *MultiLoggers) AddLogger(val gokitlog.Logger, levelName string, filters map[string]level.Option) { + logger := LogWithFilters{val: val, filters: filters, maxLevel: getLogLevelFromString(levelName)} + ml.loggers = append(ml.loggers, logger) +} + +func (ml *MultiLoggers) SetLogger(des MultiLoggers) { + ml.loggers = des.loggers +} + +func (ml *MultiLoggers) GetLogger() MultiLoggers { + return *ml +} + +func (ml MultiLoggers) Warn(msg string, args ...interface{}) { + args = append([]interface{}{level.Key(), level.WarnValue(), "msg", msg}, args...) + err := ml.Log(args...) + if err != nil { + _ = level.Error(Root).Log("Logging error", "error", err) + } +} + +func (ml MultiLoggers) Debug(msg string, args ...interface{}) { + args = append([]interface{}{level.Key(), level.DebugValue(), "msg", msg}, args...) + err := ml.Log(args...) + if err != nil { + _ = level.Error(Root).Log("Logging error", "error", err) + } +} + +func (ml MultiLoggers) Error(msg string, args ...interface{}) { + args = append([]interface{}{level.Key(), level.ErrorValue(), "msg", msg}, args...) + err := ml.Log(args...) + if err != nil { + _ = level.Error(Root).Log("Logging error", "error", err) + } +} + +func (ml MultiLoggers) Info(msg string, args ...interface{}) { + args = append([]interface{}{level.Key(), level.InfoValue(), "msg", msg}, args...) + err := ml.Log(args...) + if err != nil { + _ = level.Error(Root).Log("Logging error", "error", err) + } +} + +func (ml MultiLoggers) Log(keyvals ...interface{}) error { + for _, multilogger := range ml.loggers { + multilogger.val = gokitlog.With(multilogger.val, "t", gokitlog.TimestampFormat(time.Now, "2006-01-02T15:04:05.99-0700")) + if err := multilogger.val.Log(keyvals...); err != nil { + return err + } + } + return nil +} + +// we need to implement new function for multiloggers +func (ml MultiLoggers) New(ctx ...interface{}) MultiLoggers { + var newloger MultiLoggers + for _, logWithFilter := range ml.loggers { + logWithFilter.val = gokitlog.With(logWithFilter.val, ctx) + if len(ctx) > 0 { + v, ok := logWithFilter.filters[ctx[0].(string)] + if ok { + logWithFilter.val = level.NewFilter(logWithFilter.val, v) + } else { + logWithFilter.val = level.NewFilter(logWithFilter.val, logWithFilter.maxLevel) + } + } + newloger.loggers = append(newloger.loggers, logWithFilter) + } + return newloger +} + +func New(ctx ...interface{}) MultiLoggers { + if len(ctx) == 0 { + return Root + } + var newloger MultiLoggers + ctx = append([]interface{}{"logger"}, ctx...) + for _, logWithFilter := range Root.loggers { + logWithFilter.val = gokitlog.With(logWithFilter.val, ctx...) + v, ok := logWithFilter.filters[ctx[0].(string)] + if ok { + logWithFilter.val = level.NewFilter(logWithFilter.val, v) + } else { + logWithFilter.val = level.NewFilter(logWithFilter.val, logWithFilter.maxLevel) + } + newloger.loggers = append(newloger.loggers, logWithFilter) + } + return newloger +} + +var logLevels = map[string]level.Option{ + "trace": level.AllowDebug(), + "debug": level.AllowDebug(), + "info": level.AllowInfo(), + "warn": level.AllowWarn(), + "error": level.AllowError(), + "critical": level.AllowError(), +} + +func getLogLevelFromConfig(key string, defaultName string, cfg *ini.File) (string, level.Option) { + levelName := cfg.Section(key).Key("level").MustString(defaultName) + levelName = strings.ToLower(levelName) + level := getLogLevelFromString(levelName) + return levelName, level +} + +func getLogLevelFromString(levelName string) level.Option { + loglevel, ok := logLevels[levelName] + + if !ok { + _ = level.Error(Root).Log("Unknown log level", "level", levelName) + return level.AllowError() + } + + return loglevel +} + +// the filter is composed with logger name and level +func getFilters(filterStrArray []string) map[string]level.Option { + filterMap := make(map[string]level.Option) + + for _, filterStr := range filterStrArray { + parts := strings.Split(filterStr, ":") + if len(parts) > 1 { + filterMap[parts[0]] = getLogLevelFromString(parts[1]) + } + } + + return filterMap +} + +func Stack(skip int) string { + call := stack.Caller(skip) + s := stack.Trace().TrimBelow(call).TrimRuntime() + return s.String() +} + +type Formatedlogger func(w io.Writer) gokitlog.Logger + +func terminalColorFn(keyvals ...interface{}) term.FgBgColor { + for i := 0; i < len(keyvals)-1; i += 2 { + if keyvals[i] != level.Key() { + continue + } + switch keyvals[i+1] { + case "trace": + return term.FgBgColor{Fg: term.Gray} + case level.DebugValue(): + return term.FgBgColor{Fg: term.Gray} + case level.InfoValue(): + return term.FgBgColor{Fg: term.Green} + case level.WarnValue(): + return term.FgBgColor{Fg: term.Yellow} + case level.ErrorValue(): + return term.FgBgColor{Fg: term.Red} + case "crit": + return term.FgBgColor{Fg: term.Gray, Bg: term.DarkRed} + default: + return term.FgBgColor{} + } + } + return term.FgBgColor{} +} + +func getLogFormat(format string) Formatedlogger { + switch format { + case "console": + if isatty.IsTerminal(os.Stdout.Fd()) { + return func(w io.Writer) gokitlog.Logger { + return term.NewColorLogger(w, gokitlog.NewLogfmtLogger, terminalColorFn) + } + } + return func(w io.Writer) gokitlog.Logger { + return gokitlog.NewLogfmtLogger(w) + } + case "text": + return func(w io.Writer) gokitlog.Logger { + return gokitlog.NewLogfmtLogger(w) + } + case "json": + return func(w io.Writer) gokitlog.Logger { + return gokitlog.NewJSONLogger(gokitlog.NewSyncWriter(w)) + } + default: + return func(w io.Writer) gokitlog.Logger { + return gokitlog.NewLogfmtLogger(w) + } + } +} + +// this is for file logger only func Close() error { var err error for _, logger := range loggersToClose { @@ -59,62 +260,6 @@ func Reload() error { return nil } -var logLevels = map[string]log15.Lvl{ - "trace": log15.LvlDebug, - "debug": log15.LvlDebug, - "info": log15.LvlInfo, - "warn": log15.LvlWarn, - "error": log15.LvlError, - "critical": log15.LvlCrit, -} - -func getLogLevelFromConfig(key string, defaultName string, cfg *ini.File) (string, log15.Lvl) { - levelName := cfg.Section(key).Key("level").MustString(defaultName) - levelName = strings.ToLower(levelName) - level := getLogLevelFromString(levelName) - return levelName, level -} - -func getLogLevelFromString(levelName string) log15.Lvl { - level, ok := logLevels[levelName] - - if !ok { - Root.Error("Unknown log level", "level", levelName) - return log15.LvlError - } - - return level -} - -func getFilters(filterStrArray []string) map[string]log15.Lvl { - filterMap := make(map[string]log15.Lvl) - - for _, filterStr := range filterStrArray { - parts := strings.Split(filterStr, ":") - if len(parts) > 1 { - filterMap[parts[0]] = getLogLevelFromString(parts[1]) - } - } - - return filterMap -} - -func getLogFormat(format string) log15.Format { - switch format { - case "console": - if isatty.IsTerminal(os.Stdout.Fd()) { - return log15.TerminalFormat() - } - return log15.LogfmtFormat() - case "text": - return log15.LogfmtFormat() - case "json": - return log15.JsonFormat() - default: - return log15.LogfmtFormat() - } -} - func ReadLoggingConfig(modes []string, logsPath string, cfg *ini.File) error { if err := Close(); err != nil { return err @@ -123,32 +268,31 @@ func ReadLoggingConfig(modes []string, logsPath string, cfg *ini.File) error { defaultLevelName, _ := getLogLevelFromConfig("log", "info", cfg) defaultFilters := getFilters(util.SplitString(cfg.Section("log").Key("filters").String())) - handlers := make([]log15.Handler, 0) - + var configLoggers []LogWithFilters for _, mode := range modes { mode = strings.TrimSpace(mode) sec, err := cfg.GetSection("log." + mode) if err != nil { - Root.Error("Unknown log mode", "mode", mode) + _ = level.Error(Root).Log("Unknown log mode", "mode", mode) return errutil.Wrapf(err, "failed to get config section log.%s", mode) } // Log level. - _, level := getLogLevelFromConfig("log."+mode, defaultLevelName, cfg) + _, leveloption := getLogLevelFromConfig("log."+mode, defaultLevelName, cfg) modeFilters := getFilters(util.SplitString(sec.Key("filters").String())) + format := getLogFormat(sec.Key("format").MustString("")) - var handler log15.Handler + var handler LogWithFilters - // Generate log configuration. switch mode { case "console": - handler = log15.StreamHandler(os.Stdout, format) + handler.val = format(os.Stdout) case "file": fileName := sec.Key("file_name").MustString(filepath.Join(logsPath, "grafana.log")) dpath := filepath.Dir(fileName) if err := os.MkdirAll(dpath, os.ModePerm); err != nil { - Root.Error("Failed to create directory", "dpath", dpath, "err", err) + _ = level.Error(Root).Log("Failed to create directory", "dpath", dpath, "err", err) return errutil.Wrapf(err, "failed to create log directory %q", dpath) } fileHandler := NewFileWriter() @@ -160,65 +304,43 @@ func ReadLoggingConfig(modes []string, logsPath string, cfg *ini.File) error { fileHandler.Daily = sec.Key("daily_rotate").MustBool(true) fileHandler.Maxdays = sec.Key("max_days").MustInt64(7) if err := fileHandler.Init(); err != nil { - Root.Error("Failed to initialize file handler", "dpath", dpath, "err", err) + _ = level.Error(Root).Log("Failed to initialize file handler", "dpath", dpath, "err", err) return errutil.Wrapf(err, "failed to initialize file handler") } loggersToClose = append(loggersToClose, fileHandler) loggersToReload = append(loggersToReload, fileHandler) - handler = fileHandler + handler.val = fileHandler case "syslog": sysLogHandler := NewSyslog(sec, format) - loggersToClose = append(loggersToClose, sysLogHandler) - handler = sysLogHandler + handler.val = sysLogHandler.logger } - if handler == nil { + if handler.val == nil { panic(fmt.Sprintf("Handler is uninitialized for mode %q", mode)) } + // join default filters and mode filters together for key, value := range defaultFilters { if _, exist := modeFilters[key]; !exist { modeFilters[key] = value } } + // copy joined default + mode filters into filters for key, value := range modeFilters { if _, exist := filters[key]; !exist { filters[key] = value } } - handler = LogFilterHandler(level, modeFilters, handler) - handlers = append(handlers, handler) + handler.filters = modeFilters + handler.maxLevel = leveloption + // handler = LogFilterHandler(leveloption, modeFilters, handler) + configLoggers = append(configLoggers, handler) + } + if len(configLoggers) > 0 { + Root.loggers = configLoggers } - - Root.SetHandler(log15.MultiHandler(handlers...)) return nil } - -func LogFilterHandler(maxLevel log15.Lvl, filters map[string]log15.Lvl, h log15.Handler) log15.Handler { - return log15.FilterHandler(func(r *log15.Record) (pass bool) { - if len(filters) > 0 { - for i := 0; i < len(r.Ctx); i += 2 { - key, ok := r.Ctx[i].(string) - if ok && key == "logger" { - loggerName, strOk := r.Ctx[i+1].(string) - if strOk { - if filterLevel, ok := filters[loggerName]; ok { - return r.Lvl <= filterLevel - } - } - } - } - } - - return r.Lvl <= maxLevel - }, h) -} - -func Stack(skip int) string { - call := stack.Caller(skip) - s := stack.Trace().TrimBelow(call).TrimRuntime() - return s.String() -} diff --git a/pkg/infra/log/syslog.go b/pkg/infra/log/syslog.go index 41dc1ab816f..b1d818f5d58 100644 --- a/pkg/infra/log/syslog.go +++ b/pkg/infra/log/syslog.go @@ -4,11 +4,12 @@ package log import ( - "errors" "log/syslog" "os" - "github.com/inconshreveable/log15" + "github.com/go-kit/log" + "github.com/go-kit/log/level" + gokitsyslog "github.com/go-kit/log/syslog" "gopkg.in/ini.v1" ) @@ -18,13 +19,41 @@ type SysLogHandler struct { Address string Facility string Tag string - Format log15.Format + Format Formatedlogger + logger log.Logger } -func NewSyslog(sec *ini.Section, format log15.Format) *SysLogHandler { - handler := &SysLogHandler{ - Format: log15.LogfmtFormat(), +var selector = func(keyvals ...interface{}) syslog.Priority { + for i := 0; i < len(keyvals); i += 2 { + if keyvals[i] == level.Key() { + if v, ok := keyvals[i+1].(string); ok { + switch v { + case "emergency": + return syslog.LOG_EMERG + case "alert": + return syslog.LOG_ALERT + case "critical": + return syslog.LOG_CRIT + case "error": + return syslog.LOG_ERR + case "warning": + return syslog.LOG_WARNING + case "notice": + return syslog.LOG_NOTICE + case "info": + return syslog.LOG_INFO + case "debug": + return syslog.LOG_DEBUG + } + return syslog.LOG_LOCAL0 + } + } } + return syslog.LOG_LOCAL0 +} + +func NewSyslog(sec *ini.Section, format Formatedlogger) *SysLogHandler { + handler := &SysLogHandler{} handler.Format = format handler.Network = sec.Key("network").MustString("") @@ -33,18 +62,16 @@ func NewSyslog(sec *ini.Section, format log15.Format) *SysLogHandler { handler.Tag = sec.Key("tag").MustString("") if err := handler.Init(); err != nil { - Root.Error("Failed to init syslog log handler", "error", err) + _ = level.Error(Root).Log("Failed to init syslog log handler", "error", err) os.Exit(1) } - + handler.logger = gokitsyslog.NewSyslogLogger(handler.syslog, format, gokitsyslog.PrioritySelectorOption(selector)) return handler } func (sw *SysLogHandler) Init() error { - prio, err := parseFacility(sw.Facility) - if err != nil { - return err - } + // the facility is the origin of the syslog message + prio := parseFacility(sw.Facility) w, err := syslog.Dial(sw.Network, sw.Address, prio, sw.Tag) if err != nil { @@ -55,26 +82,8 @@ func (sw *SysLogHandler) Init() error { return nil } -func (sw *SysLogHandler) Log(r *log15.Record) error { - var err error - - msg := string(sw.Format.Format(r)) - - switch r.Lvl { - case log15.LvlDebug: - err = sw.syslog.Debug(msg) - case log15.LvlInfo: - err = sw.syslog.Info(msg) - case log15.LvlWarn: - err = sw.syslog.Warning(msg) - case log15.LvlError: - err = sw.syslog.Err(msg) - case log15.LvlCrit: - err = sw.syslog.Crit(msg) - default: - err = errors.New("invalid syslog level") - } - +func (sw *SysLogHandler) Log(keyvals ...interface{}) error { + err := sw.logger.Log(keyvals...) return err } @@ -95,11 +104,11 @@ var facilities = map[string]syslog.Priority{ "local7": syslog.LOG_LOCAL7, } -func parseFacility(facility string) (syslog.Priority, error) { - prio, ok := facilities[facility] - if !ok { - return syslog.LOG_LOCAL0, errors.New("invalid syslog facility") +func parseFacility(facility string) syslog.Priority { + v, found := facilities[facility] + if !found { + // default the facility level to LOG_LOCAL7 + return syslog.LOG_LOCAL7 } - - return prio, nil + return v } diff --git a/pkg/infra/log/syslog_windows.go b/pkg/infra/log/syslog_windows.go index a95377890a8..b98a83cb98b 100644 --- a/pkg/infra/log/syslog_windows.go +++ b/pkg/infra/log/syslog_windows.go @@ -4,18 +4,19 @@ package log import ( - "github.com/inconshreveable/log15" + "github.com/go-kit/log" "gopkg.in/ini.v1" ) type SysLogHandler struct { + logger log.Logger } -func NewSyslog(sec *ini.Section, format log15.Format) *SysLogHandler { +func NewSyslog(sec *ini.Section, format Formatedlogger) *SysLogHandler { return &SysLogHandler{} } -func (sw *SysLogHandler) Log(r *log15.Record) error { +func (sw *SysLogHandler) Log(keyvals ...interface{}) error { return nil } diff --git a/pkg/infra/remotecache/remotecache.go b/pkg/infra/remotecache/remotecache.go index be00f9e7b46..a5597084b3d 100644 --- a/pkg/infra/remotecache/remotecache.go +++ b/pkg/infra/remotecache/remotecache.go @@ -7,7 +7,8 @@ import ( "errors" "time" - "github.com/grafana/grafana/pkg/infra/log" + "github.com/go-kit/log" + glog "github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/registry" "github.com/grafana/grafana/pkg/services/sqlstore" "github.com/grafana/grafana/pkg/setting" @@ -35,7 +36,7 @@ func ProvideService(cfg *setting.Cfg, sqlStore *sqlstore.SQLStore) (*RemoteCache s := &RemoteCache{ SQLStore: sqlStore, Cfg: cfg, - log: log.New("cache.remote"), + log: glog.New("cache.remote"), client: client, } return s, nil diff --git a/pkg/infra/usagestats/service/service.go b/pkg/infra/usagestats/service/service.go index 112799a739c..e9300a83fc4 100644 --- a/pkg/infra/usagestats/service/service.go +++ b/pkg/infra/usagestats/service/service.go @@ -23,7 +23,7 @@ type UsageStats struct { SocialService social.Service kvStore *kvstore.NamespacedKVStore - log log.Logger + log log.MultiLoggers oauthProviders map[string]bool externalMetrics []usagestats.MetricsFunc diff --git a/pkg/login/social/generic_oauth_test.go b/pkg/login/social/generic_oauth_test.go index 25b41d01696..b7df2e97cee 100644 --- a/pkg/login/social/generic_oauth_test.go +++ b/pkg/login/social/generic_oauth_test.go @@ -4,28 +4,19 @@ import ( "encoding/json" "net/http" "net/http/httptest" - "os" "testing" "time" "github.com/grafana/grafana/pkg/infra/log" - "github.com/inconshreveable/log15" - "github.com/mattn/go-isatty" + "github.com/grafana/grafana/pkg/infra/log/level" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "golang.org/x/oauth2" ) -func getLogFormat() log15.Format { - if isatty.IsTerminal(os.Stdout.Fd()) { - return log15.TerminalFormat() - } - return log15.LogfmtFormat() -} - -func newLogger(name string, level log15.Lvl) log.Logger { +func newLogger(name string, lev string) log.Logger { logger := log.Root.New("logger", name) - logger.SetHandler(log15.LvlFilterHandler(level, log15.StreamHandler(os.Stdout, getLogFormat()))) + logger.AddLogger(logger, lev, map[string]level.Option{}) return logger } @@ -33,7 +24,7 @@ func TestSearchJSONForEmail(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, } @@ -121,7 +112,7 @@ func TestSearchJSONForGroups(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, } @@ -184,7 +175,7 @@ func TestSearchJSONForRole(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, } @@ -247,7 +238,7 @@ func TestUserInfoSearchesForEmailAndRole(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, emailAttributePath: "email", } @@ -456,7 +447,7 @@ func TestUserInfoSearchesForLogin(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, loginAttributePath: "login", } @@ -551,7 +542,7 @@ func TestUserInfoSearchesForName(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, nameAttributePath: "name", } @@ -649,7 +640,7 @@ func TestUserInfoSearchesForGroup(t *testing.T) { t.Run("Given a generic OAuth provider", func(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, } @@ -717,7 +708,7 @@ func TestUserInfoSearchesForGroup(t *testing.T) { func TestPayloadCompression(t *testing.T) { provider := SocialGenericOAuth{ SocialBase: &SocialBase{ - log: newLogger("generic_oauth_test", log15.LvlDebug), + log: newLogger("generic_oauth_test", "debug"), }, emailAttributePath: "email", } diff --git a/pkg/middleware/recovery.go b/pkg/middleware/recovery.go index 730f2ba6843..ea8483a6911 100644 --- a/pkg/middleware/recovery.go +++ b/pkg/middleware/recovery.go @@ -106,7 +106,8 @@ func Recovery(cfg *setting.Cfg) web.Handler { return func(c *web.Context) { defer func() { if r := recover(); r != nil { - panicLogger := log.Root + var panicLogger log.Logger + panicLogger = log.Root // try to get request logger ctx := contexthandler.FromContext(c.Req.Context()) if ctx != nil { diff --git a/pkg/plugins/manager/loader/initializer/initializer_test.go b/pkg/plugins/manager/loader/initializer/initializer_test.go index 65c575e4a51..dd1fe437529 100644 --- a/pkg/plugins/manager/loader/initializer/initializer_test.go +++ b/pkg/plugins/manager/loader/initializer/initializer_test.go @@ -5,7 +5,6 @@ import ( "path/filepath" "testing" - "github.com/inconshreveable/log15" "github.com/stretchr/testify/assert" "github.com/grafana/grafana/pkg/infra/log" @@ -357,11 +356,11 @@ type testPlugin struct { } type fakeLogger struct { - log.Logger + log.MultiLoggers } -func (f fakeLogger) New(_ ...interface{}) log15.Logger { - return fakeLogger{} +func (f fakeLogger) New(_ ...interface{}) log.MultiLoggers { + return log.MultiLoggers{} } func (f fakeLogger) Warn(_ string, _ ...interface{}) { diff --git a/pkg/services/login/loginservice/loginservice_test.go b/pkg/services/login/loginservice/loginservice_test.go index 904d485a341..5cbd5acb510 100644 --- a/pkg/services/login/loginservice/loginservice_test.go +++ b/pkg/services/login/loginservice/loginservice_test.go @@ -1,14 +1,16 @@ package loginservice import ( + "bytes" "context" "errors" "testing" + "github.com/go-kit/log" "github.com/grafana/grafana/pkg/bus" + "github.com/grafana/grafana/pkg/infra/log/level" "github.com/grafana/grafana/pkg/models" "github.com/grafana/grafana/pkg/services/quota" - log "github.com/inconshreveable/log15" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -43,11 +45,8 @@ func Test_syncOrgRoles_doesNotBreakWhenTryingToRemoveLastOrgAdmin(t *testing.T) } func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) { - logs := []string{} - logger.SetHandler(log.FuncHandler(func(r *log.Record) error { - logs = append(logs, r.Msg) - return nil - })) + buf := &bytes.Buffer{} + logger.AddLogger(log.NewLogfmtLogger(buf), "info", map[string]level.Option{}) user := createSimpleUser() externalUser := createSimpleExternalUser() @@ -57,7 +56,6 @@ func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) { defer bus.ClearBusHandlers() bus.AddHandler("test", func(ctx context.Context, q *models.GetUserOrgListQuery) error { q.Result = createUserOrgDTO() - return nil }) @@ -74,7 +72,7 @@ func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) { err := syncOrgRoles(context.Background(), &user, &externalUser) require.NoError(t, err) - assert.Contains(t, logs, models.ErrLastOrgAdmin.Error()) + assert.Contains(t, buf.String(), models.ErrLastOrgAdmin.Error()) } type authInfoServiceMock struct { diff --git a/pkg/services/ngalert/logging/logging_test.go b/pkg/services/ngalert/logging/logging_test.go index a4b6ad45dda..529a736c889 100644 --- a/pkg/services/ngalert/logging/logging_test.go +++ b/pkg/services/ngalert/logging/logging_test.go @@ -6,18 +6,17 @@ import ( "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" + glog "github.com/grafana/grafana/pkg/infra/log" + "github.com/grafana/grafana/pkg/infra/log/level" "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) + gLogger := glog.New() + gLogger.AddLogger(log.NewLogfmtLogger(writer), "info", map[string]level.Option{}) + return NewWrapper(gLogger) } tests := []struct { @@ -71,20 +70,21 @@ func Test_GoKitWrapper(t *testing.T) { } func Benchmark_Baseline(t *testing.B) { - log15Logger := log15.New() + gLogger := glog.New() var buff bytes.Buffer - log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) + gLogger.AddLogger(log.NewLogfmtLogger(&buff), "info", map[string]level.Option{}) for i := 0; i < t.N; i++ { - log15Logger.Info("test", "some", "more", "context", "data") + gLogger.Info("test", "some", "more", "context", "data") } } func Benchmark_WrapperLogger(t *testing.B) { - log15Logger := log15.New() + gLogger := glog.New() var buff bytes.Buffer - log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) - gokit := NewWrapper(log15Logger) + gLogger.AddLogger(log.NewLogfmtLogger(&buff), "info", map[string]level.Option{}) + + gokit := NewWrapper(gLogger) for i := 0; i < t.N; i++ { _ = level.Info(gokit).Log("msg", "test", "some", "more", "context", "data") @@ -92,10 +92,11 @@ func Benchmark_WrapperLogger(t *testing.B) { } func Benchmark_WrapperWriter(t *testing.B) { - log15Logger := log15.New() + gLogger := glog.New() var buff bytes.Buffer - log15Logger.SetHandler(log15.StreamHandler(&buff, log15.LogfmtFormat())) - gokit := gokit_log.NewLogfmtLogger(NewWrapper(log15Logger)) + gLogger.AddLogger(log.NewLogfmtLogger(&buff), "info", map[string]level.Option{}) + gokit := NewWrapper(gLogger) + for i := 0; i < t.N; i++ { _ = level.Info(gokit).Log("msg", "test", "some", "more", "context", "data") }