mirror of
https://github.com/grafana/grafana.git
synced 2024-11-30 12:44:10 -06:00
255 lines
8.2 KiB
Go
255 lines
8.2 KiB
Go
package log
|
|
|
|
import (
|
|
"fmt"
|
|
"testing"
|
|
"time"
|
|
|
|
gokitlog "github.com/go-kit/log"
|
|
"github.com/grafana/grafana/pkg/infra/log/level"
|
|
"github.com/grafana/grafana/pkg/util"
|
|
"github.com/stretchr/testify/require"
|
|
)
|
|
|
|
func TestLogger(t *testing.T) {
|
|
t.Run("Root logger should be initialized", func(t *testing.T) {
|
|
require.NotNil(t, root)
|
|
err := root.Log("msg", "hello")
|
|
require.NoError(t, err)
|
|
})
|
|
|
|
newLoggerScenario(t, "When creating root logger should log as expected", func(t *testing.T, ctx *scenarioContext) {
|
|
log1 := New("one")
|
|
err := log1.Log("msg", "hello 1")
|
|
require.NoError(t, err)
|
|
log2 := New("two")
|
|
err = log2.Log("msg", "hello 2")
|
|
require.NoError(t, err)
|
|
log3 := New("three")
|
|
log3.Error("hello 3")
|
|
log4 := log3.New("key", "value")
|
|
err = log4.Log("msg", "hello 4")
|
|
require.NoError(t, err)
|
|
log3.Error("hello 3 again")
|
|
|
|
require.Len(t, ctx.loggedArgs, 5)
|
|
require.Len(t, ctx.loggedArgs[0], 4)
|
|
require.Equal(t, "logger", ctx.loggedArgs[0][0].(string))
|
|
require.Equal(t, "one", ctx.loggedArgs[0][1].(string))
|
|
require.Equal(t, "msg", ctx.loggedArgs[0][2].(string))
|
|
require.Equal(t, "hello 1", ctx.loggedArgs[0][3].(string))
|
|
|
|
require.Len(t, ctx.loggedArgs[1], 4)
|
|
require.Equal(t, "logger", ctx.loggedArgs[1][0].(string))
|
|
require.Equal(t, "two", ctx.loggedArgs[1][1].(string))
|
|
require.Equal(t, "msg", ctx.loggedArgs[1][2].(string))
|
|
require.Equal(t, "hello 2", ctx.loggedArgs[1][3].(string))
|
|
|
|
require.Len(t, ctx.loggedArgs[2], 8)
|
|
require.Equal(t, "logger", ctx.loggedArgs[2][0].(string))
|
|
require.Equal(t, "three", ctx.loggedArgs[2][1].(string))
|
|
require.Equal(t, "t", ctx.loggedArgs[2][2].(string))
|
|
require.Equal(t, ctx.mockedTime.Format("2006-01-02T15:04:05.99-0700"), ctx.loggedArgs[2][3].(fmt.Stringer).String())
|
|
require.Equal(t, "lvl", ctx.loggedArgs[2][4].(string))
|
|
require.Equal(t, level.ErrorValue(), ctx.loggedArgs[2][5].(level.Value))
|
|
require.Equal(t, "msg", ctx.loggedArgs[2][6].(string))
|
|
require.Equal(t, "hello 3", ctx.loggedArgs[2][7].(string))
|
|
|
|
require.Len(t, ctx.loggedArgs[3], 6)
|
|
require.Equal(t, "logger", ctx.loggedArgs[3][0].(string))
|
|
require.Equal(t, "three", ctx.loggedArgs[3][1].(string))
|
|
require.Equal(t, "key", ctx.loggedArgs[3][2].(string))
|
|
require.Equal(t, "value", ctx.loggedArgs[3][3].(string))
|
|
require.Equal(t, "msg", ctx.loggedArgs[3][4].(string))
|
|
require.Equal(t, "hello 4", ctx.loggedArgs[3][5].(string))
|
|
|
|
require.Len(t, ctx.loggedArgs[4], 8)
|
|
require.Equal(t, "logger", ctx.loggedArgs[4][0].(string))
|
|
require.Equal(t, "three", ctx.loggedArgs[4][1].(string))
|
|
require.Equal(t, "t", ctx.loggedArgs[4][2].(string))
|
|
require.Equal(t, ctx.mockedTime.Format("2006-01-02T15:04:05.99-0700"), ctx.loggedArgs[4][3].(fmt.Stringer).String())
|
|
require.Equal(t, "lvl", ctx.loggedArgs[4][4].(string))
|
|
require.Equal(t, level.ErrorValue(), ctx.loggedArgs[4][5].(level.Value))
|
|
require.Equal(t, "msg", ctx.loggedArgs[4][6].(string))
|
|
require.Equal(t, "hello 3 again", ctx.loggedArgs[4][7].(string))
|
|
|
|
t.Run("When initializing root logger should swap loggers as expected", func(t *testing.T) {
|
|
swappedLoggedArgs := [][]interface{}{}
|
|
swapLogger := gokitlog.LoggerFunc(func(i ...interface{}) error {
|
|
swappedLoggedArgs = append(swappedLoggedArgs, i)
|
|
return nil
|
|
})
|
|
|
|
root.initialize([]logWithFilters{
|
|
{
|
|
val: swapLogger,
|
|
maxLevel: level.AllowInfo(),
|
|
},
|
|
{
|
|
val: swapLogger,
|
|
maxLevel: level.AllowAll(),
|
|
},
|
|
})
|
|
|
|
err := log1.Log("msg", "hello 1")
|
|
require.NoError(t, err)
|
|
err = log2.Log("msg", "hello 2")
|
|
require.NoError(t, err)
|
|
log3.Error("hello 3")
|
|
log3.Debug("debug")
|
|
|
|
require.Len(t, ctx.loggedArgs, 5)
|
|
require.Len(t, swappedLoggedArgs, 7, "expected 4 messages for AllowAll logger and 3 messages for AllowInfo logger")
|
|
})
|
|
})
|
|
}
|
|
|
|
func TestWithPrefix(t *testing.T) {
|
|
newLoggerScenario(t, "WithPrefix should prepend context to beginning of log message", func(t *testing.T, ctx *scenarioContext) {
|
|
ls := WithPrefix(New("test"), "k1", "v1")
|
|
ls.Info("hello", "k2", "v2")
|
|
require.Len(t, ctx.loggedArgs, 1)
|
|
require.Len(t, ctx.loggedArgs[0], 12)
|
|
|
|
args := ctx.loggedArgs[0]
|
|
require.Equal(t, "logger", args[0].(string))
|
|
require.Equal(t, "test", args[1].(string))
|
|
require.Equal(t, "k1", args[2].(string))
|
|
require.Equal(t, "v1", args[3].(string))
|
|
require.Equal(t, "t", args[4].(string))
|
|
require.Equal(t, ctx.mockedTime.Format("2006-01-02T15:04:05.99-0700"), args[5].(fmt.Stringer).String())
|
|
require.Equal(t, "lvl", args[6].(string))
|
|
require.Equal(t, level.InfoValue(), args[7].(level.Value))
|
|
require.Equal(t, "msg", args[8].(string))
|
|
require.Equal(t, "hello", args[9].(string))
|
|
require.Equal(t, "k2", args[10].(string))
|
|
require.Equal(t, "v2", args[11].(string))
|
|
})
|
|
}
|
|
|
|
func TestWithSuffix(t *testing.T) {
|
|
newLoggerScenario(t, "WithSuffix should append context to end of log message", func(t *testing.T, ctx *scenarioContext) {
|
|
ls := WithSuffix(New("test"), "k1", "v1")
|
|
ls.Info("hello", "k2", "v2")
|
|
require.Len(t, ctx.loggedArgs, 1)
|
|
require.Len(t, ctx.loggedArgs[0], 12)
|
|
|
|
args := ctx.loggedArgs[0]
|
|
require.Equal(t, "logger", args[0].(string))
|
|
require.Equal(t, "test", args[1].(string))
|
|
require.Equal(t, "t", args[2].(string))
|
|
require.Equal(t, ctx.mockedTime.Format("2006-01-02T15:04:05.99-0700"), args[3].(fmt.Stringer).String())
|
|
require.Equal(t, "lvl", args[4].(string))
|
|
require.Equal(t, level.InfoValue(), args[5].(level.Value))
|
|
require.Equal(t, "msg", args[6].(string))
|
|
require.Equal(t, "hello", args[7].(string))
|
|
require.Equal(t, "k2", args[8].(string))
|
|
require.Equal(t, "v2", args[9].(string))
|
|
require.Equal(t, "k1", args[10].(string))
|
|
require.Equal(t, "v1", args[11].(string))
|
|
})
|
|
}
|
|
|
|
func TestGetFilters(t *testing.T) {
|
|
t.Run("Parsing filters on single line with only space should return expected result", func(t *testing.T) {
|
|
filter := ` `
|
|
filters := getFilters(util.SplitString(filter))
|
|
require.Len(t, filters, 0)
|
|
})
|
|
|
|
t.Run("Parsing filters on single line with should return expected result", func(t *testing.T) {
|
|
filter := `rendering:debug oauth.generic_oauth:debug testwithoutlevel provisioning.dashboard:debug`
|
|
filters := getFilters(util.SplitString(filter))
|
|
keys := []string{}
|
|
for k := range filters {
|
|
keys = append(keys, k)
|
|
}
|
|
|
|
require.ElementsMatch(t, []string{
|
|
"rendering",
|
|
"oauth.generic_oauth",
|
|
"provisioning.dashboard",
|
|
}, keys)
|
|
})
|
|
|
|
t.Run("Parsing filters spread over multiple lines with comments should return expected result", func(t *testing.T) {
|
|
filter := `rendering:debug \
|
|
; alerting.notifier:debug \
|
|
oauth.generic_oauth:debug \
|
|
; oauth.okta:debug \
|
|
; tsdb.postgres:debug \
|
|
;tsdb.mssql:debug \
|
|
#provisioning.plugins:debug \
|
|
provisioning.dashboard:debug \
|
|
data-proxy-log:debug \
|
|
;oauthtoken:debug \
|
|
plugins.backend:debug \
|
|
tsdb.elasticsearch.client:debug \
|
|
server:debug \
|
|
tsdb.graphite:debug \
|
|
auth:debug \
|
|
plugin.manager:debug \
|
|
plugin.initializer:debug \
|
|
plugin.loader:debug \
|
|
plugin.finder:debug \
|
|
plugin.installer:debug \
|
|
plugin.signature.validator:debug`
|
|
filters := getFilters(util.SplitString(filter))
|
|
keys := []string{}
|
|
for k := range filters {
|
|
keys = append(keys, k)
|
|
}
|
|
|
|
require.ElementsMatch(t, []string{
|
|
"rendering",
|
|
"oauth.generic_oauth",
|
|
"provisioning.dashboard",
|
|
"data-proxy-log",
|
|
"plugins.backend",
|
|
"tsdb.elasticsearch.client",
|
|
"server",
|
|
"tsdb.graphite",
|
|
"auth",
|
|
"plugin.manager",
|
|
"plugin.initializer",
|
|
"plugin.loader",
|
|
"plugin.finder",
|
|
"plugin.installer",
|
|
"plugin.signature.validator",
|
|
}, keys)
|
|
})
|
|
}
|
|
|
|
type scenarioContext struct {
|
|
loggedArgs [][]interface{}
|
|
mockedTime time.Time
|
|
}
|
|
|
|
func newLoggerScenario(t *testing.T, desc string, fn func(t *testing.T, ctx *scenarioContext)) {
|
|
t.Helper()
|
|
|
|
ctx := &scenarioContext{
|
|
loggedArgs: [][]interface{}{},
|
|
mockedTime: time.Now(),
|
|
}
|
|
|
|
l := gokitlog.LoggerFunc(func(i ...interface{}) error {
|
|
ctx.loggedArgs = append(ctx.loggedArgs, i)
|
|
return nil
|
|
})
|
|
|
|
origNow := now
|
|
now = func() time.Time {
|
|
return ctx.mockedTime
|
|
}
|
|
t.Cleanup(func() {
|
|
now = origNow
|
|
})
|
|
|
|
root = newManager(l)
|
|
|
|
t.Run(desc, func(t *testing.T) {
|
|
fn(t, ctx)
|
|
})
|
|
}
|