diff --git a/go.mod b/go.mod index dbe7a0dd..33481eb2 100644 --- a/go.mod +++ b/go.mod @@ -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 diff --git a/logger/logger.go b/logger/logger.go index 029301ca..af4b0e84 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -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...) -} - -// Tracef logs a message at level Trace. -func (l *logrusLogger) Tracef(format string, args ...any) { - l.logf(logrus.TraceLevel, format, args...) -} - -// Debug logs a message at level Debug. -func (l *logrusLogger) Debug(args ...any) { - l.log(logrus.DebugLevel, args...) -} - -// Debugf logs a message at level Debug. -func (l *logrusLogger) Debugf(format string, args ...any) { - l.logf(logrus.DebugLevel, format, args...) -} - -// Info logs a message at level Info. -func (l *logrusLogger) Info(args ...any) { - l.log(logrus.InfoLevel, args...) -} - -// Infof logs a message at level Info. -func (l *logrusLogger) Infof(format string, args ...any) { - l.logf(logrus.InfoLevel, format, args...) -} - -// Warn logs a message at level Warn. -func (l *logrusLogger) Warn(args ...any) { - l.log(logrus.WarnLevel, args...) -} - -// Warnf logs a message at level Warn. -func (l *logrusLogger) Warnf(format string, args ...any) { - l.logf(logrus.WarnLevel, format, args...) -} - -// Error logs a message at level Error. -func (l *logrusLogger) Error(args ...any) { - l.log(logrus.ErrorLevel, args...) -} - -// Errorf logs a message at level Error. -func (l *logrusLogger) Errorf(format string, args ...any) { - l.logf(logrus.ErrorLevel, 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) -} - -// 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) -} - -func (l *logrusLogger) GetLevel() logger.LogLevel { - return logger.LogLevel(l.logger.Logger.GetLevel().String()) -} - -func (l *logrusLogger) IsLevelEnabled(level logger.LogLevel) bool { - lvl, _ := logrus.ParseLevel(string(level)) - return l.logger.Logger.IsLevelEnabled(lvl) -} - -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)) +// 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, } - lg.Log(level, 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)) + switch format { + case logger.TextFormat: + return slog.NewTextHandler(w, ho) + default: + return slog.NewJSONHandler(w, ho) } - lg.Logf(level, format, args...) } -func (l *logrusLogger) caller(skip int) string { +// 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 +} + +// 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" + } +} + +// 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 + } +} + +// 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 + } +} + +// 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, + } +} + +// Trace logs at Trace level. +func (l *slogLogger) Trace(args ...any) { + l.log(levelTrace, args...) +} + +// Tracef logs a formatted message at Trace level. +func (l *slogLogger) Tracef(format string, args ...any) { + l.logf(levelTrace, format, args...) +} + +// Debug logs at Debug level. +func (l *slogLogger) Debug(args ...any) { + l.log(slog.LevelDebug, args...) +} + +// Debugf logs a formatted message at Debug level. +func (l *slogLogger) Debugf(format string, args ...any) { + l.logf(slog.LevelDebug, format, args...) +} + +// Info logs at Info level. +func (l *slogLogger) Info(args ...any) { + l.log(slog.LevelInfo, args...) +} + +// Infof logs a formatted message at Info level. +func (l *slogLogger) Infof(format string, args ...any) { + l.logf(slog.LevelInfo, format, args...) +} + +// Warn logs at Warn level. +func (l *slogLogger) Warn(args ...any) { + l.log(slog.LevelWarn, args...) +} + +// Warnf logs a formatted message at Warn level. +func (l *slogLogger) Warnf(format string, args ...any) { + l.logf(slog.LevelWarn, format, args...) +} + +// Error logs at Error level. +func (l *slogLogger) Error(args ...any) { + l.log(slog.LevelError, args...) +} + +// Errorf logs a formatted message at Error level. +func (l *slogLogger) Errorf(format string, args ...any) { + l.logf(slog.LevelError, format, args...) +} + +// 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 = "" diff --git a/logger/logger_test.go b/logger/logger_test.go new file mode 100644 index 00000000..4b763817 --- /dev/null +++ b/logger/logger_test.go @@ -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) + } +}