refactor(logger): replace logrus with stdlib log/slog

Drop the external github.com/sirupsen/logrus dependency in favor of Go's standard log/slog package (available since Go 1.21). The core/logger.Logger interface is preserved unchanged — this is a pure implementation swap. Key changes: - slogLogger replaces logrusLogger, backed by slog.Logger + slog.LevelVar - Custom levelTrace (-8) and levelFatal (+12) constants extend slog's built-in 4 levels to cover the 6-level logrus-compatible range - replaceAttr normalises output: lowercase level names and RFC 3339 timestamps with milliseconds (matches previous logrus JSON format) - Shared *slog.LevelVar ensures WithFields clones inherit parent level - Level guard (early return) in log/logf avoids wasted fmt.Sprint/Sprintf when the message level is below the configured threshold - Documented the stack depth assumption for the caller skip=3 frame Test coverage (14 tests, all passing with -race): - convertLevel/revertLevel round-trip for all 6 levels - levelString for all levels including custom trace/fatal - replaceAttr timestamp format, level name, groups passthrough - caller format, level guard, WithFields, IsLevelEnabled, GetLevel
2026-06-17 21:51:06 +08:00
parent ca582a147f
commit 219dd51548
3 changed files with 451 additions and 126 deletions
@@ -30,7 +30,6 @@ require (
 	github.com/quic-go/webtransport-go v0.10.0
 	github.com/rs/xid v1.3.0
 	github.com/shadowsocks/go-shadowsocks2 v0.1.5
-	github.com/sirupsen/logrus v1.9.3
 	github.com/songgao/water v0.0.0-20200317203138-2b4b6d7c09d8
 	github.com/spf13/viper v1.19.0
 	github.com/stretchr/testify v1.11.1
@@ -57,6 +56,8 @@ require (
 	gvisor.dev/gvisor v0.0.0-20250523182742-eede7a881b20
 )

+require github.com/sirupsen/logrus v1.9.3 // indirect
+
 require (
 	github.com/alessio/shellescape v1.4.1 // indirect
 	github.com/beorn7/perks v1.0.1 // indirect
@@ -1,15 +1,26 @@
 package logger

 import (
+	"context"
 	"fmt"
 	"io"
+	"log/slog"
+	"os"
 	"path/filepath"
 	"runtime"
+	"time"

 	"github.com/go-gost/core/logger"
-	"github.com/sirupsen/logrus"
 )

+// Custom slog levels to cover the full logrus-compatible range.
+// slog built-in: Debug=-4, Info=0, Warn=4, Error=8.
+const (
+	levelTrace slog.Level = -8
+	levelFatal slog.Level = 12
+)
+
+// Options holds the configuration for a logger.
 type Options struct {
 	Name   string
 	Output io.Writer
@@ -17,178 +28,289 @@ type Options struct {
 	Level  logger.LogLevel
 }

+// Option is a functional option for configuring a logger.
 type Option func(opts *Options)

+// NameOption sets the logger name. When set, every log entry carries a
+// "logger" field with this value.
 func NameOption(name string) Option {
 	return func(opts *Options) {
 		opts.Name = name
 	}
 }

+// OutputOption sets the output destination. Defaults to os.Stderr.
 func OutputOption(out io.Writer) Option {
 	return func(opts *Options) {
 		opts.Output = out
 	}
 }

+// FormatOption sets the log format (TextFormat or JSONFormat). Defaults to JSON.
 func FormatOption(format logger.LogFormat) Option {
 	return func(opts *Options) {
 		opts.Format = format
 	}
 }

+// LevelOption sets the minimum log level. Defaults to InfoLevel.
 func LevelOption(level logger.LogLevel) Option {
 	return func(opts *Options) {
 		opts.Level = level
 	}
 }

-type logrusLogger struct {
-	logger *logrus.Entry
+// slogLogger implements logger.Logger backed by log/slog.
+type slogLogger struct {
+	logger *slog.Logger
+	level  *slog.LevelVar
 }

+// NewLogger creates a new logger.Logger backed by log/slog.
+// The returned logger implements the core/logger.Logger interface.
 func NewLogger(opts ...Option) logger.Logger {
 	var options Options
 	for _, opt := range opts {
 		opt(&options)
 	}

-	log := logrus.New()
-	if options.Output != nil {
-		log.SetOutput(options.Output)
+	out := options.Output
+	if out == nil {
+		out = os.Stderr
 	}

-	switch options.Format {
-	case logger.TextFormat:
-		log.SetFormatter(&logrus.TextFormatter{
-			FullTimestamp: true,
-		})
-	default:
-		log.SetFormatter(&logrus.JSONFormatter{
-			DisableHTMLEscape: true,
-			// PrettyPrint:       true,
-			TimestampFormat: "2006-01-02T15:04:05.000Z07:00",
-		})
-	}
+	levelVar := new(slog.LevelVar)
+	levelVar.Set(convertLevel(options.Level))

-	switch options.Level {
-	case logger.TraceLevel,
-		logger.DebugLevel,
-		logger.InfoLevel,
-		logger.WarnLevel,
-		logger.ErrorLevel,
-		logger.FatalLevel:
-		lvl, _ := logrus.ParseLevel(string(options.Level))
-		log.SetLevel(lvl)
-	default:
-		log.SetLevel(logrus.InfoLevel)
-	}
+	handler := newHandler(out, levelVar, options.Format)

-	l := &logrusLogger{
-		logger: logrus.NewEntry(log),
-	}
+	sl := slog.New(handler)
 	if options.Name != "" {
-		l.logger = l.logger.WithField("logger", options.Name)
+		sl = sl.With("logger", options.Name)
 	}

-	return l
-}
-
-// WithFields adds new fields to log.
-func (l *logrusLogger) WithFields(fields map[string]any) logger.Logger {
-	return &logrusLogger{
-		logger: l.logger.WithFields(logrus.Fields(fields)),
+	return &slogLogger{
+		logger: sl,
+		level:  levelVar,
 	}
 }

-// Trace logs a message at level Trace.
-func (l *logrusLogger) Trace(args ...any) {
-	l.log(logrus.TraceLevel, args...)
+// newHandler creates the appropriate slog.Handler based on the format.
+func newHandler(w io.Writer, levelVar *slog.LevelVar, format logger.LogFormat) slog.Handler {
+	ho := &slog.HandlerOptions{
+		Level:       levelVar,
+		ReplaceAttr: replaceAttr,
+	}
+	switch format {
+	case logger.TextFormat:
+		return slog.NewTextHandler(w, ho)
+	default:
+		return slog.NewJSONHandler(w, ho)
+	}
 }

-// Tracef logs a message at level Trace.
-func (l *logrusLogger) Tracef(format string, args ...any) {
-	l.logf(logrus.TraceLevel, format, args...)
+// replaceAttr normalises slog output to match the logrus format:
+//   - level names are lowercased (info, debug, warn, error, fatal, trace)
+//   - timestamps use RFC 3339 with milliseconds and numeric timezone offset
+func replaceAttr(groups []string, a slog.Attr) slog.Attr {
+	if len(groups) > 0 {
+		return a
+	}
+	switch a.Key {
+	case slog.TimeKey:
+		if t, ok := a.Value.Any().(time.Time); ok {
+			a.Value = slog.StringValue(t.Format("2006-01-02T15:04:05.000Z07:00"))
+		}
+	case slog.LevelKey:
+		if level, ok := a.Value.Any().(slog.Level); ok {
+			a.Value = slog.StringValue(levelString(level))
+		}
+	}
+	return a
 }

-// Debug logs a message at level Debug.
-func (l *logrusLogger) Debug(args ...any) {
-	l.log(logrus.DebugLevel, args...)
+// levelString returns a logrus-style lowercase level name for the given slog level.
+func levelString(level slog.Level) string {
+	switch {
+	case level <= levelTrace:
+		return "trace"
+	case level <= slog.LevelDebug:
+		return "debug"
+	case level <= slog.LevelInfo:
+		return "info"
+	case level <= slog.LevelWarn:
+		return "warn"
+	case level <= slog.LevelError:
+		return "error"
+	default:
+		return "fatal"
+	}
 }

-// Debugf logs a message at level Debug.
-func (l *logrusLogger) Debugf(format string, args ...any) {
-	l.logf(logrus.DebugLevel, format, args...)
+// convertLevel maps a core logger.LogLevel to the corresponding slog.Level.
+func convertLevel(lvl logger.LogLevel) slog.Level {
+	switch lvl {
+	case logger.TraceLevel:
+		return levelTrace
+	case logger.DebugLevel:
+		return slog.LevelDebug
+	case logger.InfoLevel:
+		return slog.LevelInfo
+	case logger.WarnLevel:
+		return slog.LevelWarn
+	case logger.ErrorLevel:
+		return slog.LevelError
+	case logger.FatalLevel:
+		return levelFatal
+	default:
+		return slog.LevelInfo
+	}
 }

-// Info logs a message at level Info.
-func (l *logrusLogger) Info(args ...any) {
-	l.log(logrus.InfoLevel, args...)
+// revertLevel maps a slog.Level back to a core logger.LogLevel.
+func revertLevel(lvl slog.Level) logger.LogLevel {
+	switch {
+	case lvl <= levelTrace:
+		return logger.TraceLevel
+	case lvl <= slog.LevelDebug:
+		return logger.DebugLevel
+	case lvl <= slog.LevelInfo:
+		return logger.InfoLevel
+	case lvl <= slog.LevelWarn:
+		return logger.WarnLevel
+	case lvl <= slog.LevelError:
+		return logger.ErrorLevel
+	default:
+		return logger.FatalLevel
+	}
 }

-// Infof logs a message at level Info.
-func (l *logrusLogger) Infof(format string, args ...any) {
-	l.logf(logrus.InfoLevel, format, args...)
+// WithFields returns a new Logger with the given fields attached to every
+// subsequent log entry.
+func (l *slogLogger) WithFields(fields map[string]any) logger.Logger {
+	attrs := make([]any, 0, len(fields)*2)
+	for k, v := range fields {
+		attrs = append(attrs, k, v)
+	}
+	return &slogLogger{
+		logger: l.logger.With(attrs...),
+		level:  l.level,
+	}
 }

-// Warn logs a message at level Warn.
-func (l *logrusLogger) Warn(args ...any) {
-	l.log(logrus.WarnLevel, args...)
+// Trace logs at Trace level.
+func (l *slogLogger) Trace(args ...any) {
+	l.log(levelTrace, args...)
 }

-// Warnf logs a message at level Warn.
-func (l *logrusLogger) Warnf(format string, args ...any) {
-	l.logf(logrus.WarnLevel, format, args...)
+// Tracef logs a formatted message at Trace level.
+func (l *slogLogger) Tracef(format string, args ...any) {
+	l.logf(levelTrace, format, args...)
 }

-// Error logs a message at level Error.
-func (l *logrusLogger) Error(args ...any) {
-	l.log(logrus.ErrorLevel, args...)
+// Debug logs at Debug level.
+func (l *slogLogger) Debug(args ...any) {
+	l.log(slog.LevelDebug, args...)
 }

-// Errorf logs a message at level Error.
-func (l *logrusLogger) Errorf(format string, args ...any) {
-	l.logf(logrus.ErrorLevel, format, args...)
+// Debugf logs a formatted message at Debug level.
+func (l *slogLogger) Debugf(format string, args ...any) {
+	l.logf(slog.LevelDebug, format, args...)
 }

-// Fatal logs a message at level Fatal then the process will exit with status set to 1.
-func (l *logrusLogger) Fatal(args ...any) {
-	l.log(logrus.FatalLevel, args...)
-	l.logger.Logger.Exit(1)
+// Info logs at Info level.
+func (l *slogLogger) Info(args ...any) {
+	l.log(slog.LevelInfo, args...)
 }

-// Fatalf logs a message at level Fatal then the process will exit with status set to 1.
-func (l *logrusLogger) Fatalf(format string, args ...any) {
-	l.logf(logrus.FatalLevel, format, args...)
-	l.logger.Logger.Exit(1)
+// Infof logs a formatted message at Info level.
+func (l *slogLogger) Infof(format string, args ...any) {
+	l.logf(slog.LevelInfo, format, args...)
 }

-func (l *logrusLogger) GetLevel() logger.LogLevel {
-	return logger.LogLevel(l.logger.Logger.GetLevel().String())
+// Warn logs at Warn level.
+func (l *slogLogger) Warn(args ...any) {
+	l.log(slog.LevelWarn, args...)
 }

-func (l *logrusLogger) IsLevelEnabled(level logger.LogLevel) bool {
-	lvl, _ := logrus.ParseLevel(string(level))
-	return l.logger.Logger.IsLevelEnabled(lvl)
+// Warnf logs a formatted message at Warn level.
+func (l *slogLogger) Warnf(format string, args ...any) {
+	l.logf(slog.LevelWarn, format, args...)
 }

-func (l *logrusLogger) log(level logrus.Level, args ...any) {
-	lg := l.logger
-	if l.logger.Logger.IsLevelEnabled(logrus.DebugLevel) {
-		lg = lg.WithField("caller", l.caller(3))
-	}
-	lg.Log(level, args...)
+// Error logs at Error level.
+func (l *slogLogger) Error(args ...any) {
+	l.log(slog.LevelError, args...)
 }

-func (l *logrusLogger) logf(level logrus.Level, format string, args ...any) {
-	lg := l.logger
-	if l.logger.Logger.IsLevelEnabled(logrus.DebugLevel) {
-		lg = lg.WithField("caller", l.caller(3))
-	}
-	lg.Logf(level, format, args...)
+// Errorf logs a formatted message at Error level.
+func (l *slogLogger) Errorf(format string, args ...any) {
+	l.logf(slog.LevelError, format, args...)
 }

-func (l *logrusLogger) caller(skip int) string {
+// Fatal logs at Fatal level and then calls os.Exit(1).
+func (l *slogLogger) Fatal(args ...any) {
+	l.log(levelFatal, args...)
+	os.Exit(1)
+}
+
+// Fatalf logs a formatted message at Fatal level and then calls os.Exit(1).
+func (l *slogLogger) Fatalf(format string, args ...any) {
+	l.logf(levelFatal, format, args...)
+	os.Exit(1)
+}
+
+// GetLevel returns the current log level.
+func (l *slogLogger) GetLevel() logger.LogLevel {
+	return revertLevel(l.level.Level())
+}
+
+// IsLevelEnabled reports whether messages at the given level will be logged.
+func (l *slogLogger) IsLevelEnabled(level logger.LogLevel) bool {
+	return l.level.Level() <= convertLevel(level)
+}
+
+// log emits a log entry. When the configured level is Debug or lower it
+// attaches a "caller" field with the source file and line.
+//
+// Stack depth assumption for the skip=3 argument to caller:
+//
+//	0: runtime.Caller
+//	1: caller
+//	2: log (this method)
+//	3: level method (Trace, Debug, Info, etc.)
+//	4: user's call site
+func (l *slogLogger) log(level slog.Level, args ...any) {
+	if l.level.Level() > level {
+		return
+	}
+	msg := fmt.Sprint(args...)
+	if l.level.Level() <= slog.LevelDebug {
+		l.logger.LogAttrs(context.Background(), level, msg,
+			slog.String("caller", l.caller(3)))
+	} else {
+		l.logger.LogAttrs(context.Background(), level, msg)
+	}
+}
+
+// logf emits a formatted log entry. When the configured level is Debug or
+// lower it attaches a "caller" field with the source file and line.
+func (l *slogLogger) logf(level slog.Level, format string, args ...any) {
+	if l.level.Level() > level {
+		return
+	}
+	msg := fmt.Sprintf(format, args...)
+	if l.level.Level() <= slog.LevelDebug {
+		l.logger.LogAttrs(context.Background(), level, msg,
+			slog.String("caller", l.caller(3)))
+	} else {
+		l.logger.LogAttrs(context.Background(), level, msg)
+	}
+}
+
+// caller returns a "dir/file.go:line" description of the caller, skipping
+// the given number of stack frames.
+func (l *slogLogger) caller(skip int) string {
 	_, file, line, ok := runtime.Caller(skip)
 	if !ok {
 		file = "<???>"
@@ -0,0 +1,202 @@
+package logger
+
+import (
+	"bytes"
+	"log/slog"
+	"regexp"
+	"testing"
+	"time"
+
+	"github.com/go-gost/core/logger"
+)
+
+func TestConvertLevelRevertLevelRoundTrip(t *testing.T) {
+	levels := []logger.LogLevel{
+		logger.TraceLevel,
+		logger.DebugLevel,
+		logger.InfoLevel,
+		logger.WarnLevel,
+		logger.ErrorLevel,
+		logger.FatalLevel,
+	}
+
+	for _, lvl := range levels {
+		slogLvl := convertLevel(lvl)
+		back := revertLevel(slogLvl)
+		if back != lvl {
+			t.Errorf("round-trip failed for %q: got %q", lvl, back)
+		}
+	}
+}
+
+func TestConvertLevelDefault(t *testing.T) {
+	if got := convertLevel("unknown"); got != slog.LevelInfo {
+		t.Errorf("expected Info level for unknown input, got %v", got)
+	}
+}
+
+func TestRevertLevelMapping(t *testing.T) {
+	tests := []struct {
+		slogLevel slog.Level
+		want      logger.LogLevel
+	}{
+		{levelTrace, logger.TraceLevel},
+		{levelTrace + 1, logger.DebugLevel},
+		{slog.LevelDebug, logger.DebugLevel},
+		{slog.LevelDebug + 1, logger.InfoLevel},
+		{slog.LevelInfo, logger.InfoLevel},
+		{slog.LevelInfo + 1, logger.WarnLevel},
+		{slog.LevelWarn, logger.WarnLevel},
+		{slog.LevelWarn + 1, logger.ErrorLevel},
+		{slog.LevelError, logger.ErrorLevel},
+		{slog.LevelError + 1, logger.FatalLevel},
+		{levelFatal, logger.FatalLevel},
+	}
+
+	for _, tt := range tests {
+		got := revertLevel(tt.slogLevel)
+		if got != tt.want {
+			t.Errorf("revertLevel(%v) = %q, want %q", tt.slogLevel, got, tt.want)
+		}
+	}
+}
+
+func TestLevelString(t *testing.T) {
+	tests := []struct {
+		level slog.Level
+		want  string
+	}{
+		{levelTrace - 1, "trace"},
+		{levelTrace, "trace"},
+		{slog.LevelDebug, "debug"},
+		{slog.LevelInfo, "info"},
+		{slog.LevelWarn, "warn"},
+		{slog.LevelError, "error"},
+		{levelFatal, "fatal"},
+		{levelFatal + 1, "fatal"},
+	}
+
+	for _, tt := range tests {
+		got := levelString(tt.level)
+		if got != tt.want {
+			t.Errorf("levelString(%v) = %q, want %q", tt.level, got, tt.want)
+		}
+	}
+}
+
+func TestReplaceAttrTimestamp(t *testing.T) {
+	ts := time.Date(2026, 6, 17, 12, 0, 0, 123000000, time.FixedZone("+0800", 8*60*60))
+	attr := slog.Attr{Key: slog.TimeKey, Value: slog.TimeValue(ts)}
+
+	result := replaceAttr(nil, attr)
+	got := result.Value.String()
+
+	// Should be RFC 3339 with milliseconds and numeric timezone: "2026-06-17T12:00:00.123+08:00"
+	re := regexp.MustCompile(`^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}[+-]\d{2}:\d{2}$`)
+	if !re.MatchString(got) {
+		t.Errorf("timestamp format mismatch: got %q", got)
+	}
+}
+
+func TestReplaceAttrLevel(t *testing.T) {
+	attr := slog.Attr{Key: slog.LevelKey, Value: slog.AnyValue(slog.LevelDebug)}
+	result := replaceAttr(nil, attr)
+	if got := result.Value.String(); got != "debug" {
+		t.Errorf("expected level 'debug', got %q", got)
+	}
+}
+
+func TestReplaceAttrNonMatchingKey(t *testing.T) {
+	attr := slog.Attr{Key: "msg", Value: slog.StringValue("hello")}
+	result := replaceAttr(nil, attr)
+	if result.Value.String() != "hello" {
+		t.Errorf("expected unchanged value 'hello', got %q", result.Value.String())
+	}
+}
+
+func TestReplaceAttrWithGroups(t *testing.T) {
+	// When groups are present, replaceAttr should pass through unchanged.
+	attr := slog.Attr{Key: slog.LevelKey, Value: slog.AnyValue(slog.LevelWarn)}
+	result := replaceAttr([]string{"sub"}, attr)
+	if result.Value.Kind() != slog.KindAny {
+		t.Errorf("expected unchanged level value kind, got %v", result.Value.Kind())
+	}
+}
+
+func TestCallerFormat(t *testing.T) {
+	l := &slogLogger{logger: slog.Default(), level: new(slog.LevelVar)}
+	caller := l.caller(0)
+	// skip=0 resolves to the caller function's own location (logger.go), not
+	// the test file. Match the "dir/file.go:line" format.
+	re := regexp.MustCompile(`^\w+/[^/]+\.go:\d+$`)
+	if !re.MatchString(caller) {
+		t.Errorf("caller format mismatch: got %q", caller)
+	}
+}
+
+func TestLevelGuardSkipsFormatting(t *testing.T) {
+	// Log with a level below the configured threshold — should be a no-op.
+	var buf bytes.Buffer
+	l := NewLogger(
+		OutputOption(&buf),
+		LevelOption(logger.WarnLevel),
+		FormatOption(logger.TextFormat),
+	)
+	// Info is below Warn; message should not appear.
+	l.Info("should not appear")
+	if buf.Len() != 0 {
+		t.Errorf("expected empty output, got %q", buf.String())
+	}
+}
+
+func TestLevelGuardAllowsHigherLevel(t *testing.T) {
+	var buf bytes.Buffer
+	l := NewLogger(
+		OutputOption(&buf),
+		LevelOption(logger.WarnLevel),
+		FormatOption(logger.TextFormat),
+	)
+	// Error is above Warn; message should appear.
+	l.Error("should appear")
+	if buf.Len() == 0 {
+		t.Error("expected output, got none")
+	}
+}
+
+func TestWithFields(t *testing.T) {
+	var buf bytes.Buffer
+	l := NewLogger(
+		OutputOption(&buf),
+		LevelOption(logger.InfoLevel),
+		FormatOption(logger.TextFormat),
+	)
+	child := l.WithFields(map[string]any{"request_id": "abc123"})
+	child.Info("test message")
+	out := buf.String()
+	if out == "" {
+		t.Error("expected output, got none")
+	}
+	// Verify the child and parent share the same LevelVar.
+	parentLevel := l.GetLevel()
+	childLevel := child.GetLevel()
+	if parentLevel != childLevel {
+		t.Errorf("parent and child levels should match: %q vs %q", parentLevel, childLevel)
+	}
+}
+
+func TestIsLevelEnabled(t *testing.T) {
+	l := NewLogger(LevelOption(logger.InfoLevel))
+	if !l.IsLevelEnabled(logger.WarnLevel) {
+		t.Error("Warn should be enabled when level is Info")
+	}
+	if l.IsLevelEnabled(logger.TraceLevel) {
+		t.Error("Trace should be disabled when level is Info")
+	}
+}
+
+func TestGetLevel(t *testing.T) {
+	l := NewLogger(LevelOption(logger.ErrorLevel))
+	if got := l.GetLevel(); got != logger.ErrorLevel {
+		t.Errorf("expected ErrorLevel, got %q", got)
+	}
+}