package sneklog import ( "bytes" "encoding/json" "errors" "net/http" "os" "strings" "testing" ) type stubLoggerWriter struct { printErr error closeErr error printCalls int closeCalls int messages []any } func (w *stubLoggerWriter) Formatter() *Formatter { return &Formatter{} } func (w *stubLoggerWriter) Close() error { w.closeCalls++ return w.closeErr } func (w *stubLoggerWriter) Write(p []byte) (int, error) { return len(p), nil } func (w *stubLoggerWriter) Print(_ LogLevel, _ string, _ []*MethodTraceback, messages ...any) error { w.printCalls++ w.messages = append([]any(nil), messages...) return w.printErr } func TestLoggerCloseReturnsJoinedErrorsWithoutRelogging(t *testing.T) { firstErr := errors.New("first close failed") secondErr := errors.New("second close failed") first := &stubLoggerWriter{closeErr: firstErr} second := &stubLoggerWriter{closeErr: secondErr} logger := CreateLogger().AddWriters(first, second) err := logger.Close() if !errors.Is(err, firstErr) { t.Fatalf("Close() error should include first writer error, got %v", err) } if !errors.Is(err, secondErr) { t.Fatalf("Close() error should include second writer error, got %v", err) } if first.printCalls != 0 || second.printCalls != 0 { t.Fatalf("Close() should not log through writers again, got print calls first=%d second=%d", first.printCalls, second.printCalls) } if first.closeCalls != 1 || second.closeCalls != 1 { t.Fatalf("Close() should close each writer once, got close calls first=%d second=%d", first.closeCalls, second.closeCalls) } if err := logger.Close(); err != nil { t.Fatalf("second Close() should be a no-op, got %v", err) } } func TestLoggerPrintDoesNotRecurseOnWriterError(t *testing.T) { oldStderr := os.Stderr stderrFile, err := os.CreateTemp(t.TempDir(), "stderr") if err != nil { t.Fatalf("CreateTemp() error = %v", err) } os.Stderr = stderrFile t.Cleanup(func() { os.Stderr = oldStderr _ = stderrFile.Close() }) bad := &stubLoggerWriter{printErr: errors.New("print failed")} good := &stubLoggerWriter{} logger := CreateLogger().AddWriters(bad, good) logger.Error("boom") if bad.printCalls != 1 { t.Fatalf("bad writer should be called once, got %d", bad.printCalls) } if good.printCalls != 1 { t.Fatalf("good writer should be called once, got %d", good.printCalls) } } func TestLoggerPreservesMessageTypesWithoutReplacers(t *testing.T) { writer := &stubLoggerWriter{} logger := CreateLogger().AddWriter(writer) logger.Error("status", 500) if len(writer.messages) != 2 { t.Fatalf("writer should receive two messages, got %d", len(writer.messages)) } if _, ok := writer.messages[1].(int); !ok { t.Fatalf("writer should receive original int message type, got %T", writer.messages[1]) } } func TestLoggerPrintfFormatsMessage(t *testing.T) { writer := &stubLoggerWriter{} logger := CreateLogger(). SetLevel(DEBUG). AddWriter(writer) logger.Printf(INFO, "status=%d %s", 200, "ok") if writer.printCalls != 1 { t.Fatalf("Printf() should write once, got %d calls", writer.printCalls) } if len(writer.messages) != 1 { t.Fatalf("Printf() should produce one formatted message, got %d parts", len(writer.messages)) } if got, ok := writer.messages[0].(string); !ok || got != "status=200 ok" { t.Fatalf("Printf() should format message, got %#v", writer.messages) } } func TestLoggerUsesSeverityOrderingWhenThresholdModeIsDisabled(t *testing.T) { writer := &stubLoggerWriter{} logger := CreateLogger(). SetLevel(NewThresholdLogLevel(1, 0, "warn")). AddWriter(writer) logger.Print(NewThresholdLogLevel(0, 100, "info")) logger.Print(NewThresholdLogLevel(2, 0, "error")) if writer.printCalls != 1 { t.Fatalf("severity mode should allow only lower-or-equal severity levels, got %d writes", writer.printCalls) } } func TestLoggerUsesThresholdOrderingWhenThresholdModeIsEnabled(t *testing.T) { writer := &stubLoggerWriter{} logger := CreateLogger(). SetLevel(NewThresholdLogLevel(4, 20, "custom")). SetThresholdMode(true). AddWriter(writer) logger.Print(NewThresholdLogLevel(4, 10, "debug")) logger.Print(NewThresholdLogLevel(0, 30, "info")) if writer.printCalls != 1 { t.Fatalf("threshold mode should allow only entries at or below the configured threshold, got %d writes", writer.printCalls) } } func TestDeprecatedLevelMethodKeepsLegacySeverityBehavior(t *testing.T) { writer := &stubLoggerWriter{} logger := CreateLogger(). Level(FATAL). AddWriter(writer) logger.Print(INFO, "info") logger.Print(WARN, "warn") logger.Print(ERROR, "error") logger.Print(FATAL, "fatal") logger.Print(DEBUG, "debug") if writer.printCalls != 4 { t.Fatalf("Level(FATAL) should keep legacy behavior and allow INFO/WARN/ERROR/FATAL only, got %d writes", writer.printCalls) } } func TestSameLevelIgnoresThresholdDifferencesForCompatibility(t *testing.T) { legacy := NewLogLevel(1, "warn") threshold := NewThresholdLogLevel(1, 20, "warn") if !legacy.SameLevel(threshold) { t.Fatalf("SameLevel() should continue comparing only severity index") } if legacy.Equal(threshold) { t.Fatalf("Equal() should distinguish levels with different threshold configuration") } } func TestSameThresholdComparesOnlyThresholdValue(t *testing.T) { first := NewThresholdLogLevel(1, 20, "warn") second := NewThresholdLogLevel(9, 20, "custom") third := NewThresholdLogLevel(1, 30, "warn") if !first.SameThreshold(second) { t.Fatalf("SameThreshold() should ignore severity and compare threshold only") } if first.SameThreshold(third) { t.Fatalf("SameThreshold() should detect different threshold values") } } func TestLogLevelForMethodReturnsExpectedLevels(t *testing.T) { tests := []struct { name string method string want LogLevel }{ {name: "get", method: http.MethodGet, want: HTTPGetLevel}, {name: "head", method: http.MethodHead, want: HTTPHeadLevel}, {name: "post", method: http.MethodPost, want: HTTPPostLevel}, {name: "put", method: http.MethodPut, want: HTTPPutLevel}, {name: "patch", method: http.MethodPatch, want: HTTPPatchLevel}, {name: "delete", method: http.MethodDelete, want: HTTPDeleteLevel}, {name: "options", method: http.MethodOptions, want: HTTPOptionsLevel}, {name: "connect", method: http.MethodConnect, want: HTTPConnectLevel}, {name: "trace", method: http.MethodTrace, want: HTTPTraceLevel}, {name: "unknown", method: "PROPFIND", want: HTTPUnknownLevel}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { got := LogLevelForMethod(tt.method) if got.n != tt.want.n || got.t != tt.want.t || got.fg != tt.want.fg || got.bg != tt.want.bg { t.Fatalf("LogLevelForMethod(%q) = %#v, want %#v", tt.method, got, tt.want) } }) } } func TestNewLevelConstructorsSetExpectedSeverity(t *testing.T) { tests := []struct { name string got LogLevel want LogLevel wantTh uint8 }{ {name: "info", got: NewInfoLogLevel("custom"), want: INFO, wantTh: 10}, {name: "warn", got: NewWarnLogLevel("custom"), want: WARN, wantTh: 20}, {name: "error", got: NewErrorLogLevel("custom"), want: ERROR, wantTh: 30}, {name: "fatal", got: NewFatalLogLevel("custom"), want: FATAL, wantTh: 40}, {name: "debug", got: NewDebugLogLevel("custom"), want: DEBUG, wantTh: 0}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { if tt.got.n != tt.want.n { t.Fatalf("%s severity = %d, want %d", tt.name, tt.got.n, tt.want.n) } if tt.got.th != tt.wantTh { t.Fatalf("%s threshold = %d, want %d", tt.name, tt.got.th, tt.wantTh) } if tt.got.GetName() != "custom" { t.Fatalf("%s constructor should preserve name, got %q", tt.name, tt.got.GetName()) } }) } } func TestNewLevelConstructorsWithColorsSetExpectedFields(t *testing.T) { info := NewInfoLogLevelWithColors("info-custom", FgBlue, BgYellow) if info.n != INFO.n || info.GetName() != "info-custom" || info.fg != FgBlue || info.bg != BgYellow { t.Fatalf("NewInfoLogLevelWithColors() = %#v", info) } warn := NewWarnLogLevelWithColors("warn-custom", FgMagenta, BgCyan) if warn.n != WARN.n || warn.GetName() != "warn-custom" || warn.fg != FgMagenta || warn.bg != BgCyan { t.Fatalf("NewWarnLogLevelWithColors() = %#v", warn) } errLevel := NewErrorLogLevelWithColors("error-custom", FgRed, BgWhite) if errLevel.n != ERROR.n || errLevel.GetName() != "error-custom" || errLevel.fg != FgRed || errLevel.bg != BgWhite { t.Fatalf("NewErrorLogLevelWithColors() = %#v", errLevel) } fatal := NewFatalLogLevelWithColors("fatal-custom", FgHiRed, BgBlack) if fatal.n != FATAL.n || fatal.GetName() != "fatal-custom" || fatal.fg != FgHiRed || fatal.bg != BgBlack { t.Fatalf("NewFatalLogLevelWithColors() = %#v", fatal) } debug := NewDebugLogLevelWithColors("debug-custom", FgGreen, BgDefault) if debug.n != DEBUG.n || debug.GetName() != "debug-custom" || debug.fg != FgGreen || debug.bg != BgDefault { t.Fatalf("NewDebugLogLevelWithColors() = %#v", debug) } } func TestCreateTextWriterCloseOnNonCloserIsNoOp(t *testing.T) { writer := CreateTextWriter(&bytes.Buffer{}) if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } } func TestCreateTextWriterDoesNotCloseExternalCloser(t *testing.T) { file, err := os.CreateTemp(t.TempDir(), "text-writer") if err != nil { t.Fatalf("CreateTemp() error = %v", err) } t.Cleanup(func() { _ = file.Close() }) writer := CreateTextWriter(file) if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } if _, err := file.WriteString("still open"); err != nil { t.Fatalf("CreateTextWriter() should not close external writers, got %v", err) } } func TestCreateJsonWriterCloseOnNonCloserIsNoOp(t *testing.T) { writer := CreateJsonWriter(&bytes.Buffer{}, false) if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } } func TestCreateJsonWriterDoesNotCloseExternalCloser(t *testing.T) { file, err := os.CreateTemp(t.TempDir(), "json-writer") if err != nil { t.Fatalf("CreateTemp() error = %v", err) } t.Cleanup(func() { _ = file.Close() }) writer := CreateJsonWriter(file, false) if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } if _, err := file.WriteString("still open"); err != nil { t.Fatalf("CreateJsonWriter() should not close external writers, got %v", err) } } func TestJsonWriterPrintAllowsEmptyMessages(t *testing.T) { var buf bytes.Buffer writer := CreateJsonWriter(&buf, false) if err := writer.Print(INFO, "TEST", nil); err != nil { t.Fatalf("Print() error = %v", err) } var message LoggerJsonMessage if err := json.Unmarshal(buf.Bytes(), &message); err != nil { t.Fatalf("json.Unmarshal() error = %v", err) } if message.Message != "" { t.Fatalf("message should be empty, got %q", message.Message) } } func TestJsonWriterPrintPreservesTrailingNewlineSemantic(t *testing.T) { var buf bytes.Buffer writer := CreateJsonWriter(&buf, false) if err := writer.Print(INFO, "TEST", nil, "hello\n"); err != nil { t.Fatalf("Print() error = %v", err) } data := buf.Bytes() if !bytes.HasSuffix(data, []byte("\n")) { t.Fatalf("JSON output should end with newline, got %q", data) } var message LoggerJsonMessage if err := json.Unmarshal(bytes.TrimSuffix(data, []byte("\n")), &message); err != nil { t.Fatalf("json.Unmarshal() error = %v", err) } if message.Message != "hello" { t.Fatalf("message should not include trailing newline, got %q", message.Message) } } func TestTextWriterPrintlnDoesNotLeaveTrailingMessageSeparator(t *testing.T) { var buf bytes.Buffer formatter := NewFormatter(). SetFormat("%m (%S)"). SetColorOutput(false) writer := CreateTextWriter(&buf).SetFormatter(formatter) if err := writer.Print(DEBUG, "TEST", nil, "debug details", "\n"); err != nil { t.Fatalf("Print() error = %v", err) } got := strings.TrimSuffix(buf.String(), "\n") if got != "debug details (%S)" { t.Fatalf("println newline marker should not leave trailing message separator, got %q", got) } } func TestTextWriterPrintlnDoesNotLeaveTrailingMessageSeparatorAfterReplacement(t *testing.T) { var buf bytes.Buffer formatter := NewFormatter(). SetFormat("%m (%S)"). SetColorOutput(false) writer := CreateTextWriter(&buf).SetFormatter(formatter) logger := CreateLogger(). SetLevel(DEBUG). AddWriter(writer). AddReplacer("details", "details") logger.Debugln("debug details") got := strings.TrimSuffix(buf.String(), "\n") if got != "debug details (%S)" { t.Fatalf("println newline marker should not leave trailing message separator after replacements, got %q", got) } } func TestJsonWriterPrintlnDoesNotLeaveTrailingMessageSeparator(t *testing.T) { var buf bytes.Buffer writer := CreateJsonWriter(&buf, false) if err := writer.Print(INFO, "TEST", nil, "hello", "\n"); err != nil { t.Fatalf("Print() error = %v", err) } var message LoggerJsonMessage if err := json.Unmarshal(bytes.TrimSuffix(buf.Bytes(), []byte("\n")), &message); err != nil { t.Fatalf("json.Unmarshal() error = %v", err) } if message.Message != "hello" { t.Fatalf("message should not include trailing separator from newline marker, got %q", message.Message) } } func TestLogLevelForegroundSettersOverridePreviousColorMode(t *testing.T) { level := NewLogLevel(0, "custom") formatter := NewFormatter() level.SetFgColor(FgRed) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, FgRed.String()) { t.Fatalf("expected plain foreground color prefix %q, got %q", FgRed.String(), got) } level.SetForeground256Color(FgColor256(123)) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, FgColor256(123).String()) { t.Fatalf("expected 256-color foreground prefix %q, got %q", FgColor256(123).String(), got) } level.SetForegroundRGB(1, 2, 3) expectedRGB := NewFgColorRGB(1, 2, 3).String() if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, expectedRGB) { t.Fatalf("expected RGB foreground prefix %q, got %q", expectedRGB, got) } level.SetFgColor(FgBlue) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, FgBlue.String()) { t.Fatalf("expected last plain foreground color to win with prefix %q, got %q", FgBlue.String(), got) } } func TestLogLevelBackgroundSettersOverridePreviousColorMode(t *testing.T) { level := NewLogLevel(0, "custom") formatter := NewFormatter() level.SetBgColor(BgRed) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, BgRed.String()) { t.Fatalf("expected plain background color prefix %q, got %q", BgRed.String(), got) } level.SetBackground256Color(BgColor256(123)) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, BgColor256(123).String()) { t.Fatalf("expected 256-color background prefix %q, got %q", BgColor256(123).String(), got) } level.SetBackgroundRGB(1, 2, 3) expectedRGB := NewBgColorRGB(1, 2, 3).String() if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, expectedRGB) { t.Fatalf("expected RGB background prefix %q, got %q", expectedRGB, got) } level.SetBgColor(BgBlue) if got := formatter.ColorizeString("x", level); !strings.HasPrefix(got, BgBlue.String()) { t.Fatalf("expected last plain background color to win with prefix %q, got %q", BgBlue.String(), got) } } func TestLogLevelAttributesAffectColorizedOutput(t *testing.T) { level := NewLogLevel(0, "custom") level.AddAttribute(Italic).AddAttribute(Bold) got := NewFormatter().ColorizeString("x", level) if !strings.Contains(got, Italic.String()) { t.Fatalf("expected italic attribute in colorized output, got %q", got) } if !strings.Contains(got, Bold.String()) { t.Fatalf("expected bold attribute in colorized output, got %q", got) } } func TestLogLevelRemoveAttributeRemovesAllMatches(t *testing.T) { level := NewLogLevel(0, "custom") level.AddAttribute(Bold).AddAttribute(Italic).AddAttribute(Bold) level.RemoveAttribute(Bold) got := level.GetAttributes() if len(got) != 1 || got[0] != Italic { t.Fatalf("expected only italic attribute to remain, got %#v", got) } } func TestLogLevelSetAttributesCopiesInputSlice(t *testing.T) { level := NewLogLevel(0, "custom") attrs := []Attribute{Bold, Italic} level.SetAttributes(attrs) attrs[0] = Underline got := level.GetAttributes() if len(got) != 2 || got[0] != Bold || got[1] != Italic { t.Fatalf("expected SetAttributes to copy input slice, got %#v", got) } } func TestLogLevelGetAttributesReturnsCopy(t *testing.T) { level := NewLogLevel(0, "custom") level.SetAttributes([]Attribute{Bold, Italic}) got := level.GetAttributes() got[0] = Underline again := level.GetAttributes() if len(again) != 2 || again[0] != Bold || again[1] != Italic { t.Fatalf("expected GetAttributes to return a copy, got %#v", again) } } func TestLogLevelDeprecatedForegroundAccessorsRemainCompatible(t *testing.T) { level := NewLogLevel(0, "custom") level.SetFgColor(FgBlue) if got := level.GetFgColor(); got != FgBlue { t.Fatalf("expected deprecated foreground accessors to round-trip %v, got %v", FgBlue, got) } level.SetForegroundColor(FgRed) if got := level.GetFgColor(); got != FgRed { t.Fatalf("expected deprecated getter to reflect new foreground setter, got %v", got) } } func TestLogLevelDeprecatedBackgroundAccessorsRemainCompatible(t *testing.T) { level := NewLogLevel(0, "custom") level.SetBgColor(BgBlue) if got := level.GetBgColor(); got != BgBlue { t.Fatalf("expected deprecated background accessors to round-trip %v, got %v", BgBlue, got) } level.SetBackgroundColor(BgRed) if got := level.GetBgColor(); got != BgRed { t.Fatalf("expected deprecated getter to reflect new background setter, got %v", got) } } func TestFormatterHandlesEmptyTracebackPlaceholders(t *testing.T) { formatter := NewFormatter(). SetFormat("%m|%b|%B|%M|%f|%n|%s|%p") got := formatter.FormatMessage(INFO, "TEST", nil, "hello") if got != "hello|||||||" { t.Fatalf("empty traceback placeholders should be empty, got %q", got) } } func TestFormatterDoesNotInterpretPlaceholdersInsideMessages(t *testing.T) { formatter := NewFormatter(). SetFormat("%L:%m") message := "literal %L %s %p" got := formatter.FormatMessage(INFO, "TEST", nil, message) if got != "INFO:literal %L %s %p" { t.Fatalf("message placeholder-looking text should stay literal, got %q", got) } } func TestNewFormatterDoesNotMutateDefaultFormatter(t *testing.T) { formatter := NewFormatter() formatter.SetFormat("custom") if DefaultTextFormatter.Format == "custom" { t.Fatal("NewFormatter() should return a copy, not mutate DefaultTextFormatter") } } func TestTextWriterColorOutputHonorsColorOnlyStdoutFalse(t *testing.T) { var buf bytes.Buffer formatter := NewFormatter(). SetFormat("%m"). SetColorOutput(true). SetColorOnlyStdout(false) writer := CreateTextWriter(&buf).SetFormatter(formatter) if err := writer.Print(INFO, "TEST", nil, "hello"); err != nil { t.Fatalf("Print() error = %v", err) } if !strings.Contains(buf.String(), "\x1b[") { t.Fatalf("ColorOnlyStdout(false) should allow color for external writers, got %q", buf.String()) } } func TestTextWriterColorOutputCanBeDisabled(t *testing.T) { var buf bytes.Buffer formatter := NewFormatter(). SetFormat("%m"). SetColorOutput(false). SetColorOnlyStdout(false) writer := CreateTextWriter(&buf).SetFormatter(formatter) if err := writer.Print(INFO, "TEST", nil, "hello"); err != nil { t.Fatalf("Print() error = %v", err) } if strings.Contains(buf.String(), "\x1b[") { t.Fatalf("SetColorOutput(false) should disable color output, got %q", buf.String()) } } func TestCreateTextStdoutWriterDoesNotCloseStdout(t *testing.T) { stdoutFile := swapStdout(t) writer := CreateTextStdoutWriter() if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } if _, err := stdoutFile.WriteString("still open"); err != nil { t.Fatalf("stdout writer Close() should not close stdout, got %v", err) } } func TestCreateJsonStdoutWriterDoesNotCloseStdout(t *testing.T) { stdoutFile := swapStdout(t) writer := CreateJsonStdoutWriter(false) if err := writer.Close(); err != nil { t.Fatalf("Close() error = %v", err) } if _, err := stdoutFile.WriteString("still open"); err != nil { t.Fatalf("stdout writer Close() should not close stdout, got %v", err) } } func TestGetFullTracebackSkipsRuntimeAndSneklogFrames(t *testing.T) { tracebacks := captureTracebackForTest() if len(tracebacks) == 0 { t.Fatal("expected at least one traceback frame") } first := tracebacks[0] if first.Method != "captureTracebackForTest" { t.Fatalf("first frame should be the nearest user frame, got %s", first.Method) } for _, tb := range tracebacks { if strings.HasPrefix(tb.Signature, "runtime.") { t.Fatalf("runtime frame should be filtered out, got %s", tb.Signature) } if _, ok := internalTracebackMethods[tb.Method]; ok { t.Fatalf("internal sneklog frame should be filtered out, got %s", tb.Signature) } } } func TestGetTracebackReturnsNearestUserFrame(t *testing.T) { tb := captureSingleTracebackForTest() if tb == nil { t.Fatal("expected traceback frame") } if tb.Method != "captureSingleTracebackForTest" { t.Fatalf("expected nearest user frame, got %s", tb.Method) } if strings.HasPrefix(tb.Signature, "runtime.") { t.Fatalf("runtime frame should be filtered out, got %s", tb.Signature) } if _, ok := internalTracebackMethods[tb.Method]; ok { t.Fatalf("internal sneklog frame should be filtered out, got %s", tb.Signature) } } func swapStdout(t *testing.T) *os.File { t.Helper() oldStdout := os.Stdout stdoutFile, err := os.CreateTemp(t.TempDir(), "stdout") if err != nil { t.Fatalf("CreateTemp() error = %v", err) } os.Stdout = stdoutFile t.Cleanup(func() { os.Stdout = oldStdout _ = stdoutFile.Close() }) return stdoutFile } func captureTracebackForTest() []*MethodTraceback { return getFullTraceback(0) } func captureSingleTracebackForTest() *MethodTraceback { return getTraceback() }