summercms/modules/diary/console_test.go

package diary_test

import (
	"bytes"
	"context"
	"log/slog"
	"strings"
	"testing"
	"time"

	"git.golem15.com/golem15/summercms/modules/bonfire"
	"git.golem15.com/golem15/summercms/modules/diary"
	"github.com/charmbracelet/colorprofile"
)

// record handles one record with a zero time (no time column) on h.
func record(t *testing.T, h slog.Handler, level slog.Level, msg string, attrs ...slog.Attr) {
	t.Helper()
	r := slog.NewRecord(time.Time{}, level, msg, 0)
	r.AddAttrs(attrs...)
	if err := h.Handle(context.Background(), r); err != nil {
		t.Fatalf("Handle: %v", err)
	}
}

// TestConsoleStripsControlChars: control characters in the message, in
// attribute keys and in values never reach the terminal; line breaks become
// spaces, so one record is one line.
func TestConsoleStripsControlChars(t *testing.T) {
	for _, profile := range []colorprofile.Profile{colorprofile.NoTTY, colorprofile.ANSI256} {
		var buf bytes.Buffer
		h := diary.NewConsoleHandler(&buf, diary.ConsoleOptions{Profile: profile})
		record(t, h, slog.LevelInfo, "evil \x1b[31mred\x1b[0m\a bell\nsecond line\rreturn",
			slog.String("value", "a\x1b]0;title\x07b\nc"),
			slog.String("k\x1bey", "v"),
			slog.Any("err", errString("boom\x1b[2Jclear")))
		out := buf.String()
		if strings.Count(out, "\n") != 1 || !strings.HasSuffix(out, "\n") {
			t.Errorf("profile %v: record is not exactly one line: %q", profile, out)
		}
		for _, bad := range []string{"\x1b[31mred", "\x1b]0;", "\a", "\x07", "\r", "\x1b[2J", "k\x1bey"} {
			if strings.Contains(out, bad) {
				t.Errorf("profile %v: output carries %q: %q", profile, bad, out)
			}
		}
		for _, want := range []string{"[31mred", "bell second line return", "[2Jclear", "key="} {
			if !strings.Contains(out, want) {
				t.Errorf("profile %v: output lacks the cleaned text %q: %q", profile, want, out)
			}
		}
	}
}

type errString string

func (e errString) Error() string { return string(e) }

// TestConsoleComponentPrefix: the component is a fixed-width column, so
// messages line up whether a record has a short component, none or one
// given as a record attribute; inside a group it is an ordinary attribute.
func TestConsoleComponentPrefix(t *testing.T) {
	var buf bytes.Buffer
	h := diary.NewConsoleHandler(&buf, diary.ConsoleOptions{Profile: colorprofile.NoTTY})
	record(t, h.WithAttrs([]slog.Attr{slog.String(diary.ComponentKey, "db")}), slog.LevelInfo, "MSG")
	record(t, h.WithAttrs([]slog.Attr{slog.String(diary.ComponentKey, "journal")}), slog.LevelWarn, "MSG")
	record(t, h, slog.LevelError, "MSG")
	record(t, h, slog.LevelDebug, "MSG", slog.String(diary.ComponentKey, "river"))
	record(t, h.WithGroup("g").WithAttrs([]slog.Attr{slog.String(diary.ComponentKey, "inner")}), slog.LevelInfo, "MSG")

	lines := strings.Split(strings.TrimSuffix(buf.String(), "\n"), "\n")
	if len(lines) != 5 {
		t.Fatalf("got %d lines, want 5:\n%s", len(lines), buf.String())
	}
	wantPrefix := []string{
		"INFO  db         MSG",
		"WARN  journal    MSG",
		"ERROR            MSG",
		"DEBUG river      MSG",
		"INFO             MSG g.component=inner",
	}
	for i, want := range wantPrefix {
		if !strings.HasPrefix(lines[i], want) {
			t.Errorf("line %d = %q, want prefix %q", i, lines[i], want)
		}
		if col := strings.Index(lines[i], "MSG"); col != 17 {
			t.Errorf("line %d: message at column %d, want 17: %q", i, col, lines[i])
		}
	}
	if strings.Contains(lines[3], "component=") {
		t.Errorf("record-level component printed as an attribute: %q", lines[3])
	}

	// A record with a time starts with HH:MM:SS.
	buf.Reset()
	r := slog.NewRecord(time.Date(2026, 10, 21, 9, 5, 7, 0, time.Local), slog.LevelInfo, "timed", 0)
	if err := h.Handle(context.Background(), r); err != nil {
		t.Fatal(err)
	}
	if !strings.HasPrefix(buf.String(), "09:05:07 INFO ") {
		t.Errorf("timed line = %q, want the 09:05:07 prefix", buf.String())
	}
}

// TestConsoleStyledOnlyOnTerminal: the NoTTY profile writes no escape
// codes and ANSI256 does; through Setup, the auto format styles only when
// the profile allows it (never on a plain buffer unless forced).
func TestConsoleStyledOnlyOnTerminal(t *testing.T) {
	for _, tc := range []struct {
		profile colorprofile.Profile
		styled  bool
	}{{colorprofile.NoTTY, false}, {colorprofile.ANSI256, true}, {colorprofile.TrueColor, true}} {
		var buf bytes.Buffer
		h := diary.NewConsoleHandler(&buf, diary.ConsoleOptions{Profile: tc.profile})
		record(t, h.WithAttrs([]slog.Attr{slog.String(diary.ComponentKey, "blog")}), slog.LevelWarn, "styled?", slog.Int("n", 1))
		if got := strings.Contains(buf.String(), "\x1b["); got != tc.styled {
			t.Errorf("profile %v: escape codes %v, want %v: %q", tc.profile, got, tc.styled, buf.String())
		}
	}

	for _, tc := range []struct {
		name    string
		color   bonfire.ColorMode
		environ []string
		styled  bool
	}{
		{"auto on a buffer", bonfire.ColorAuto, []string{}, false},
		{"auto forced", bonfire.ColorAuto, []string{"FORCE_COLOR=1"}, true},
		{"auto forced but NO_COLOR", bonfire.ColorAuto, []string{"FORCE_COLOR=1", "NO_COLOR=1"}, false},
		{"always", bonfire.ColorAlways, []string{}, true},
		{"never forced", bonfire.ColorNever, []string{"FORCE_COLOR=1"}, false},
	} {
		t.Run(tc.name, func(t *testing.T) {
			var buf lockedBuffer
			setup(t, diary.Options{Stderr: &buf, Color: tc.color, Environ: tc.environ}, "SUMMER_LOG__DEFAULT=console")
			diary.For("blog").Info("hello")
			out := buf.String()
			if got := strings.Contains(out, "\x1b["); got != tc.styled {
				t.Errorf("escape codes %v, want %v: %q", got, tc.styled, out)
			}
			if !tc.styled && !strings.Contains(out, "level=INFO") {
				t.Errorf("unstyled console is not logfmt: %q", out)
			}
		})
	}
}

// TestConsoleLevelFromOptions: ConsoleOptions.Level gates records and nil
// means info.
func TestConsoleLevelFromOptions(t *testing.T) {
	var buf bytes.Buffer
	h := diary.NewConsoleHandler(&buf, diary.ConsoleOptions{Profile: colorprofile.NoTTY})
	if h.Enabled(context.Background(), slog.LevelDebug) || !h.Enabled(context.Background(), slog.LevelInfo) {
		t.Error("default console level is not info")
	}
	h = diary.NewConsoleHandler(&buf, diary.ConsoleOptions{Profile: colorprofile.NoTTY, Level: slog.LevelError})
	if h.Enabled(context.Background(), slog.LevelWarn) {
		t.Error("console level error lets warn through")
	}
}