update
Some checks failed
Pipeline: Test, Lint, Build / Get version info (push) Has been cancelled
Pipeline: Test, Lint, Build / Lint Go code (push) Has been cancelled
Pipeline: Test, Lint, Build / Test Go code (push) Has been cancelled
Pipeline: Test, Lint, Build / Test JS code (push) Has been cancelled
Pipeline: Test, Lint, Build / Lint i18n files (push) Has been cancelled
Pipeline: Test, Lint, Build / Check Docker configuration (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (darwin/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (darwin/arm64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/386) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v5) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v6) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v7) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (windows/386) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (windows/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Push to GHCR (push) Has been cancelled
Pipeline: Test, Lint, Build / Push to Docker Hub (push) Has been cancelled
Pipeline: Test, Lint, Build / Cleanup digest artifacts (push) Has been cancelled
Pipeline: Test, Lint, Build / Build Windows installers (push) Has been cancelled
Pipeline: Test, Lint, Build / Package/Release (push) Has been cancelled
Pipeline: Test, Lint, Build / Upload Linux PKG (push) Has been cancelled
Close stale issues and PRs / stale (push) Has been cancelled
POEditor import / update-translations (push) Has been cancelled
Some checks failed
Pipeline: Test, Lint, Build / Get version info (push) Has been cancelled
Pipeline: Test, Lint, Build / Lint Go code (push) Has been cancelled
Pipeline: Test, Lint, Build / Test Go code (push) Has been cancelled
Pipeline: Test, Lint, Build / Test JS code (push) Has been cancelled
Pipeline: Test, Lint, Build / Lint i18n files (push) Has been cancelled
Pipeline: Test, Lint, Build / Check Docker configuration (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (darwin/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (darwin/arm64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/386) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v5) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v6) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm/v7) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (linux/arm64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (windows/386) (push) Has been cancelled
Pipeline: Test, Lint, Build / Build (windows/amd64) (push) Has been cancelled
Pipeline: Test, Lint, Build / Push to GHCR (push) Has been cancelled
Pipeline: Test, Lint, Build / Push to Docker Hub (push) Has been cancelled
Pipeline: Test, Lint, Build / Cleanup digest artifacts (push) Has been cancelled
Pipeline: Test, Lint, Build / Build Windows installers (push) Has been cancelled
Pipeline: Test, Lint, Build / Package/Release (push) Has been cancelled
Pipeline: Test, Lint, Build / Upload Linux PKG (push) Has been cancelled
Close stale issues and PRs / stale (push) Has been cancelled
POEditor import / update-translations (push) Has been cancelled
This commit is contained in:
74
log/formatters.go
Normal file
74
log/formatters.go
Normal file
@@ -0,0 +1,74 @@
|
||||
package log
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"io"
|
||||
"iter"
|
||||
"reflect"
|
||||
"slices"
|
||||
"strings"
|
||||
"time"
|
||||
|
||||
"github.com/navidrome/navidrome/utils/slice"
|
||||
)
|
||||
|
||||
func ShortDur(d time.Duration) string {
|
||||
var s string
|
||||
switch {
|
||||
case d > time.Hour:
|
||||
s = d.Round(time.Minute).String()
|
||||
case d > time.Minute:
|
||||
s = d.Round(time.Second).String()
|
||||
case d > time.Second:
|
||||
s = d.Round(10 * time.Millisecond).String()
|
||||
case d > time.Millisecond:
|
||||
s = d.Round(100 * time.Microsecond).String()
|
||||
default:
|
||||
s = d.String()
|
||||
}
|
||||
s = strings.TrimSuffix(s, "0s")
|
||||
return strings.TrimSuffix(s, "0m")
|
||||
}
|
||||
|
||||
func StringerValue(s fmt.Stringer) string {
|
||||
v := reflect.ValueOf(s)
|
||||
if v.Kind() == reflect.Pointer && v.IsNil() {
|
||||
return "nil"
|
||||
}
|
||||
return s.String()
|
||||
}
|
||||
|
||||
func formatSeq[T any](v iter.Seq[T]) string {
|
||||
return formatSlice(slices.Collect(v))
|
||||
}
|
||||
|
||||
func formatSlice[T any](v []T) string {
|
||||
s := slice.Map(v, func(x T) string { return fmt.Sprintf("%v", x) })
|
||||
return fmt.Sprintf("[`%s`]", strings.Join(s, "`,`"))
|
||||
}
|
||||
|
||||
func CRLFWriter(w io.Writer) io.Writer {
|
||||
return &crlfWriter{w: w}
|
||||
}
|
||||
|
||||
type crlfWriter struct {
|
||||
w io.Writer
|
||||
lastByte byte
|
||||
}
|
||||
|
||||
func (cw *crlfWriter) Write(p []byte) (int, error) {
|
||||
var written int
|
||||
for _, b := range p {
|
||||
if b == '\n' && cw.lastByte != '\r' {
|
||||
if _, err := cw.w.Write([]byte{'\r'}); err != nil {
|
||||
return written, err
|
||||
}
|
||||
}
|
||||
if _, err := cw.w.Write([]byte{b}); err != nil {
|
||||
return written, err
|
||||
}
|
||||
written++
|
||||
cw.lastByte = b
|
||||
}
|
||||
return written, nil
|
||||
}
|
||||
70
log/formatters_test.go
Normal file
70
log/formatters_test.go
Normal file
@@ -0,0 +1,70 @@
|
||||
package log_test
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"io"
|
||||
"time"
|
||||
|
||||
"github.com/navidrome/navidrome/log"
|
||||
. "github.com/onsi/ginkgo/v2"
|
||||
. "github.com/onsi/gomega"
|
||||
)
|
||||
|
||||
var _ = DescribeTable("ShortDur",
|
||||
func(d time.Duration, expected string) {
|
||||
Expect(log.ShortDur(d)).To(Equal(expected))
|
||||
},
|
||||
Entry("1ns", 1*time.Nanosecond, "1ns"),
|
||||
Entry("9µs", 9*time.Microsecond, "9µs"),
|
||||
Entry("2ms", 2*time.Millisecond, "2ms"),
|
||||
Entry("5ms", 5*time.Millisecond, "5ms"),
|
||||
Entry("5.2ms", 5*time.Millisecond+240*time.Microsecond, "5.2ms"),
|
||||
Entry("1s", 1*time.Second, "1s"),
|
||||
Entry("1.26s", 1*time.Second+263*time.Millisecond, "1.26s"),
|
||||
Entry("4m", 4*time.Minute, "4m"),
|
||||
Entry("4m3s", 4*time.Minute+3*time.Second, "4m3s"),
|
||||
Entry("4h", 4*time.Hour, "4h"),
|
||||
Entry("4h", 4*time.Hour+2*time.Second, "4h"),
|
||||
Entry("4h2m", 4*time.Hour+2*time.Minute+5*time.Second+200*time.Millisecond, "4h2m"),
|
||||
)
|
||||
|
||||
var _ = Describe("StringerValue", func() {
|
||||
It("should return the string representation of a fmt.Stringer", func() {
|
||||
Expect(log.StringerValue(time.Second)).To(Equal("1s"))
|
||||
})
|
||||
It("should return 'nil' for a nil fmt.Stringer", func() {
|
||||
v := (*time.Time)(nil)
|
||||
Expect(log.StringerValue(v)).To(Equal("nil"))
|
||||
})
|
||||
})
|
||||
|
||||
var _ = Describe("CRLFWriter", func() {
|
||||
var (
|
||||
buffer *bytes.Buffer
|
||||
writer io.Writer
|
||||
)
|
||||
|
||||
BeforeEach(func() {
|
||||
buffer = new(bytes.Buffer)
|
||||
writer = log.CRLFWriter(buffer)
|
||||
})
|
||||
|
||||
Describe("Write", func() {
|
||||
It("should convert all LFs to CRLFs", func() {
|
||||
n, err := writer.Write([]byte("hello\nworld\nagain\n"))
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
Expect(n).To(Equal(18))
|
||||
Expect(buffer.String()).To(Equal("hello\r\nworld\r\nagain\r\n"))
|
||||
})
|
||||
|
||||
It("should not convert LF to CRLF if preceded by CR", func() {
|
||||
n, err := writer.Write([]byte("hello\r"))
|
||||
Expect(n).To(Equal(6))
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
n, err = writer.Write([]byte("\nworld\n"))
|
||||
Expect(n).To(Equal(7))
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
Expect(buffer.String()).To(Equal("hello\r\nworld\r\n"))
|
||||
})
|
||||
})
|
||||
})
|
||||
351
log/log.go
Normal file
351
log/log.go
Normal file
@@ -0,0 +1,351 @@
|
||||
package log
|
||||
|
||||
import (
|
||||
"context"
|
||||
"errors"
|
||||
"fmt"
|
||||
"io"
|
||||
"iter"
|
||||
"net/http"
|
||||
"os"
|
||||
"runtime"
|
||||
"sort"
|
||||
"strings"
|
||||
"sync"
|
||||
"time"
|
||||
|
||||
"github.com/sirupsen/logrus"
|
||||
)
|
||||
|
||||
type Level uint32
|
||||
|
||||
type LevelFunc = func(ctx interface{}, msg interface{}, keyValuePairs ...interface{})
|
||||
|
||||
var redacted = &Hook{
|
||||
AcceptedLevels: logrus.AllLevels,
|
||||
RedactionList: []string{
|
||||
// Keys from the config
|
||||
"(ApiKey:\")[\\w]*",
|
||||
"(Secret:\")[\\w]*",
|
||||
"(Spotify.*ID:\")[\\w]*",
|
||||
"(PasswordEncryptionKey:[\\s]*\")[^\"]*",
|
||||
"(UserHeader:[\\s]*\")[^\"]*",
|
||||
"(TrustedSources:[\\s]*\")[^\"]*",
|
||||
"(MetricsPath:[\\s]*\")[^\"]*",
|
||||
"(DevAutoCreateAdminPassword:[\\s]*\")[^\"]*",
|
||||
"(DevAutoLoginUsername:[\\s]*\")[^\"]*",
|
||||
|
||||
// UI appConfig
|
||||
"(subsonicToken:)[\\w]+(\\s)",
|
||||
"(subsonicSalt:)[\\w]+(\\s)",
|
||||
"(token:)[^\\s]+",
|
||||
|
||||
// Subsonic query params
|
||||
"([^\\w]t=)[\\w]+",
|
||||
"([^\\w]s=)[^&]+",
|
||||
"([^\\w]p=)[^&]+",
|
||||
"([^\\w]jwt=)[^&]+",
|
||||
|
||||
// External services query params
|
||||
"([^\\w]api_key=)[\\w]+",
|
||||
},
|
||||
}
|
||||
|
||||
const (
|
||||
LevelFatal = Level(logrus.FatalLevel)
|
||||
LevelError = Level(logrus.ErrorLevel)
|
||||
LevelWarn = Level(logrus.WarnLevel)
|
||||
LevelInfo = Level(logrus.InfoLevel)
|
||||
LevelDebug = Level(logrus.DebugLevel)
|
||||
LevelTrace = Level(logrus.TraceLevel)
|
||||
)
|
||||
|
||||
type contextKey string
|
||||
|
||||
const loggerCtxKey = contextKey("logger")
|
||||
|
||||
type levelPath struct {
|
||||
path string
|
||||
level Level
|
||||
}
|
||||
|
||||
var (
|
||||
currentLevel Level
|
||||
loggerMu sync.RWMutex
|
||||
defaultLogger = logrus.New()
|
||||
logSourceLine = false
|
||||
rootPath string
|
||||
logLevels []levelPath
|
||||
)
|
||||
|
||||
// SetLevel sets the global log level used by the simple logger.
|
||||
func SetLevel(l Level) {
|
||||
loggerMu.Lock()
|
||||
currentLevel = l
|
||||
defaultLogger.Level = logrus.TraceLevel
|
||||
loggerMu.Unlock()
|
||||
logrus.SetLevel(logrus.Level(l))
|
||||
}
|
||||
|
||||
func SetLevelString(l string) {
|
||||
level := levelFromString(l)
|
||||
SetLevel(level)
|
||||
}
|
||||
|
||||
func levelFromString(l string) Level {
|
||||
envLevel := strings.ToLower(l)
|
||||
var level Level
|
||||
switch envLevel {
|
||||
case "fatal":
|
||||
level = LevelFatal
|
||||
case "error":
|
||||
level = LevelError
|
||||
case "warn":
|
||||
level = LevelWarn
|
||||
case "debug":
|
||||
level = LevelDebug
|
||||
case "trace":
|
||||
level = LevelTrace
|
||||
default:
|
||||
level = LevelInfo
|
||||
}
|
||||
return level
|
||||
}
|
||||
|
||||
// SetLogLevels sets the log levels for specific paths in the codebase.
|
||||
func SetLogLevels(levels map[string]string) {
|
||||
loggerMu.Lock()
|
||||
defer loggerMu.Unlock()
|
||||
logLevels = nil
|
||||
for k, v := range levels {
|
||||
logLevels = append(logLevels, levelPath{path: k, level: levelFromString(v)})
|
||||
}
|
||||
sort.Slice(logLevels, func(i, j int) bool {
|
||||
return logLevels[i].path > logLevels[j].path
|
||||
})
|
||||
}
|
||||
|
||||
func SetLogSourceLine(enabled bool) {
|
||||
logSourceLine = enabled
|
||||
}
|
||||
|
||||
func SetRedacting(enabled bool) {
|
||||
if enabled {
|
||||
loggerMu.Lock()
|
||||
defer loggerMu.Unlock()
|
||||
defaultLogger.AddHook(redacted)
|
||||
}
|
||||
}
|
||||
|
||||
func SetOutput(w io.Writer) {
|
||||
if runtime.GOOS == "windows" {
|
||||
w = CRLFWriter(w)
|
||||
}
|
||||
loggerMu.Lock()
|
||||
defer loggerMu.Unlock()
|
||||
defaultLogger.SetOutput(w)
|
||||
}
|
||||
|
||||
// Redact applies redaction to a single string
|
||||
func Redact(msg string) string {
|
||||
r, _ := redacted.redact(msg)
|
||||
return r
|
||||
}
|
||||
|
||||
func NewContext(ctx context.Context, keyValuePairs ...interface{}) context.Context {
|
||||
if ctx == nil {
|
||||
ctx = context.Background()
|
||||
}
|
||||
|
||||
logger, ok := ctx.Value(loggerCtxKey).(*logrus.Entry)
|
||||
if !ok {
|
||||
logger = createNewLogger()
|
||||
}
|
||||
logger = addFields(logger, keyValuePairs)
|
||||
ctx = context.WithValue(ctx, loggerCtxKey, logger)
|
||||
|
||||
return ctx
|
||||
}
|
||||
|
||||
func SetDefaultLogger(l *logrus.Logger) {
|
||||
loggerMu.Lock()
|
||||
defer loggerMu.Unlock()
|
||||
defaultLogger = l
|
||||
}
|
||||
|
||||
func CurrentLevel() Level {
|
||||
loggerMu.RLock()
|
||||
defer loggerMu.RUnlock()
|
||||
return currentLevel
|
||||
}
|
||||
|
||||
// IsGreaterOrEqualTo returns true if the caller's current log level is equal or greater than the provided level.
|
||||
func IsGreaterOrEqualTo(level Level) bool {
|
||||
return shouldLog(level, 2)
|
||||
}
|
||||
|
||||
func Fatal(args ...interface{}) {
|
||||
log(LevelFatal, args...)
|
||||
os.Exit(1)
|
||||
}
|
||||
|
||||
func Error(args ...interface{}) {
|
||||
log(LevelError, args...)
|
||||
}
|
||||
|
||||
func Warn(args ...interface{}) {
|
||||
log(LevelWarn, args...)
|
||||
}
|
||||
|
||||
func Info(args ...interface{}) {
|
||||
log(LevelInfo, args...)
|
||||
}
|
||||
|
||||
func Debug(args ...interface{}) {
|
||||
log(LevelDebug, args...)
|
||||
}
|
||||
|
||||
func Trace(args ...interface{}) {
|
||||
log(LevelTrace, args...)
|
||||
}
|
||||
|
||||
func log(level Level, args ...interface{}) {
|
||||
if !shouldLog(level, 3) {
|
||||
return
|
||||
}
|
||||
logger, msg := parseArgs(args)
|
||||
logger.Log(logrus.Level(level), msg)
|
||||
}
|
||||
|
||||
func Writer() io.Writer {
|
||||
loggerMu.RLock()
|
||||
defer loggerMu.RUnlock()
|
||||
return defaultLogger.Writer()
|
||||
}
|
||||
|
||||
func shouldLog(requiredLevel Level, skip int) bool {
|
||||
loggerMu.RLock()
|
||||
level := currentLevel
|
||||
levels := logLevels
|
||||
loggerMu.RUnlock()
|
||||
|
||||
if level >= requiredLevel {
|
||||
return true
|
||||
}
|
||||
if len(levels) == 0 {
|
||||
return false
|
||||
}
|
||||
|
||||
_, file, _, ok := runtime.Caller(skip)
|
||||
if !ok {
|
||||
return false
|
||||
}
|
||||
|
||||
file = strings.TrimPrefix(file, rootPath)
|
||||
for _, lp := range levels {
|
||||
if strings.HasPrefix(file, lp.path) {
|
||||
return lp.level >= requiredLevel
|
||||
}
|
||||
}
|
||||
return false
|
||||
}
|
||||
|
||||
func parseArgs(args []interface{}) (*logrus.Entry, string) {
|
||||
var l *logrus.Entry
|
||||
var err error
|
||||
if args[0] == nil {
|
||||
l = createNewLogger()
|
||||
args = args[1:]
|
||||
} else {
|
||||
l, err = extractLogger(args[0])
|
||||
if err != nil {
|
||||
l = createNewLogger()
|
||||
} else {
|
||||
args = args[1:]
|
||||
}
|
||||
}
|
||||
if len(args) > 1 {
|
||||
kvPairs := args[1:]
|
||||
l = addFields(l, kvPairs)
|
||||
}
|
||||
if logSourceLine {
|
||||
_, file, line, ok := runtime.Caller(3)
|
||||
if !ok {
|
||||
file = "???"
|
||||
line = 0
|
||||
}
|
||||
//_, filename := path.Split(file)
|
||||
//l = l.WithField("filename", filename).WithField("line", line)
|
||||
l = l.WithField(" source", fmt.Sprintf("file://%s:%d", file, line))
|
||||
}
|
||||
|
||||
switch msg := args[0].(type) {
|
||||
case error:
|
||||
return l, msg.Error()
|
||||
case string:
|
||||
return l, msg
|
||||
}
|
||||
|
||||
return l, ""
|
||||
}
|
||||
|
||||
func addFields(logger *logrus.Entry, keyValuePairs []interface{}) *logrus.Entry {
|
||||
for i := 0; i < len(keyValuePairs); i += 2 {
|
||||
switch name := keyValuePairs[i].(type) {
|
||||
case error:
|
||||
logger = logger.WithField("error", name.Error())
|
||||
case string:
|
||||
if i+1 >= len(keyValuePairs) {
|
||||
logger = logger.WithField(name, "!!!!Invalid number of arguments in log call!!!!")
|
||||
} else {
|
||||
switch v := keyValuePairs[i+1].(type) {
|
||||
case time.Duration:
|
||||
logger = logger.WithField(name, ShortDur(v))
|
||||
case fmt.Stringer:
|
||||
logger = logger.WithField(name, StringerValue(v))
|
||||
case iter.Seq[string]:
|
||||
logger = logger.WithField(name, formatSeq(v))
|
||||
case []string:
|
||||
logger = logger.WithField(name, formatSlice(v))
|
||||
default:
|
||||
logger = logger.WithField(name, v)
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
return logger
|
||||
}
|
||||
|
||||
func extractLogger(ctx interface{}) (*logrus.Entry, error) {
|
||||
switch ctx := ctx.(type) {
|
||||
case *logrus.Entry:
|
||||
return ctx, nil
|
||||
case context.Context:
|
||||
logger := ctx.Value(loggerCtxKey)
|
||||
if logger != nil {
|
||||
return logger.(*logrus.Entry), nil
|
||||
}
|
||||
return extractLogger(NewContext(ctx))
|
||||
case *http.Request:
|
||||
return extractLogger(ctx.Context())
|
||||
}
|
||||
return nil, errors.New("no logger found")
|
||||
}
|
||||
|
||||
func createNewLogger() *logrus.Entry {
|
||||
//logrus.SetFormatter(&logrus.TextFormatter{ForceColors: true, DisableTimestamp: false, FullTimestamp: true})
|
||||
//l.Formatter = &logrus.TextFormatter{ForceColors: true, DisableTimestamp: false, FullTimestamp: true}
|
||||
loggerMu.RLock()
|
||||
defer loggerMu.RUnlock()
|
||||
logger := logrus.NewEntry(defaultLogger)
|
||||
return logger
|
||||
}
|
||||
|
||||
func init() {
|
||||
defaultLogger.Level = logrus.TraceLevel
|
||||
_, file, _, ok := runtime.Caller(0)
|
||||
if !ok {
|
||||
return
|
||||
}
|
||||
rootPath = strings.TrimSuffix(file, "log/log.go")
|
||||
}
|
||||
249
log/log_test.go
Normal file
249
log/log_test.go
Normal file
@@ -0,0 +1,249 @@
|
||||
package log
|
||||
|
||||
import (
|
||||
"context"
|
||||
"errors"
|
||||
"net/http/httptest"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
. "github.com/onsi/ginkgo/v2"
|
||||
. "github.com/onsi/gomega"
|
||||
"github.com/sirupsen/logrus"
|
||||
"github.com/sirupsen/logrus/hooks/test"
|
||||
)
|
||||
|
||||
func TestLog(t *testing.T) {
|
||||
SetLevel(LevelInfo)
|
||||
RegisterFailHandler(Fail)
|
||||
RunSpecs(t, "Log Suite")
|
||||
}
|
||||
|
||||
var _ = Describe("Logger", func() {
|
||||
var l *logrus.Logger
|
||||
var hook *test.Hook
|
||||
|
||||
BeforeEach(func() {
|
||||
l, hook = test.NewNullLogger()
|
||||
SetLevel(LevelTrace)
|
||||
SetDefaultLogger(l)
|
||||
})
|
||||
|
||||
Describe("Logging", func() {
|
||||
It("logs a simple message", func() {
|
||||
Error("Simple Message")
|
||||
Expect(hook.LastEntry().Message).To(Equal("Simple Message"))
|
||||
Expect(hook.LastEntry().Data).To(BeEmpty())
|
||||
})
|
||||
|
||||
It("logs a message when context is nil", func() {
|
||||
Error(nil, "Simple Message")
|
||||
Expect(hook.LastEntry().Message).To(Equal("Simple Message"))
|
||||
Expect(hook.LastEntry().Data).To(BeEmpty())
|
||||
})
|
||||
|
||||
It("Empty context", func() {
|
||||
Error(context.TODO(), "Simple Message")
|
||||
Expect(hook.LastEntry().Message).To(Equal("Simple Message"))
|
||||
Expect(hook.LastEntry().Data).To(BeEmpty())
|
||||
})
|
||||
|
||||
It("logs messages with two kv pairs", func() {
|
||||
Error("Simple Message", "key1", "value1", "key2", "value2")
|
||||
Expect(hook.LastEntry().Message).To(Equal("Simple Message"))
|
||||
Expect(hook.LastEntry().Data["key1"]).To(Equal("value1"))
|
||||
Expect(hook.LastEntry().Data["key2"]).To(Equal("value2"))
|
||||
Expect(hook.LastEntry().Data).To(HaveLen(2))
|
||||
})
|
||||
|
||||
It("logs error objects as simple messages", func() {
|
||||
Error(errors.New("error test"))
|
||||
Expect(hook.LastEntry().Message).To(Equal("error test"))
|
||||
Expect(hook.LastEntry().Data).To(BeEmpty())
|
||||
})
|
||||
|
||||
It("logs errors passed as last argument", func() {
|
||||
Error("Error scrobbling track", "id", 1, errors.New("some issue"))
|
||||
Expect(hook.LastEntry().Message).To(Equal("Error scrobbling track"))
|
||||
Expect(hook.LastEntry().Data["id"]).To(Equal(1))
|
||||
Expect(hook.LastEntry().Data["error"]).To(Equal("some issue"))
|
||||
Expect(hook.LastEntry().Data).To(HaveLen(2))
|
||||
})
|
||||
|
||||
It("can get data from the request's context", func() {
|
||||
ctx := NewContext(context.TODO(), "foo", "bar")
|
||||
req := httptest.NewRequest("get", "/", nil).WithContext(ctx)
|
||||
|
||||
Error(req, "Simple Message", "key1", "value1")
|
||||
|
||||
Expect(hook.LastEntry().Message).To(Equal("Simple Message"))
|
||||
Expect(hook.LastEntry().Data["foo"]).To(Equal("bar"))
|
||||
Expect(hook.LastEntry().Data["key1"]).To(Equal("value1"))
|
||||
Expect(hook.LastEntry().Data).To(HaveLen(2))
|
||||
})
|
||||
|
||||
It("does not log anything if level is lower", func() {
|
||||
SetLevel(LevelError)
|
||||
Info("Simple Message")
|
||||
Expect(hook.LastEntry()).To(BeNil())
|
||||
})
|
||||
|
||||
It("logs source file and line number, if requested", func() {
|
||||
SetLogSourceLine(true)
|
||||
Error("A crash happened")
|
||||
// NOTE: This assertion breaks if the line number above changes
|
||||
Expect(hook.LastEntry().Data[" source"]).To(ContainSubstring("/log/log_test.go:93"))
|
||||
Expect(hook.LastEntry().Message).To(Equal("A crash happened"))
|
||||
})
|
||||
|
||||
It("logs fmt.Stringer as a string", func() {
|
||||
t := time.Now()
|
||||
Error("Simple Message", "key1", t)
|
||||
Expect(hook.LastEntry().Data["key1"]).To(Equal(t.String()))
|
||||
})
|
||||
It("logs nil fmt.Stringer as nil", func() {
|
||||
var t *time.Time
|
||||
Error("Simple Message", "key1", t)
|
||||
Expect(hook.LastEntry().Data["key1"]).To(Equal("nil"))
|
||||
})
|
||||
})
|
||||
|
||||
Describe("Levels", func() {
|
||||
BeforeEach(func() {
|
||||
SetLevel(LevelTrace)
|
||||
})
|
||||
It("logs error messages", func() {
|
||||
Error("msg")
|
||||
Expect(hook.LastEntry().Level).To(Equal(logrus.ErrorLevel))
|
||||
})
|
||||
It("logs warn messages", func() {
|
||||
Warn("msg")
|
||||
Expect(hook.LastEntry().Level).To(Equal(logrus.WarnLevel))
|
||||
})
|
||||
It("logs info messages", func() {
|
||||
Info("msg")
|
||||
Expect(hook.LastEntry().Level).To(Equal(logrus.InfoLevel))
|
||||
})
|
||||
It("logs debug messages", func() {
|
||||
Debug("msg")
|
||||
Expect(hook.LastEntry().Level).To(Equal(logrus.DebugLevel))
|
||||
})
|
||||
It("logs trace messages", func() {
|
||||
Trace("msg")
|
||||
Expect(hook.LastEntry().Level).To(Equal(logrus.TraceLevel))
|
||||
})
|
||||
})
|
||||
|
||||
Describe("LogLevels", func() {
|
||||
It("logs at specific levels", func() {
|
||||
SetLevel(LevelError)
|
||||
Debug("message 1")
|
||||
Expect(hook.LastEntry()).To(BeNil())
|
||||
|
||||
SetLogLevels(map[string]string{
|
||||
"log/log_test": "debug",
|
||||
})
|
||||
|
||||
Debug("message 2")
|
||||
Expect(hook.LastEntry().Message).To(Equal("message 2"))
|
||||
})
|
||||
})
|
||||
|
||||
Describe("IsGreaterOrEqualTo", func() {
|
||||
BeforeEach(func() {
|
||||
SetLogLevels(nil)
|
||||
})
|
||||
|
||||
It("returns false if log level is below provided level", func() {
|
||||
SetLevel(LevelError)
|
||||
Expect(IsGreaterOrEqualTo(LevelWarn)).To(BeFalse())
|
||||
})
|
||||
|
||||
It("returns true if log level is equal to provided level", func() {
|
||||
SetLevel(LevelWarn)
|
||||
Expect(IsGreaterOrEqualTo(LevelWarn)).To(BeTrue())
|
||||
})
|
||||
|
||||
It("returns true if log level is above provided level", func() {
|
||||
SetLevel(LevelTrace)
|
||||
Expect(IsGreaterOrEqualTo(LevelDebug)).To(BeTrue())
|
||||
})
|
||||
|
||||
It("returns true if log level for the current code path is equal provided level", func() {
|
||||
SetLevel(LevelError)
|
||||
SetLogLevels(map[string]string{
|
||||
"log/log_test": "debug",
|
||||
})
|
||||
|
||||
// Need to nest it in a function to get the correct code path
|
||||
var result = func() bool {
|
||||
return IsGreaterOrEqualTo(LevelDebug)
|
||||
}()
|
||||
|
||||
Expect(result).To(BeTrue())
|
||||
})
|
||||
})
|
||||
|
||||
Describe("extractLogger", func() {
|
||||
It("returns an error if the context is nil", func() {
|
||||
_, err := extractLogger(nil)
|
||||
Expect(err).ToNot(BeNil())
|
||||
})
|
||||
|
||||
It("returns an error if the context is a string", func() {
|
||||
_, err := extractLogger("any msg")
|
||||
Expect(err).ToNot(BeNil())
|
||||
})
|
||||
|
||||
It("returns the logger from context if it has one", func() {
|
||||
logger := logrus.NewEntry(logrus.New())
|
||||
ctx := context.Background()
|
||||
ctx = context.WithValue(ctx, loggerCtxKey, logger)
|
||||
|
||||
Expect(extractLogger(ctx)).To(Equal(logger))
|
||||
})
|
||||
|
||||
It("returns the logger from request's context if it has one", func() {
|
||||
logger := logrus.NewEntry(logrus.New())
|
||||
ctx := context.Background()
|
||||
ctx = context.WithValue(ctx, loggerCtxKey, logger)
|
||||
req := httptest.NewRequest("get", "/", nil).WithContext(ctx)
|
||||
|
||||
Expect(extractLogger(req)).To(Equal(logger))
|
||||
})
|
||||
})
|
||||
|
||||
Describe("SetLevelString", func() {
|
||||
It("converts Fatal level", func() {
|
||||
SetLevelString("Fatal")
|
||||
Expect(CurrentLevel()).To(Equal(LevelFatal))
|
||||
})
|
||||
It("converts Error level", func() {
|
||||
SetLevelString("ERROR")
|
||||
Expect(CurrentLevel()).To(Equal(LevelError))
|
||||
})
|
||||
It("converts Warn level", func() {
|
||||
SetLevelString("warn")
|
||||
Expect(CurrentLevel()).To(Equal(LevelWarn))
|
||||
})
|
||||
It("converts Info level", func() {
|
||||
SetLevelString("info")
|
||||
Expect(CurrentLevel()).To(Equal(LevelInfo))
|
||||
})
|
||||
It("converts Debug level", func() {
|
||||
SetLevelString("debug")
|
||||
Expect(CurrentLevel()).To(Equal(LevelDebug))
|
||||
})
|
||||
It("converts Trace level", func() {
|
||||
SetLevelString("trace")
|
||||
Expect(CurrentLevel()).To(Equal(LevelTrace))
|
||||
})
|
||||
})
|
||||
|
||||
Describe("Redact", func() {
|
||||
Describe("Subsonic API password", func() {
|
||||
msg := "getLyrics.view?v=1.2.0&c=iSub&u=user_name&p=first%20and%20other%20words&title=Title"
|
||||
Expect(Redact(msg)).To(Equal("getLyrics.view?v=1.2.0&c=iSub&u=user_name&p=[REDACTED]&title=Title"))
|
||||
})
|
||||
})
|
||||
})
|
||||
88
log/redactrus.go
Executable file
88
log/redactrus.go
Executable file
@@ -0,0 +1,88 @@
|
||||
package log
|
||||
|
||||
// Copied from https://github.com/whuang8/redactrus (MIT License)
|
||||
// Copyright (c) 2018 William Huang
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"reflect"
|
||||
"regexp"
|
||||
|
||||
"github.com/sirupsen/logrus"
|
||||
)
|
||||
|
||||
// Hook is a logrus hook for redacting information from logs
|
||||
type Hook struct {
|
||||
// Messages with a log level not contained in this array
|
||||
// will not be dispatched. If empty, all messages will be dispatched.
|
||||
AcceptedLevels []logrus.Level
|
||||
RedactionList []string
|
||||
redactionKeys []*regexp.Regexp
|
||||
}
|
||||
|
||||
// Levels returns the user defined AcceptedLevels
|
||||
// If AcceptedLevels is empty, all logrus levels are returned
|
||||
func (h *Hook) Levels() []logrus.Level {
|
||||
if len(h.AcceptedLevels) == 0 {
|
||||
return logrus.AllLevels
|
||||
}
|
||||
return h.AcceptedLevels
|
||||
}
|
||||
|
||||
// Fire redacts values in a log Entry that match
|
||||
// with keys defined in the RedactionList
|
||||
func (h *Hook) Fire(e *logrus.Entry) error {
|
||||
if err := h.initRedaction(); err != nil {
|
||||
return err
|
||||
}
|
||||
for _, re := range h.redactionKeys {
|
||||
// Redact based on key matching in Data fields
|
||||
for k, v := range e.Data {
|
||||
if re.MatchString(k) {
|
||||
e.Data[k] = "[REDACTED]"
|
||||
continue
|
||||
}
|
||||
if v == nil {
|
||||
continue
|
||||
}
|
||||
switch reflect.TypeOf(v).Kind() {
|
||||
case reflect.String:
|
||||
e.Data[k] = re.ReplaceAllString(v.(string), "$1[REDACTED]$2")
|
||||
continue
|
||||
case reflect.Map:
|
||||
s := fmt.Sprintf("%+v", v)
|
||||
e.Data[k] = re.ReplaceAllString(s, "$1[REDACTED]$2")
|
||||
continue
|
||||
}
|
||||
}
|
||||
|
||||
// Redact based on text matching in the Message field
|
||||
e.Message = re.ReplaceAllString(e.Message, "$1[REDACTED]$2")
|
||||
}
|
||||
|
||||
return nil
|
||||
}
|
||||
|
||||
func (h *Hook) initRedaction() error {
|
||||
if len(h.redactionKeys) == 0 {
|
||||
for _, redactionKey := range h.RedactionList {
|
||||
re, err := regexp.Compile(redactionKey)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
h.redactionKeys = append(h.redactionKeys, re)
|
||||
}
|
||||
}
|
||||
return nil
|
||||
}
|
||||
|
||||
func (h *Hook) redact(msg string) (string, error) {
|
||||
if err := h.initRedaction(); err != nil {
|
||||
return msg, err
|
||||
}
|
||||
for _, re := range h.redactionKeys {
|
||||
msg = re.ReplaceAllString(msg, "$1[REDACTED]$2")
|
||||
}
|
||||
|
||||
return msg, nil
|
||||
}
|
||||
159
log/redactrus_test.go
Executable file
159
log/redactrus_test.go
Executable file
@@ -0,0 +1,159 @@
|
||||
package log
|
||||
|
||||
import (
|
||||
"testing"
|
||||
|
||||
"github.com/sirupsen/logrus"
|
||||
"github.com/stretchr/testify/assert"
|
||||
)
|
||||
|
||||
var h = &Hook{}
|
||||
|
||||
type levelsTest struct {
|
||||
name string
|
||||
acceptedLevels []logrus.Level
|
||||
expected []logrus.Level
|
||||
description string
|
||||
}
|
||||
|
||||
func TestLevels(t *testing.T) {
|
||||
tests := []levelsTest{
|
||||
{
|
||||
name: "undefinedAcceptedLevels",
|
||||
acceptedLevels: []logrus.Level{},
|
||||
expected: logrus.AllLevels,
|
||||
description: "All logrus levels expected, but did not receive them",
|
||||
},
|
||||
{
|
||||
name: "definedAcceptedLevels",
|
||||
acceptedLevels: []logrus.Level{logrus.InfoLevel},
|
||||
expected: []logrus.Level{logrus.InfoLevel},
|
||||
description: "Logrus Info level expected, but did not receive that.",
|
||||
},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
fn := func(t *testing.T) {
|
||||
h.AcceptedLevels = test.acceptedLevels
|
||||
levels := h.Levels()
|
||||
assert.Equal(t, test.expected, levels, test.description)
|
||||
}
|
||||
|
||||
t.Run(test.name, fn)
|
||||
}
|
||||
}
|
||||
|
||||
type levelThresholdTest struct {
|
||||
name string
|
||||
level logrus.Level
|
||||
expected []logrus.Level
|
||||
description string
|
||||
}
|
||||
|
||||
// levelThreshold returns a []logrus.Level including all levels
|
||||
// above and including the level given. If the provided level does not exit,
|
||||
// an empty slice is returned.
|
||||
func levelThreshold(l logrus.Level) []logrus.Level {
|
||||
//nolint
|
||||
if l < 0 || int(l) > len(logrus.AllLevels) {
|
||||
return []logrus.Level{}
|
||||
}
|
||||
return logrus.AllLevels[:l+1]
|
||||
}
|
||||
|
||||
func TestLevelThreshold(t *testing.T) {
|
||||
tests := []levelThresholdTest{
|
||||
{
|
||||
name: "unknownLogLevel",
|
||||
level: logrus.Level(100),
|
||||
expected: []logrus.Level{},
|
||||
description: "An empty Level slice was expected but was not returned",
|
||||
},
|
||||
{
|
||||
name: "errorLogLevel",
|
||||
level: logrus.ErrorLevel,
|
||||
expected: []logrus.Level{logrus.PanicLevel, logrus.FatalLevel, logrus.ErrorLevel},
|
||||
description: "The panic, fatal, and error levels were expected but were not returned",
|
||||
},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
fn := func(t *testing.T) {
|
||||
levels := levelThreshold(test.level)
|
||||
assert.Equal(t, test.expected, levels, test.description)
|
||||
}
|
||||
|
||||
t.Run(test.name, fn)
|
||||
}
|
||||
}
|
||||
|
||||
func TestInvalidRegex(t *testing.T) {
|
||||
e := &logrus.Entry{}
|
||||
h = &Hook{RedactionList: []string{"\\"}}
|
||||
err := h.Fire(e)
|
||||
|
||||
assert.NotNil(t, err)
|
||||
}
|
||||
|
||||
type EntryDataValuesTest struct {
|
||||
name string
|
||||
redactionList []string
|
||||
logFields logrus.Fields
|
||||
expected logrus.Fields
|
||||
description string //nolint
|
||||
}
|
||||
|
||||
// Test that any occurrence of a redaction pattern
|
||||
// in the values of the entry's data fields is redacted.
|
||||
func TestEntryDataValues(t *testing.T) {
|
||||
tests := []EntryDataValuesTest{
|
||||
{
|
||||
name: "match on key",
|
||||
redactionList: []string{"Password"},
|
||||
logFields: logrus.Fields{"Password": "password123!"},
|
||||
expected: logrus.Fields{"Password": "[REDACTED]"},
|
||||
description: "Password value should have been redacted, but was not.",
|
||||
},
|
||||
{
|
||||
name: "string value",
|
||||
redactionList: []string{"William"},
|
||||
logFields: logrus.Fields{"Description": "His name is William"},
|
||||
expected: logrus.Fields{"Description": "His name is [REDACTED]"},
|
||||
description: "William should have been redacted, but was not.",
|
||||
},
|
||||
{
|
||||
name: "map value",
|
||||
redactionList: []string{"William"},
|
||||
logFields: logrus.Fields{"Description": map[string]string{"name": "His name is William"}},
|
||||
expected: logrus.Fields{"Description": "map[name:His name is [REDACTED]]"},
|
||||
description: "William should have been redacted, but was not.",
|
||||
},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
fn := func(t *testing.T) {
|
||||
logEntry := &logrus.Entry{
|
||||
Data: test.logFields,
|
||||
}
|
||||
h = &Hook{RedactionList: test.redactionList}
|
||||
err := h.Fire(logEntry)
|
||||
|
||||
assert.Nil(t, err)
|
||||
assert.Equal(t, test.expected, logEntry.Data)
|
||||
}
|
||||
t.Run(test.name, fn)
|
||||
}
|
||||
}
|
||||
|
||||
// Test that any occurrence of a redaction pattern
|
||||
// in the entry's Message field is redacted.
|
||||
func TestEntryMessage(t *testing.T) {
|
||||
logEntry := &logrus.Entry{
|
||||
Message: "Secret Password: password123!",
|
||||
}
|
||||
h = &Hook{RedactionList: []string{`(Password: ).*`}}
|
||||
err := h.Fire(logEntry)
|
||||
|
||||
assert.Nil(t, err)
|
||||
assert.Equal(t, "Secret Password: [REDACTED]", logEntry.Message)
|
||||
}
|
||||
Reference in New Issue
Block a user