logger_test.go #1

package logger_test

import (
	"bufio"
	"os"
	"path/filepath"
	"strings"
	"testing"
	"time"

	"workshop.perforce.com/p4lf/internal/logger"
)

func newTestLogger(t *testing.T, maxSize int64, debug int) (*logger.Logger, string) {
	t.Helper()
	dir := t.TempDir()
	logPath := filepath.Join(dir, "p4lf.log")
	l, err := logger.New(logPath, maxSize, debug)
	if err != nil {
		t.Fatalf("logger.New: %v", err)
	}
	t.Cleanup(func() { l.Close() })
	return l, logPath
}

func readLog(t *testing.T, path string) string {
	t.Helper()
	data, err := os.ReadFile(path)
	if err != nil {
		t.Fatalf("ReadFile %q: %v", path, err)
	}
	return string(data)
}

// TestLogger_InfoWritten verifies that Infof produces an [INFO] line.
func TestLogger_InfoWritten(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 0)
	l.Infof("hello %s", "world")
	l.Close()

	if !strings.Contains(readLog(t, logPath), "[INFO] hello world") {
		t.Errorf("expected [INFO] line in log; got:\n%s", readLog(t, logPath))
	}
}

// TestLogger_WarnAndErrorWritten verifies WARN and ERROR levels.
func TestLogger_WarnAndErrorWritten(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 0)
	l.Warnf("something fishy")
	l.Errorf("something broken")
	l.Close()

	content := readLog(t, logPath)
	if !strings.Contains(content, "[WARN] something fishy") {
		t.Errorf("expected [WARN] line; got:\n%s", content)
	}
	if !strings.Contains(content, "[ERROR] something broken") {
		t.Errorf("expected [ERROR] line; got:\n%s", content)
	}
}

// TestLogger_DebugFiltered verifies that Debugf output is suppressed when debug=0.
func TestLogger_DebugFiltered(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 0)
	l.Debugf("this should be suppressed")
	l.Close()

	if strings.Contains(readLog(t, logPath), "suppressed") {
		t.Error("debug message appeared in log when debug=0")
	}
}

// TestLogger_DebugEnabled verifies that Debugf output appears when debug=1.
func TestLogger_DebugEnabled(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 1)
	l.Debugf("debug detail")
	l.Close()

	if !strings.Contains(readLog(t, logPath), "[DEBUG] debug detail") {
		t.Errorf("expected [DEBUG] line when debug=1; got:\n%s", readLog(t, logPath))
	}
}

// TestLogger_TimestampFormat verifies that each line starts with an ISO-8601 UTC timestamp.
func TestLogger_TimestampFormat(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 0)
	l.Infof("timestamped message")
	l.Close()

	f, err := os.Open(logPath)
	if err != nil {
		t.Fatal(err)
	}
	defer f.Close()
	scanner := bufio.NewScanner(f)
	scanner.Scan()
	line := scanner.Text()

	// Expected prefix: 2006-01-02T15:04:05.000Z
	if len(line) < 24 || line[4] != '-' || line[7] != '-' || line[10] != 'T' || !strings.HasSuffix(strings.Fields(line)[0], "Z") {
		t.Errorf("line does not start with expected ISO timestamp: %q", line)
	}
}

// TestLogger_Rotate verifies that an explicit Rotate() call creates a rotated
// log file and that subsequent writes go to a fresh log at the original path.
func TestLogger_Rotate(t *testing.T) {
	l, logPath := newTestLogger(t, 0, 0)
	dir := filepath.Dir(logPath)

	l.Infof("before rotation")
	if err := l.Rotate(); err != nil {
		t.Fatalf("Rotate: %v", err)
	}
	l.Infof("after rotation")
	l.Close()

	// Original log should exist and contain only post-rotation content.
	if !strings.Contains(readLog(t, logPath), "after rotation") {
		t.Error("post-rotate content missing from current log")
	}
	if strings.Contains(readLog(t, logPath), "before rotation") {
		t.Error("pre-rotate content unexpectedly in current log")
	}

	// A rotated file (plain .log or gzipped .log.gz) must appear within 2s.
	deadline := time.Now().Add(2 * time.Second)
	for time.Now().Before(deadline) {
		plain, _ := filepath.Glob(filepath.Join(dir, "p4lf.*.log"))
		gzipped, _ := filepath.Glob(filepath.Join(dir, "p4lf.*.log.gz"))
		if len(plain) > 0 || len(gzipped) > 0 {
			return
		}
		time.Sleep(20 * time.Millisecond)
	}
	t.Error("no rotated log file found after Rotate()")
}

// TestLogger_MaxLogSizeRotation verifies that the log is automatically rotated
// when the size threshold is exceeded.
func TestLogger_MaxLogSizeRotation(t *testing.T) {
	const maxSize = 200
	l, logPath := newTestLogger(t, maxSize, 0)
	dir := filepath.Dir(logPath)

	// Each log line is ~60+ bytes; 10 lines will exceed 200 bytes.
	for i := 0; i < 10; i++ {
		l.Infof("log line %d — padding to trigger auto-rotation threshold", i)
	}
	l.Close()

	deadline := time.Now().Add(2 * time.Second)
	for time.Now().Before(deadline) {
		plain, _ := filepath.Glob(filepath.Join(dir, "p4lf.*.log"))
		gzipped, _ := filepath.Glob(filepath.Join(dir, "p4lf.*.log.gz"))
		if len(plain) > 0 || len(gzipped) > 0 {
			return
		}
		time.Sleep(20 * time.Millisecond)
	}
	t.Errorf("no rotation occurred after exceeding MaxLogSize=%d", maxSize)
}