mirror of
https://github.com/navidrome/navidrome.git
synced 2026-10-26 02:07:18 +01:00
* feat(auth): add per-user token_epoch column and bump method * feat(auth): add aud and ep claims, omitted when zero * feat(auth): add CreateAPIToken for non-expiring, audience-scoped tokens * feat(auth): add CheckClaims for epoch and audience validation * feat(jellyfin): issue non-expiring, jellyfin-scoped access tokens * fix(subsonic): reject API-scoped and revoked tokens on the jwt path * fix(server): reject API-scoped and revoked tokens on the native API * fix(server): pin the token-subject guard and stop leaking test config Adds a regression spec for the DevAutoLogin/ExtAuth guard in tokenAllowed, switches its comparison to case-insensitive to match the user lookup's own COLLATE NOCASE semantics, and restores Subsonic JWT test config after each spec instead of leaking SessionTimeout. * feat(request): add a token epoch holder for handler-to-middleware signalling * refactor(server): write the refreshed JWT header after the handler runs * feat(auth): revoke all tokens for a user when their password changes * fix(server): restore Unwrap on the JWT refresh writer so SSE write deadlines apply * test(auth): pin that non-session tokens reject API access tokens * test(jellyfin): pin token scoping and epoch revocation end to end Exercises auth.CreateAPIToken and CheckClaims against the real Jellyfin router and SQLite DB: the minted token has no exp and is aud-scoped to jellyfin, and bumping token_epoch through the real UserRepository revokes an already-issued token on the next protected request. * test(nativeapi): pin the token-epoch handoff through a real password-change request Drive a self password change through the real Authenticator/JWTRefresher chain and a real SQLite-backed userRepository, so the epoch handoff between Put and the refreshed-token writer is verified end to end, not as two separately-tested halves. Also fix tokenAllowed to read the enriched ctx it was given instead of r.Context(), so its warning log carries the username. * refactor(server): drop tokenAllowed's now-unused request parameter Finding-2 already moved every use to ctx; r was dead weight. Also note in the new nativeapi test why it must stay the package's only real-DB spec: db.Db() is a process-wide singleton its cleanup closes for good. * refactor(auth): remove duplication in claim decoding and token minting * refactor(auth): group aud with the standard JWT claims * refactor(auth): read aud with the standard-claim accessor pattern * fix(log): redact every api_key spelling the Jellyfin API accepts * fix(auth): bind session tokens to the user id, not just the username * fix(auth): return the token epoch from the same atomic increment * fix(auth): bump the token epoch in the same statement as the password write * chore(auth): trim comments to the why-only budget
371 lines
8 KiB
Go
371 lines
8 KiB
Go
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 any, msg any, keyValuePairs ...any)
|
|
|
|
var redacted = &Hook{
|
|
AcceptedLevels: logrus.AllLevels,
|
|
RedactionList: []string{
|
|
// Keys from the config
|
|
"(ApiKey:\")[\\w]*",
|
|
"(Secret:\")[\\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. Values can be JWTs (dots, dashes), so match everything up
|
|
// to the next query separator or whitespace, not just word chars. A [\w]+ class would stop
|
|
// at a JWT's first '.' and leak its payload and signature. Case-insensitive with an
|
|
// optional underscore: the API accepts api_key, apikey and ApiKey alike.
|
|
"(?i)([^\\w]api_?key=)[^&\\s]+",
|
|
},
|
|
}
|
|
|
|
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 := ParseLogLevel(l)
|
|
SetLevel(level)
|
|
}
|
|
|
|
func ParseLogLevel(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: ParseLogLevel(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)
|
|
}
|
|
|
|
// EnableJournalFormat wraps the current logger formatter with syslog
|
|
// priority prefixes for systemd-journald. Only call this when output
|
|
// goes to stderr and JOURNAL_STREAM is set.
|
|
func EnableJournalFormat() {
|
|
loggerMu.Lock()
|
|
defer loggerMu.Unlock()
|
|
defaultLogger.Formatter = &journalFormatter{inner: defaultLogger.Formatter}
|
|
}
|
|
|
|
// Redact applies redaction to a single string
|
|
func Redact(msg string) string {
|
|
r, _ := redacted.redact(msg)
|
|
return r
|
|
}
|
|
|
|
func NewContext(ctx context.Context, keyValuePairs ...any) 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
|
|
}
|
|
|
|
// SetDefaultLogger swaps the process-wide logger and returns the previous one,
|
|
// so tests can restore the original (with its hooks and formatter) on cleanup.
|
|
func SetDefaultLogger(l *logrus.Logger) *logrus.Logger {
|
|
loggerMu.Lock()
|
|
defer loggerMu.Unlock()
|
|
prev := defaultLogger
|
|
defaultLogger = l
|
|
return prev
|
|
}
|
|
|
|
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 ...any) {
|
|
log(LevelFatal, args...)
|
|
os.Exit(1)
|
|
}
|
|
|
|
func Error(args ...any) {
|
|
log(LevelError, args...)
|
|
}
|
|
|
|
func Warn(args ...any) {
|
|
log(LevelWarn, args...)
|
|
}
|
|
|
|
func Info(args ...any) {
|
|
log(LevelInfo, args...)
|
|
}
|
|
|
|
func Debug(args ...any) {
|
|
log(LevelDebug, args...)
|
|
}
|
|
|
|
func Trace(args ...any) {
|
|
log(LevelTrace, args...)
|
|
}
|
|
|
|
func Log(level Level, args ...any) {
|
|
log(level, args...)
|
|
}
|
|
|
|
func log(level Level, args ...any) {
|
|
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 []any) (*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 []any) *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 any) (*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")
|
|
}
|