Vetting/internal/logs/logs_test.go

package logs_test

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

	"vetting/internal/events"
	"vetting/internal/logs"
)

// TestAppendFansOutToSSE verifies the two guarantees of the log hub:
// (a) every line is persisted to the per-run file, and (b) every line
// is published as an SSE event with name log-<runID>. The UI relies on
// both — the file for reload replay, the event for live tail.
func TestAppendFansOutToSSE(t *testing.T) {
	dir := t.TempDir()
	hub := events.NewHub()
	lh, err := logs.NewHub(dir, hub)
	if err != nil {
		t.Fatalf("NewHub: %v", err)
	}
	defer lh.Close()

	_, ch, cancel := hub.Subscribe()
	defer cancel()

	w, err := lh.WriterFor(77)
	if err != nil {
		t.Fatalf("WriterFor: %v", err)
	}
	w.Append(logs.Line{Level: "info", Text: "hello from agent"})
	w.Append(logs.Line{Level: "error", Text: "<script>pwn</script>"})

	got := collect(ch, 3, 500*time.Millisecond)
	// Filter out heartbeats that may sneak in.
	var logEvents []events.Event
	for _, ev := range got {
		if strings.HasPrefix(ev.Name, "log-") {
			logEvents = append(logEvents, ev)
		}
	}
	if len(logEvents) < 2 {
		t.Fatalf("expected 2 log events, got %d (all=%+v)", len(logEvents), got)
	}
	for _, ev := range logEvents {
		if ev.Name != "log-77" {
			t.Fatalf("unexpected event name %q", ev.Name)
		}
	}
	// XSS protection: raw <script> must not appear — it's HTML-escaped.
	if strings.Contains(logEvents[1].Payload, "<script>") {
		t.Fatalf("log payload not escaped: %q", logEvents[1].Payload)
	}
	if !strings.Contains(logEvents[1].Payload, "&lt;script&gt;") {
		t.Fatalf("expected escaped <script>, got %q", logEvents[1].Payload)
	}

	// On disk: the file must contain both lines.
	path := filepath.Join(dir, "run-77.log")
	body, err := os.ReadFile(path)
	if err != nil {
		t.Fatalf("read log file: %v", err)
	}
	text := string(body)
	if !strings.Contains(text, "hello from agent") {
		t.Fatalf("disk log missing info line: %q", text)
	}
	if !strings.Contains(text, "<script>pwn</script>") {
		t.Fatalf("disk log should keep raw text (unescaped): %q", text)
	}
	if !strings.Contains(text, "INFO") || !strings.Contains(text, "ERROR") {
		t.Fatalf("disk log missing level prefix: %q", text)
	}
}

// TestAppendStagePublishesBothEvents: a line tagged with a stage must
// fan out to BOTH the all-pane event (log-<runID>) AND the stage-pane
// event (log-<runID>-<stage>) so the detail page's per-stage tabs see
// their own slice. Disk format prepends "[stage] " so the flat log
// remains greppable.
func TestAppendStagePublishesBothEvents(t *testing.T) {
	dir := t.TempDir()
	hub := events.NewHub()
	lh, err := logs.NewHub(dir, hub)
	if err != nil {
		t.Fatalf("NewHub: %v", err)
	}
	defer lh.Close()

	_, ch, cancel := hub.Subscribe()
	defer cancel()

	w, err := lh.WriterFor(42)
	if err != nil {
		t.Fatalf("WriterFor: %v", err)
	}
	w.Append(logs.Line{Level: "info", Stage: "SMART", Text: "reading attributes"})

	got := collect(ch, 4, 500*time.Millisecond)
	names := map[string]int{}
	for _, ev := range got {
		if strings.HasPrefix(ev.Name, "log-") {
			names[ev.Name]++
		}
	}
	if names["log-42"] != 1 {
		t.Fatalf("expected 1 event on log-42, got %d (names=%+v)", names["log-42"], names)
	}
	if names["log-42-SMART"] != 1 {
		t.Fatalf("expected 1 event on log-42-SMART, got %d (names=%+v)", names["log-42-SMART"], names)
	}

	// Disk: stage prepended so flat log is still useful.
	body, err := os.ReadFile(filepath.Join(dir, "run-42.log"))
	if err != nil {
		t.Fatalf("read log file: %v", err)
	}
	if !strings.Contains(string(body), "[SMART] reading attributes") {
		t.Fatalf("disk log missing stage prefix: %q", body)
	}
}

// TestReplay re-parses a file written by Append and emits the same SSE
// fragments — detail-page uses this to seed the All pane on reload of
// an in-flight run.
func TestReplay(t *testing.T) {
	dir := t.TempDir()
	hub := events.NewHub()
	lh, err := logs.NewHub(dir, hub)
	if err != nil {
		t.Fatalf("NewHub: %v", err)
	}
	defer lh.Close()

	w, err := lh.WriterFor(99)
	if err != nil {
		t.Fatalf("WriterFor: %v", err)
	}
	w.Append(logs.Line{Level: "info", Text: "dispatcher: picked"})
	w.Append(logs.Line{Level: "info", Stage: "SMART", Text: "smartctl /dev/sda"})

	replay := lh.Replay(99)
	if !strings.Contains(replay, "dispatcher: picked") {
		t.Fatalf("replay missing untagged line: %q", replay)
	}
	if !strings.Contains(replay, "smartctl /dev/sda") {
		t.Fatalf("replay missing tagged line: %q", replay)
	}
	if !strings.Contains(replay, `class="log-stage"`) {
		t.Fatalf("replay should render stage badge for tagged line: %q", replay)
	}
	// Missing file → empty string, no panic.
	if got := lh.Replay(12345); got != "" {
		t.Fatalf("replay of unknown run = %q, want empty", got)
	}
}

// TestWriterForIsCached verifies a second call returns the same Writer
// — otherwise parallel /log POSTs would race on file opens and possibly
// stomp on in-flight writes.
func TestWriterForIsCached(t *testing.T) {
	hub := events.NewHub()
	lh, err := logs.NewHub(t.TempDir(), hub)
	if err != nil {
		t.Fatalf("NewHub: %v", err)
	}
	defer lh.Close()

	w1, err := lh.WriterFor(1)
	if err != nil {
		t.Fatalf("WriterFor: %v", err)
	}
	w2, err := lh.WriterFor(1)
	if err != nil {
		t.Fatalf("WriterFor: %v", err)
	}
	if w1 != w2 {
		t.Fatalf("Writer not cached: %p vs %p", w1, w2)
	}
}

// collect drains up to max events or bails after deadline.
func collect(ch <-chan events.Event, max int, deadline time.Duration) []events.Event {
	out := []events.Event{}
	timer := time.NewTimer(deadline)
	defer timer.Stop()
	for len(out) < max {
		select {
		case ev, ok := <-ch:
			if !ok {
				return out
			}
			out = append(out, ev)
		case <-timer.C:
			return out
		}
	}
	return out
}