memby/server/internal/logging/logging_test.go

package logging

import (
	"bytes"
	"io"
	"log/slog"
	"path/filepath"
	"strings"
	"testing"
)

func TestConsoleLineLeadsWithTimeLevelAndMessage(t *testing.T) {
	var output bytes.Buffer
	New(&output, slog.LevelInfo).Info("gateway ready", "listen", ":8080")

	line := strings.TrimRight(output.String(), "\n")
	if strings.HasPrefix(line, "{") {
		t.Fatalf("expected console output, got JSON: %s", line)
	}
	// The timestamp is a column, not a field: nothing labelled `time=` may appear in
	// front of — or anywhere in — the readable part of the line.
	if strings.Contains(line, "time=") || strings.Contains(line, "msg=") {
		t.Fatalf("console line still carries slog's own keys: %s", line)
	}
	if !strings.Contains(line, "INFO") || !strings.Contains(line, "gateway ready") {
		t.Fatalf("line is missing its level or message: %s", line)
	}
	if !strings.Contains(line, "listen=:8080") {
		t.Fatalf("line is missing its fields: %s", line)
	}
}

func TestConsoleLineOrdersIdentityFirstAndErrorLast(t *testing.T) {
	var output bytes.Buffer
	New(&output, slog.LevelInfo).Info("playback requested",
		"error", "nope", "title", "Dune", "user", "matt", "component", "playback",
	)

	line := output.String()
	order := []string{"component=playback", "user=matt", "title=Dune", "error=nope"}
	previous := -1
	for _, want := range order {
		at := strings.Index(line, want)
		if at < 0 {
			t.Fatalf("output %q does not contain %q", line, want)
		}
		if at < previous {
			t.Fatalf("field %q is out of order in %q", want, line)
		}
		previous = at
	}
}

func TestConsoleQuotesOnlyAmbiguousValues(t *testing.T) {
	var output bytes.Buffer
	New(&output, slog.LevelInfo).Info("signed in", "device", "Living Room", "user", "matt")

	line := output.String()
	if !strings.Contains(line, `device="Living Room"`) {
		t.Errorf("a value containing a space was not quoted: %s", line)
	}
	if !strings.Contains(line, `user=matt`) {
		t.Errorf("an unambiguous value was quoted: %s", line)
	}
}

func TestLoggingRedactsSensitiveAttributesAndURLs(t *testing.T) {
	var output bytes.Buffer
	logger, buffer := NewBuffered(&output, LevelTrace, 10, FormatConsole)
	logger.Log(nil, LevelTrace, "diagnostic request",
		"authorization", "Bearer private-token",
		"url", "https://emby.example/stream?api_key=private-key&quality=720p",
	)

	line := output.String()
	if strings.Contains(line, "private-token") || strings.Contains(line, "private-key") {
		t.Fatalf("console leaked a secret: %s", line)
	}
	if !strings.Contains(line, "TRACE") {
		t.Fatalf("console did not render TRACE: %s", line)
	}
	page := buffer.Events(0, 1)
	if len(page.Events) != 1 || page.Events[0].Level != "TRACE" ||
		page.Events[0].Attributes["authorization"] != "[redacted]" ||
		strings.Contains(page.Events[0].Attributes["url"], "private-key") {
		t.Fatalf("buffer leaked or mislabelled diagnostic event: %+v", page.Events)
	}
}

func TestParseFormat(t *testing.T) {
	tests := map[string]Format{
		"":         FormatConsole,
		"console":  FormatConsole,
		"nonsense": FormatConsole,
		"json":     FormatJSON,
		" LOGFMT":  FormatLogfmt,
		"text":     FormatLogfmt,
	}
	for input, want := range tests {
		if got := ParseFormat(input); got != want {
			t.Errorf("ParseFormat(%q) = %v, want %v", input, got, want)
		}
	}
}

func TestSelectedFormatIsWhatGetsWritten(t *testing.T) {
	var output bytes.Buffer
	logger, _ := NewBuffered(&output, slog.LevelInfo, 0, FormatJSON)
	logger.Info("gateway ready")
	if !strings.HasPrefix(strings.TrimSpace(output.String()), "{") {
		t.Fatalf("JSON format did not produce JSON: %s", output.String())
	}

	output.Reset()
	logger, _ = NewBuffered(&output, slog.LevelInfo, 0, FormatLogfmt)
	logger.Info("gateway ready")
	if !strings.Contains(output.String(), `msg="gateway ready"`) {
		t.Fatalf("logfmt format did not produce logfmt: %s", output.String())
	}
}

func TestBufferedLoggerRetainsStructuredEventsWithCursorPagination(t *testing.T) {
	var output bytes.Buffer
	logger, buffer := NewBuffered(&output, slog.LevelDebug, 3, FormatConsole)
	for i := 1; i <= 5; i++ {
		logger.Info("request complete", "number", i)
	}

	first := buffer.Events(0, 2)
	if first.Dropped != 2 || len(first.Events) != 2 || !first.HasMore {
		t.Fatalf("unexpected first page: %+v", first)
	}
	if first.Events[0].Sequence != 3 || first.Events[0].Attributes["number"] != "3" {
		t.Fatalf("oldest retained event was not delivered: %+v", first.Events[0])
	}
	second := buffer.Events(first.Next, 2)
	if len(second.Events) != 1 || second.Events[0].Sequence != 5 || second.HasMore {
		t.Fatalf("unexpected second page: %+v", second)
	}
}

func TestTailCursorReadDoesNotCopyTheRing(t *testing.T) {
	logger, buffer := NewBuffered(io.Discard, slog.LevelInfo, 5_000, FormatConsole)
	for range 5_000 {
		logger.Info("request complete")
	}
	allocations := testing.AllocsPerRun(100, func() {
		page := buffer.Events(5_000, 1_000)
		if len(page.Events) != 0 || page.HasMore {
			t.Fatalf("tail cursor unexpectedly returned events: %+v", page)
		}
	})
	if allocations > 2 {
		t.Fatalf("tail cursor allocated %.1f objects; the ring may be getting copied", allocations)
	}
}

func TestPersistentBufferRestoresTheRetainedTail(t *testing.T) {
	path := filepath.Join(t.TempDir(), "events.jsonl")
	var output bytes.Buffer
	logger, first, err := NewPersistentBuffered(&output, slog.LevelInfo, 3, FormatConsole, path)
	if err != nil {
		t.Fatal(err)
	}
	for i := 1; i <= 5; i++ {
		logger.Info("request", "number", i)
	}
	if err := first.Close(); err != nil {
		t.Fatal(err)
	}

	_, restored, err := NewPersistentBuffered(&output, slog.LevelInfo, 3, FormatConsole, path)
	if err != nil {
		t.Fatal(err)
	}
	defer restored.Close()
	page := restored.Events(0, 10)
	if len(page.Events) != 3 || page.Events[0].Attributes["number"] != "3" ||
		page.Events[2].Attributes["number"] != "5" {
		t.Fatalf("restored events = %+v", page.Events)
	}
}

func TestParseLevel(t *testing.T) {
	tests := map[string]slog.Level{
		"":        slog.LevelInfo,
		"trace":   LevelTrace,
		"debug":   slog.LevelDebug,
		"WARNING": slog.LevelWarn,
		"error":   slog.LevelError,
		"unknown": slog.LevelInfo,
	}
	for input, want := range tests {
		if got := ParseLevel(input); got != want {
			t.Errorf("ParseLevel(%q) = %v, want %v", input, got, want)
		}
	}
}

func TestParseCapacity(t *testing.T) {
	if got := ParseCapacity("1000", 5); got != 1000 {
		t.Fatalf("capacity = %d", got)
	}
	if got := ParseCapacity("-1", 5); got != 5 {
		t.Fatalf("negative capacity = %d", got)
	}
}