package logger import ( "bytes" "errors" "log/slog" "strings" "testing" "time" "github.com/imgproxy/imgproxy/v3/testutil" "github.com/stretchr/testify/suite" ) type FormatterPrettyTestSuite struct { testutil.LazySuite buf testutil.LazyObj[*bytes.Buffer] config testutil.LazyObj[*Config] handler testutil.LazyObj[*Handler] logger testutil.LazyObj[*slog.Logger] } func (s *FormatterPrettyTestSuite) SetupTest() { s.buf, _ = testutil.NewLazySuiteObj( s, func() (*bytes.Buffer, error) { return new(bytes.Buffer), nil }, ) s.config, _ = testutil.NewLazySuiteObj( s, func() (*Config, error) { cfg := NewDefaultConfig() cfg.Format = FormatPretty return &cfg, nil }, ) s.handler, _ = testutil.NewLazySuiteObj( s, func() (*Handler, error) { return NewHandler(s.buf(), s.config()), nil }, ) s.logger, _ = testutil.NewLazySuiteObj( s, func() (*slog.Logger, error) { return slog.New(s.handler()), nil }, ) } func (s *FormatterPrettyTestSuite) SetupSubTest() { s.ResetLazyObjects() } func (s *FormatterPrettyTestSuite) removeColorCodes() { p := s.buf().Bytes() q := p[:0] inEscape := false for i := 0; i < len(p); i++ { switch { case p[i] == '\x1b': // Skip ANSI escape codes inEscape = true case inEscape && p[i] == 'm': inEscape = false case !inEscape: q = append(q, p[i]) } } s.buf().Truncate(len(q)) } func (s *FormatterPrettyTestSuite) checkNextEntry(lvl, msg string) { // Remove color codes from the log entry, // we're not going to test coloring s.removeColorCodes() // Pretty level names are always 3 characters long s.Require().Len(lvl, 3) str, err := s.buf().ReadString('\n') s.Require().NoError(err) const timeLen = 19 const lvlLen = 3 + 4 // +4 for the space and brackets const prefixLen = timeLen + lvlLen s.Require().GreaterOrEqual(len(str), prefixLen) timePart := str[:timeLen] levelPart := str[timeLen:prefixLen] now := time.Now() t, err := time.ParseInLocation(time.DateTime, timePart, now.Location()) s.Require().NoError(err) s.Require().WithinDuration(time.Now(), t, time.Minute) s.Equal(" ["+lvl+"] ", levelPart) // Check the message s.Equal(msg+"\n", str[prefixLen:]) } func (s *FormatterPrettyTestSuite) TestLevel() { type testEntry struct { level slog.Level levelName string message string } testEntries := []testEntry{ {level: slog.LevelDebug, levelName: "DBG", message: "Debug message"}, {level: slog.LevelInfo, levelName: "INF", message: "Info message"}, {level: slog.LevelWarn, levelName: "WRN", message: "Warning message"}, {level: slog.LevelError, levelName: "ERR", message: "Error message"}, {level: LevelCritical, levelName: "CRT", message: "Critical message"}, } testCases := []struct { level slog.Level entries []testEntry }{ {level: slog.LevelDebug, entries: testEntries}, {level: slog.LevelInfo, entries: testEntries[1:]}, {level: slog.LevelWarn, entries: testEntries[2:]}, {level: slog.LevelError, entries: testEntries[3:]}, {level: LevelCritical, entries: testEntries[4:]}, } for _, tc := range testCases { s.Run(tc.level.String(), func() { s.config().Level = tc.level for _, entry := range testEntries { s.logger().Log(s.T().Context(), entry.level, entry.message) } for _, entry := range tc.entries { s.checkNextEntry(entry.levelName, entry.message) } }) } } func (s *FormatterPrettyTestSuite) TestAttributes() { s.logger().Info( "Test message", slog.String("string", "value"), slog.Int("int", -100), slog.Uint64("uint64", 200), slog.Float64("float64", 3.14), slog.Bool("bool", true), slog.Time("time", time.Date(1984, 1, 2, 3, 4, 5, 6, time.UTC)), slog.Duration("duration", time.Minute), slog.Any("err", errors.New("error value")), slog.Any("any", struct { Field1 string Field2 int }{"value", 42}), ) s.checkNextEntry( "INF", strings.Join([]string{ "Test message", "string=value", "int=-100", "uint64=200", "float64=3.14", "bool=true", `time="1984-01-02 03:04:05"`, "duration=1m0s", `err="error value"`, `any="{Field1:value Field2:42}"`, }, " "), ) } func (s *FormatterPrettyTestSuite) TestGroups() { s.Run("LastGroupNotEmpty", func() { s.logger(). With( slog.String("string", "value"), slog.Int("int", -100), ). WithGroup("group1"). With( slog.Uint64("uint64", 200), slog.Float64("float64", 3.14), ). WithGroup("group2"). With(slog.Group("group3", slog.Bool("bool", true), slog.Time("time", time.Date(1984, 1, 2, 3, 4, 5, 6, time.UTC)), )). With(slog.Group("empty_group")). WithGroup("group4"). Info( "Test message", slog.Duration("duration", time.Minute), slog.Any("any", struct { Field1 string Field2 int }{"value", 42}), ) s.checkNextEntry( "INF", strings.Join([]string{ "Test message", "string=value", "int=-100", "group1={", "uint64=200", "float64=3.14", "group2={", "group3={", "bool=true", `time="1984-01-02 03:04:05"`, "}", "group4={", "duration=1m0s", `any="{Field1:value Field2:42}"`, "}", "}", "}", }, " "), ) }) s.Run("LastGroupsEmpty", func() { s.logger(). With( slog.String("string", "value"), slog.Int("int", -100), ). WithGroup("group1"). With( slog.Uint64("uint64", 200), slog.Float64("float64", 3.14), ). WithGroup("group2"). With(slog.Group("group3", slog.Bool("bool", true), slog.Time("time", time.Date(1984, 1, 2, 3, 4, 5, 6, time.UTC)), )). With(slog.Group("empty_group")). WithGroup("group4"). WithGroup("group5"). Info("Test message") s.checkNextEntry( "INF", strings.Join([]string{ "Test message", "string=value", "int=-100", "group1={", "uint64=200", "float64=3.14", "group2={", "group3={", "bool=true", `time="1984-01-02 03:04:05"`, "}", "}", "}", }, " "), ) }) } func (s *FormatterPrettyTestSuite) TestQuoting() { s.logger().Info( "Test message", "key", "value", "key with spaces", "value with spaces", `key"with"quotes`, `value"with"quotes`, "key\nwith\nnewlines", "value\nwith\nnewlines", slog.Group("group name", slog.String("key", "value")), ) s.checkNextEntry( "INF", strings.Join([]string{ "Test message", "key=value", `"key with spaces"="value with spaces"`, `"key\"with\"quotes"="value\"with\"quotes"`, `"key\nwith\nnewlines"="value\nwith\nnewlines"`, `"group name"={ key=value }`, }, " "), ) } func (s *FormatterPrettyTestSuite) TestSpecialFields() { s.logger().Info( "Test message", "stack", "stack value\nwith new lines", "key1", "value1", "error", errors.New("error value"), "key2", "value2", "source", "source value", "key3", "value3", slog.Group( "group", "stack", "stack in group", "error", "error in group", "source", "source in group", ), ) s.checkNextEntry( "INF", strings.Join([]string{ "Test message", "key1=value1", "key2=value2", "key3=value3", "group={", `stack="stack in group"`, `error="error in group"`, `source="source in group"`, "}", `error="error value"`, `source="source value"`, }, " "), ) s.removeColorCodes() s.Require().Equal("stack value\nwith new lines\n", s.buf().String()) } func TestFormatterPretty(t *testing.T) { suite.Run(t, new(FormatterPrettyTestSuite)) }