mfer/internal/log/log_test.go

//nolint:testpackage // white-box tests exercise unexported internals
package log

import (
	"bytes"
	stdlog "log"
	"log/slog"
	"os"
	"testing"

	"github.com/stretchr/testify/assert"
)

func TestBuild(t *testing.T) {
	t.Parallel()
	Init()
}

// capture points the package's writers at fresh buffers and sets its level,
// with colors off, then restores the default writers and level when the test
// ends. The state it changes is process-wide, so tests that use it do not
// run in parallel.
func capture(t *testing.T, l Level) (*bytes.Buffer, *bytes.Buffer) {
	t.Helper()

	var stdout, stderr bytes.Buffer

	DisableStyling()
	SetOutput(&stdout, &stderr)
	SetLevel(l)
	Init()

	t.Cleanup(func() {
		SetOutput(os.Stdout, os.Stderr)
		SetLevel(InfoLevel)
		Init()
	})

	return &stdout, &stderr
}

// TestLevelFiltering logs at every level, through both the plain and the
// formatting helpers, and checks that exactly the messages at or above the
// set level are written.
//
//nolint:paralleltest // changes the package's process-wide writers and level
func TestLevelFiltering(t *testing.T) {
	messages := []struct {
		level Level
		text  string
	}{
		{DebugLevel, "debug plain"},
		{DebugLevel, "debug formatted"},
		{VerboseLevel, "verbose plain"},
		{VerboseLevel, "verbose formatted"},
		{InfoLevel, "info plain"},
		{InfoLevel, "info formatted"},
		{WarnLevel, "warn plain"},
		{WarnLevel, "warn formatted"},
		{ErrorLevel, "error plain"},
		{ErrorLevel, "error formatted"},
	}

	levels := []Level{DebugLevel, VerboseLevel, InfoLevel, WarnLevel, ErrorLevel}

	for _, set := range levels {
		t.Run(set.String(), func(t *testing.T) {
			stdout, stderr := capture(t, set)

			Debug("debug plain")
			Debugf("debug %s", "formatted")
			Verbose("verbose plain")
			Verbosef("verbose %s", "formatted")
			Info("info plain")
			Infof("info %s", "formatted")
			Warn("warn plain")
			Warnf("warn %s", "formatted")
			Error("error plain")
			Errorf("error %s", "formatted")

			for _, m := range messages {
				if m.level >= set {
					assert.Contains(t, stderr.String(), m.text)
				} else {
					assert.NotContains(t, stderr.String(), m.text)
				}
			}

			assert.Empty(t, stdout.String())
		})
	}
}

// TestLineFormat checks the exact uncolored lines: a symbol per level
// right-aligned in four columns, then the message padded to 25 columns.
//
//nolint:paralleltest // changes the package's process-wide writers and level
func TestLineFormat(t *testing.T) {
	_, stderr := capture(t, VerboseLevel)

	Infof("scanning filesystem...")
	Verbosef("+ %s (%s)", "a.txt", "1 B")
	Warn("short")
	Errorf("%s", "a message longer than twenty-five columns")

	want := "   • scanning filesystem...   \n" +
		"   • + a.txt (1 B)            \n" +
		"   • short                    \n" +
		"   ⨯ a message longer than twenty-five columns\n"
	assert.Equal(t, want, stderr.String())
}

// TestDebugCallerTag checks that debug lines start with the file and line
// of the call that logged them.
//
//nolint:paralleltest // changes the package's process-wide writers and level
func TestDebugCallerTag(t *testing.T) {
	_, stderr := capture(t, DebugLevel)

	Debugf("enumerating path: %s", "/tmp")

	assert.Regexp(t, `^   • log_test\.go:\d+: enumerating path: /tmp\s*\n$`,
		stderr.String())
}

// TestColoredLine checks the colored lines: the symbol bold, and the line in
// the level's color.
func TestColoredLine(t *testing.T) {
	t.Parallel()

	var buf bytes.Buffer

	lg := slog.New(&cliHandler{w: &buf, color: true})
	lg.Debug("debug")
	lg.Info("info")
	lg.Warn("warn")
	lg.Error("error")

	want := "\x1b[37m\x1b[1m   •\x1b[0m debug                    \x1b[0m\n" +
		"\x1b[34m\x1b[1m   •\x1b[0m info                     \x1b[0m\n" +
		"\x1b[33m\x1b[1m   •\x1b[0m warn                     \x1b[0m\n" +
		"\x1b[31m\x1b[1m   ⨯\x1b[0m error                    \x1b[0m\n"
	assert.Equal(t, want, buf.String())
}

// TestRecordLevels checks the slog level of the record each helper logs,
// through slog's text handler with the time left out. slog has no verbose
// level, so verbose messages are info records.
//
//nolint:paralleltest // changes the package's process-wide logger and level
func TestRecordLevels(t *testing.T) {
	var buf bytes.Buffer

	capture(t, DebugLevel)

	opts := &slog.HandlerOptions{
		Level: slog.LevelDebug,
		ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr {
			if a.Key == slog.TimeKey {
				return slog.Attr{}
			}

			return a
		},
	}

	mu.Lock()
	logger = slog.New(slog.NewTextHandler(&buf, opts))
	mu.Unlock()

	Debugf("debug")
	Verbosef("verbose")
	Infof("info")
	Warnf("warn")
	Errorf("error")

	assert.Regexp(t, `^level=DEBUG msg="log_test\.go:\d+: debug"\n`+
		"level=INFO msg=verbose\n"+
		"level=INFO msg=info\n"+
		"level=WARN msg=warn\n"+
		"level=ERROR msg=error\n$", buf.String())
}

// TestProgress checks that progress lines go to the stdout writer whatever
// the log level, each starting with a carriage return so it overwrites the
// last, and that ProgressDone erases the line.
//
//nolint:paralleltest // changes the package's process-wide writers and level
func TestProgress(t *testing.T) {
	stdout, stderr := capture(t, ErrorLevel)

	Progressf("Scanning: %d files found", 1000)
	Progressf("Scanning: %d files found", 2000)
	ProgressDone()

	assert.Equal(t,
		"\rScanning: 1000 files found\rScanning: 2000 files found\r\x1b[K",
		stdout.String())
	assert.Empty(t, stderr.String())
}

// TestBeforeInit checks that records go to slog.Default() until Init runs,
// still filtered by the package's level. slog's default handler writes
// through the standard library's log package.
//
//nolint:paralleltest // changes the package's process-wide logger
func TestBeforeInit(t *testing.T) {
	var buf bytes.Buffer

	flags := stdlog.Flags()

	stdlog.SetOutput(&buf)
	stdlog.SetFlags(0)

	mu.Lock()
	logger = nil
	mu.Unlock()

	t.Cleanup(func() {
		stdlog.SetOutput(os.Stderr)
		stdlog.SetFlags(flags)
		Init()
	})

	Infof("loaded manifest with %d files", 3)
	Verbose("not shown at info level")

	assert.Equal(t, "INFO loaded manifest with 3 files\n", buf.String())
}