template/pkg/logger/handler_test.go
djmil 5ec8e6999a pkg/logger: human handler UX— colon format- debug mode- dedup counter
Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
2026-06-03 18:48:51 +00:00

244 lines
7.6 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

package logger
import (
"log/slog"
"strings"
"testing"
)
// ── humanLevel ────────────────────────────────────────────────────────────────
func TestHumanLevel(t *testing.T) {
tests := []struct {
level slog.Level
want string
}{
{slog.LevelDebug, "debug: "},
{slog.LevelInfo, ""},
{slog.LevelWarn, "warning: "},
{slog.LevelError, "error: "},
{slog.LevelError + 4, "error: "},
}
for _, tc := range tests {
if got := humanLevel(tc.level); got != tc.want {
t.Errorf("humanLevel(%v) = %q, want %q", tc.level, got, tc.want)
}
}
}
// ── INFO normal mode ──────────────────────────────────────────────────────────
func TestInfoNoFieldsNormalMode(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelInfo)).Info("hello world")
if got := strings.TrimRight(buf.String(), "\n"); got != "hello world" {
t.Errorf("got %q, want %q", got, "hello world")
}
}
func TestInfoFieldsHiddenNormalMode(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelInfo)).Info("starting", "port", 8080)
got := strings.TrimRight(buf.String(), "\n")
if got != "starting..." {
t.Errorf("got %q, want %q", got, "starting...")
}
}
// ── INFO debug mode ───────────────────────────────────────────────────────────
func TestInfoFieldsVisibleDebugMode(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelDebug)).Info("started", "port", 8080)
got := strings.TrimRight(buf.String(), "\n")
if got != "started: port=8080" {
t.Errorf("got %q, want %q", got, "started: port=8080")
}
}
// ── WARN / ERROR always full fields ──────────────────────────────────────────
func TestWarnFullFieldsNormalMode(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelInfo)).Warn("check", "key", "val")
if !strings.HasPrefix(buf.String(), "warning: ") {
t.Errorf("missing prefix: %q", buf.String())
}
if !strings.Contains(buf.String(), "key=val") {
t.Errorf("fields missing from WARN: %q", buf.String())
}
}
func TestErrorFullFieldsNormalMode(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelInfo)).Error("failed", "host", "db:5432")
if !strings.HasPrefix(buf.String(), "error: ") {
t.Errorf("missing prefix: %q", buf.String())
}
if !strings.Contains(buf.String(), "host=db:5432") {
t.Errorf("fields missing from ERROR: %q", buf.String())
}
}
// ── DEBUG deduplication ───────────────────────────────────────────────────────
func TestDebugNoFields(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
slog.New(h).Debug("step")
h.flush()
if got := strings.TrimRight(buf.String(), "\n"); got != "debug: step" {
t.Errorf("got %q, want %q", got, "debug: step")
}
}
func TestDebugFieldsHiddenWithEllipsis(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
slog.New(h).Debug("step", "n", 1)
h.flush()
if got := strings.TrimRight(buf.String(), "\n"); got != "debug: step..." {
t.Errorf("got %q, want %q", got, "debug: step...")
}
}
func TestDebugDedupCounter(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
log := slog.New(h)
log.Debug("processing", "n", 1)
log.Debug("processing", "n", 2)
log.Debug("processing", "n", 3)
log.Info("done") // commits the debug line
got := buf.String()
if !strings.Contains(got, "×3") {
t.Errorf("missing counter ×3: %q", got)
}
if !strings.HasSuffix(got, "done\n") {
t.Errorf("should end with done\\n: %q", got)
}
}
func TestDebugDedupCounterNotShownForSingle(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
slog.New(h).Debug("step")
h.flush()
if strings.Contains(buf.String(), "×") {
t.Errorf("counter should not appear for single occurrence: %q", buf.String())
}
}
func TestDebugCommittedByInfo(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
log := slog.New(h)
log.Debug("step")
log.Info("phase complete")
got := buf.String()
// debug line committed (newline written) before INFO
if !strings.Contains(got, "debug: step\n") {
t.Errorf("debug line should be followed by newline: %q", got)
}
if !strings.Contains(got, "phase complete\n") {
t.Errorf("info line should appear: %q", got)
}
}
func TestDebugDifferentMessageResetsCounter(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
log := slog.New(h)
log.Debug("alpha")
log.Debug("beta") // different message — commits alpha, starts beta
h.flush()
got := buf.String()
if !strings.Contains(got, "alpha\n") {
t.Errorf("alpha should be committed with newline: %q", got)
}
if !strings.Contains(got, "beta") {
t.Errorf("beta should appear: %q", got)
}
}
// ── WithAttrs ─────────────────────────────────────────────────────────────────
func TestWithAttrsVisibleOnWarn(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelInfo).WithAttrs([]slog.Attr{slog.String("rid", "abc")})
slog.New(h).Warn("check")
if !strings.Contains(buf.String(), "rid=abc") {
t.Errorf("pre-set attr missing from WARN: %q", buf.String())
}
}
func TestWithAttrsHiddenOnInfoNormalMode(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelInfo).WithAttrs([]slog.Attr{slog.String("rid", "abc")})
slog.New(h).Info("request")
if strings.Contains(buf.String(), "rid") {
t.Errorf("pre-set attrs should be hidden on INFO in normal mode: %q", buf.String())
}
if !strings.Contains(buf.String(), "...") {
t.Errorf("ellipsis should signal hidden attrs: %q", buf.String())
}
}
// ── Level filtering ───────────────────────────────────────────────────────────
func TestLevelFilteringAtWarn(t *testing.T) {
var buf strings.Builder
log := slog.New(newHumanHandler(&buf, slog.LevelWarn))
log.Info("dropped")
log.Warn("kept")
if strings.Contains(buf.String(), "dropped") {
t.Error("INFO should be filtered at WARN level")
}
if !strings.Contains(buf.String(), "kept") {
t.Error("WARN should appear")
}
}
// ── multiHandler fan-out ──────────────────────────────────────────────────────
func TestMultiHandlerFanOut(t *testing.T) {
var screen, file strings.Builder
m := multiHandler{
newHumanHandler(&screen, slog.LevelInfo),
slog.NewJSONHandler(&file, &slog.HandlerOptions{Level: slog.LevelDebug}),
}
log := slog.New(m)
log.Debug("trace", "k", "v")
log.Info("event", "k", "v")
if strings.Contains(screen.String(), "trace") {
t.Error("DEBUG should not appear on screen (handler level is INFO)")
}
if !strings.Contains(screen.String(), "event") {
t.Error("INFO should appear on screen")
}
if !strings.Contains(file.String(), "trace") {
t.Error("DEBUG should appear in file")
}
if !strings.Contains(file.String(), "event") {
t.Error("INFO should appear in file")
}
}