diff --git a/pkg/infra/log/log.go b/pkg/infra/log/log.go index f8d074b33dd..bd393178a26 100644 --- a/pkg/infra/log/log.go +++ b/pkg/infra/log/log.go @@ -15,11 +15,12 @@ import ( gokitlog "github.com/go-kit/log" "github.com/go-kit/log/term" "github.com/go-stack/stack" + "github.com/mattn/go-isatty" + "gopkg.in/ini.v1" + "github.com/grafana/grafana/pkg/infra/log/level" "github.com/grafana/grafana/pkg/util" "github.com/grafana/grafana/pkg/util/errutil" - "github.com/mattn/go-isatty" - "gopkg.in/ini.v1" ) var loggersToClose []DisposableHandler @@ -27,6 +28,12 @@ var loggersToReload []ReloadableHandler var filters map[string]level.Option var Root MultiLoggers +const ( + // top 7 calls in the stack are within logger + DefaultCallerDepth = 7 + CallerContextKey = "caller" +) + func init() { loggersToClose = make([]DisposableHandler, 0) loggersToReload = make([]ReloadableHandler, 0) @@ -99,24 +106,13 @@ func (ml MultiLoggers) Log(keyvals ...interface{}) error { return nil } -// we need to implement new function for multiloggers +// New creates a new logger from the existing one with additional context 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 + return with(ml, gokitlog.With, ctx) } +// New creates MultiLoggers with the provided context and caller that is added as a suffix. +// The first element of the context must be the logger name func New(ctx ...interface{}) MultiLoggers { if len(ctx) == 0 { return Root @@ -136,6 +132,28 @@ func New(ctx ...interface{}) MultiLoggers { return newloger } +func with(loggers MultiLoggers, withFunc func(gokitlog.Logger, ...interface{}) gokitlog.Logger, ctx []interface{}) MultiLoggers { + if len(ctx) == 0 { + return loggers + } + var newloger MultiLoggers + for _, l := range loggers.loggers { + l.val = withFunc(l.val, ctx...) + newloger.loggers = append(newloger.loggers, l) + } + return newloger +} + +// WithPrefix adds context that will be added to the log message +func WithPrefix(loggers MultiLoggers, ctx ...interface{}) MultiLoggers { + return with(loggers, gokitlog.WithPrefix, ctx) +} + +// WithSuffix adds context that will be appended at the end of the log message +func WithSuffix(loggers MultiLoggers, ctx ...interface{}) MultiLoggers { + return with(loggers, gokitlog.WithSuffix, ctx) +} + var logLevels = map[string]level.Option{ "trace": level.AllowDebug(), "debug": level.AllowDebug(), @@ -183,6 +201,19 @@ func Stack(skip int) string { return s.String() } +// StackCaller returns a go-kit Valuer function that returns the stack trace from the place it is called. Argument `skip` allows skipping top n lines from the stack. +func StackCaller(skip int) gokitlog.Valuer { + return func() interface{} { + return Stack(skip + 1) + } +} + +// Caller proxies go-kit/log Caller and returns a Valuer function that returns a file and line from a specified depth +// in the callstack +func Caller(depth int) gokitlog.Valuer { + return gokitlog.Caller(depth) +} + type Formatedlogger func(w io.Writer) gokitlog.Logger func terminalColorFn(keyvals ...interface{}) term.FgBgColor { diff --git a/pkg/login/social/generic_oauth_test.go b/pkg/login/social/generic_oauth_test.go index b7df2e97cee..b72172ab88b 100644 --- a/pkg/login/social/generic_oauth_test.go +++ b/pkg/login/social/generic_oauth_test.go @@ -7,15 +7,16 @@ import ( "testing" "time" - "github.com/grafana/grafana/pkg/infra/log" - "github.com/grafana/grafana/pkg/infra/log/level" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "golang.org/x/oauth2" + + "github.com/grafana/grafana/pkg/infra/log" + "github.com/grafana/grafana/pkg/infra/log/level" ) func newLogger(name string, lev string) log.Logger { - logger := log.Root.New("logger", name) + logger := log.New(name) logger.AddLogger(logger, lev, map[string]level.Option{}) return logger } diff --git a/pkg/services/sqlstore/sqlstore.go b/pkg/services/sqlstore/sqlstore.go index 734b1f23653..6e8c0aec106 100644 --- a/pkg/services/sqlstore/sqlstore.go +++ b/pkg/services/sqlstore/sqlstore.go @@ -12,6 +12,9 @@ import ( "time" "github.com/go-sql-driver/mysql" + _ "github.com/lib/pq" + "xorm.io/xorm" + "github.com/grafana/grafana/pkg/bus" "github.com/grafana/grafana/pkg/infra/fs" "github.com/grafana/grafana/pkg/infra/localcache" @@ -25,8 +28,6 @@ import ( "github.com/grafana/grafana/pkg/setting" "github.com/grafana/grafana/pkg/util" "github.com/grafana/grafana/pkg/util/errutil" - _ "github.com/lib/pq" - "xorm.io/xorm" ) var ( @@ -372,7 +373,8 @@ func (ss *SQLStore) initEngine(engine *xorm.Engine) error { if !debugSQL { engine.SetLogger(&xorm.DiscardLogger{}) } else { - engine.SetLogger(NewXormLogger(log.LvlInfo, log.New("sqlstore.xorm"))) + // add stack to database calls to be able to see what repository initiated queries. Top 7 items from the stack as they are likely in the xorm library. + engine.SetLogger(NewXormLogger(log.LvlInfo, log.WithSuffix(log.New("sqlstore.xorm"), log.CallerContextKey, log.StackCaller(log.DefaultCallerDepth)))) engine.ShowSQL(true) engine.ShowExecTime(true) }