fancy-dns/internal/qlog/qlog_test.go

package qlog

import (
	"fmt"
	"path/filepath"
	"strconv"
	"strings"
	"sync"
	"testing"
	"time"

	"github.com/miekg/dns"
)

// openLogger builds a Logger over a temp-dir bbolt file. Every logger this
// file creates is closed through t.Cleanup, so a failing assertion cannot leak
// the flush goroutine or hold the bbolt file lock.
func openLogger(t *testing.T, path string, mutate func(*Options)) *Logger {
	t.Helper()
	opt := Options{
		Path:          path,
		MaxEntries:    1000,
		LiveBuffer:    256,
		FlushInterval: 20 * time.Millisecond,
		SampleRate:    1,
		LogBlocked:    true,
		LogCached:     true,
		LogErrors:     true,
		TopDomains:    128,
		TopTTL:        time.Minute,
	}
	if mutate != nil {
		mutate(&opt)
	}
	l, err := New(opt)
	if err != nil {
		t.Fatalf("qlog.New: %v", err)
	}
	t.Cleanup(func() { _ = l.Close() })
	return l
}

func tempPath(t *testing.T) string {
	t.Helper()
	return filepath.Join(t.TempDir(), "queries.db")
}

// entryFor builds an entry the way the engine does: the question-derived
// fields come from a real dns.Msg via FromMsg, the rest is filled in by the
// caller.
func entryFor(i int) Entry {
	q := new(dns.Msg)
	q.SetQuestion(fmt.Sprintf("host%d.test.", i), dns.TypeA)
	m := new(dns.Msg)
	m.SetReply(q)
	rr, err := dns.NewRR(q.Question[0].Name + " 30 IN A 203.0.113.7")
	if err != nil {
		panic(err)
	}
	m.Answer = []dns.RR{rr}
	e := Entry{
		TS:       time.Date(2024, 5, 1, 12, 0, i, 0, time.UTC),
		Client:   "192.0.2.10",
		Group:    "testers",
		Duration: int64(i) * 2,
		Action:   ActionAllow,
		Upstream: "127.0.0.1:5399",
		List:     "test-list",
		Protocol: "udp",
	}
	e.FromMsg(m)
	return e
}

func names(items []Entry) []string {
	out := make([]string, 0, len(items))
	for _, e := range items {
		out = append(out, e.Name)
	}
	return out
}

// TestLogRoundTripReopen is the core promise of the package: what Log accepted
// is what Search hands back after the process restarted.
func TestLogRoundTripReopen(t *testing.T) {
	path := tempPath(t)
	first := openLogger(t, path, nil)
	for i := 1; i <= 5; i++ {
		first.Log(entryFor(i))
	}
	first.Flush()
	if got := first.Count(); got != 5 {
		t.Fatalf("Count() = %d, want 5", got)
	}
	// Close before reopening: bbolt takes an exclusive file lock, so a
	// reopened handle would just block on the timeout.
	if err := first.Close(); err != nil {
		t.Fatalf("close: %v", err)
	}

	second := openLogger(t, path, nil)
	page, err := second.Search(Query{Limit: 50})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 5 {
		t.Fatalf("Total = %d, want 5", page.Total)
	}
	want := []string{"host5.test.", "host4.test.", "host3.test.", "host2.test.", "host1.test."}
	if got := names(page.Items); !equalStrings(got, want) {
		t.Fatalf("names = %v, want %v (newest first)", got, want)
	}
	for i, e := range page.Items {
		w := entryFor(5 - i)
		assertEntryFields(t, e, w)
	}
	if got := second.Count(); got != 5 {
		t.Errorf("Count() after reopen = %d, want 5", got)
	}
	if n := second.ErrorCount(); n != 0 {
		t.Errorf("ErrorCount() = %d, want 0", n)
	}
}

// TestReopenContinuesEntryIDs pins that ids stay unique across a restart: a
// logger that resumed at 1 would hand the UI two entries with the same id.
func TestReopenContinuesEntryIDs(t *testing.T) {
	path := tempPath(t)
	first := openLogger(t, path, nil)
	for i := 1; i <= 3; i++ {
		first.Log(entryFor(i))
	}
	first.Flush()
	if err := first.Close(); err != nil {
		t.Fatalf("close: %v", err)
	}

	second := openLogger(t, path, nil)
	second.Log(entryFor(4))
	second.Flush()
	page, err := second.Search(Query{Limit: 50})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if len(page.Items) != 4 {
		t.Fatalf("items = %d, want 4", len(page.Items))
	}
	seen := map[uint64]bool{}
	for _, e := range page.Items {
		if seen[e.ID] {
			t.Fatalf("duplicate entry id %d in %v", e.ID, names(page.Items))
		}
		seen[e.ID] = true
	}
	if page.Items[0].ID != 4 {
		t.Errorf("newest id = %d, want 4 (ids must continue across a restart)", page.Items[0].ID)
	}
}

// assertEntryFields compares every field the round trip has to preserve.
func assertEntryFields(t *testing.T, got, want Entry) {
	t.Helper()
	if !got.TS.Equal(want.TS) {
		t.Errorf("TS = %v, want %v", got.TS, want.TS)
	}
	if got.Client != want.Client {
		t.Errorf("Client = %q, want %q", got.Client, want.Client)
	}
	if got.Group != want.Group {
		t.Errorf("Group = %q, want %q", got.Group, want.Group)
	}
	if got.Name != want.Name {
		t.Errorf("Name = %q, want %q", got.Name, want.Name)
	}
	if got.QType != want.QType {
		t.Errorf("QType = %d, want %d", got.QType, want.QType)
	}
	if got.QTypeStr != want.QTypeStr {
		t.Errorf("QTypeStr = %q, want %q", got.QTypeStr, want.QTypeStr)
	}
	if got.RCode != want.RCode {
		t.Errorf("RCode = %d, want %d", got.RCode, want.RCode)
	}
	if got.Action != want.Action {
		t.Errorf("Action = %q, want %q", got.Action, want.Action)
	}
	if got.Duration != want.Duration {
		t.Errorf("Duration = %d, want %d", got.Duration, want.Duration)
	}
	if got.Upstream != want.Upstream {
		t.Errorf("Upstream = %q, want %q", got.Upstream, want.Upstream)
	}
	if got.List != want.List {
		t.Errorf("List = %q, want %q", got.List, want.List)
	}
	if got.Protocol != want.Protocol {
		t.Errorf("Protocol = %q, want %q", got.Protocol, want.Protocol)
	}
	if got.Blocked != want.Blocked {
		t.Errorf("Blocked = %v, want %v", got.Blocked, want.Blocked)
	}
	if got.RCodeName() != "NOERROR" {
		t.Errorf("RCodeName() = %q, want NOERROR", got.RCodeName())
	}
}

func equalStrings(a, b []string) bool {
	if len(a) != len(b) {
		return false
	}
	for i := range a {
		if a[i] != b[i] {
			return false
		}
	}
	return true
}

// TestMaxEntriesEvictsOldestFirst covers the on-disk size bound: the ring
// never grows past MaxEntries and the survivors are the newest entries.
func TestMaxEntriesEvictsOldestFirst(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.MaxEntries = 8 })
	for i := 1; i <= 20; i++ {
		l.Log(entryFor(i))
	}
	l.Flush()
	if got := l.Count(); got > 8 {
		t.Fatalf("Count() = %d, want <= 8", got)
	}
	if got := l.Count(); got != 8 {
		t.Fatalf("Count() = %d, want 8 (the ring should be full, not short)", got)
	}
	page, err := l.Search(Query{Limit: 100})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	want := []string{
		"host20.test.", "host19.test.", "host18.test.", "host17.test.",
		"host16.test.", "host15.test.", "host14.test.", "host13.test.",
	}
	if got := names(page.Items); !equalStrings(got, want) {
		t.Fatalf("survivors = %v, want %v", got, want)
	}
	// A second flush must not trim below the bound either: the key count is
	// re-checked on every transaction.
	l.Flush()
	if got := l.Count(); got != 8 {
		t.Errorf("Count() after re-flush = %d, want 8", got)
	}
}

// TestMaxEntriesZeroMeansUnbounded documents the escape hatch: 0 disables the
// trim entirely.
func TestMaxEntriesZeroMeansUnbounded(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.MaxEntries = 0 })
	for i := 1; i <= 25; i++ {
		l.Log(entryFor(i))
	}
	l.Flush()
	if got := l.Count(); got != 25 {
		t.Fatalf("Count() = %d, want 25", got)
	}
}

// TestLiveRingOrderAndGapFree pins the SSE initial burst: newest first, one
// step at a time, with no holes where the ring wrapped.
func TestLiveRingOrderAndGapFree(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.LiveBuffer = 32 })
	for i := 1; i <= 40; i++ {
		l.Log(entryFor(i))
	}
	got := l.Recent(32)
	if len(got) != 32 {
		t.Fatalf("Recent(32) returned %d entries, want 32", len(got))
	}
	for i, e := range got {
		want := 40 - i
		if e.ID != uint64(want) {
			t.Fatalf("entry %d has id %d, want %d (ring must be newest first, gap free)", i, e.ID, want)
		}
		if e.Name != fmt.Sprintf("host%d.test.", want) {
			t.Fatalf("entry %d name = %q, want host%d.test.", i, e.Name, want)
		}
	}
	if got := l.Recent(5); len(got) != 5 || got[0].ID != 40 || got[4].ID != 36 {
		t.Fatalf("Recent(5) = %v, want ids 40..36", got)
	}
	// limit <= 0 falls back to the 200-entry default, bounded by the ring.
	if got := l.Recent(0); len(got) != 32 {
		t.Fatalf("Recent(0) returned %d entries, want the whole 32-slot ring", len(got))
	}
	// A limit past the ring size clamps instead of panicking.
	if got := l.Recent(10000); len(got) != 32 {
		t.Fatalf("Recent(10000) returned %d entries, want 32", len(got))
	}
}

// TestLiveRingEmptyBeforeAnyWrite covers the zero state.
func TestLiveRingEmptyBeforeAnyWrite(t *testing.T) {
	l := openLogger(t, tempPath(t), nil)
	if got := l.Recent(10); len(got) != 0 {
		t.Fatalf("Recent(10) on an empty ring = %d entries, want 0", len(got))
	}
	if got := l.Stats().TotalLogged; got != 0 {
		t.Fatalf("TotalLogged = %d, want 0", got)
	}
}

// TestLiveRingConcurrentLogAndRecent is the race test for the whole point of
// the []atomic.Pointer[liveEntry] ring: many writers publish while readers
// walk, and no reader may ever see a half-written entry. Every entry carries
// its own writer id and sequence in two fields, so a torn read — the failure
// mode a mutex-free ring has to avoid — shows up as Name not matching
// Client+Protocol.
func TestLiveRingConcurrentLogAndRecent(t *testing.T) {
	const (
		writers   = 8
		perWriter = 200
		readers   = 3
	)
	l := openLogger(t, tempPath(t), func(o *Options) {
		o.LiveBuffer = 2048
		o.Path = "" // the live ring is what is under test; skip bbolt
	})
	var start sync.WaitGroup
	var done sync.WaitGroup
	start.Add(1)
	for w := 0; w < writers; w++ {
		w := w
		done.Add(1)
		go func() {
			defer done.Done()
			start.Wait()
			for i := 0; i < perWriter; i++ {
				l.Log(Entry{
					Client:   "w" + strconv.Itoa(w),
					Name:     fmt.Sprintf("w%d-i%d.test.", w, i),
					Protocol: strconv.Itoa(i),
					QType:    dns.TypeA,
					QTypeStr: "A",
					Action:   ActionAllow,
					TS:       time.Unix(int64(i), 0),
				})
			}
		}()
	}
	stop := make(chan struct{})
	var readersWG sync.WaitGroup
	for r := 0; r < readers; r++ {
		readersWG.Add(1)
		go func() {
			defer readersWG.Done()
			start.Wait()
			for {
				select {
				case <-stop:
					return
				default:
				}
				snapshot := l.Recent(64)
				seenID := make(map[uint64]bool, len(snapshot))
				seenKey := make(map[string]bool, len(snapshot))
				for _, e := range snapshot {
					// Name and the client/protocol pair are written together
					// into one immutable entry, so a reader that saw a mix
					// of two would be reading torn data.
					want := fmt.Sprintf("%s-i%s.test.", e.Client, e.Protocol)
					if e.Name != want {
						t.Errorf("torn entry: name %q does not match client %q/protocol %q", e.Name, e.Client, e.Protocol)
						return
					}
					if e.ID == 0 {
						t.Errorf("entry with id 0 reached a reader: %+v", e)
						return
					}
					if e.ID > writers*perWriter {
						t.Errorf("entry id %d is beyond the %d written", e.ID, writers*perWriter)
						return
					}
					if seenID[e.ID] {
						t.Errorf("id %d appeared twice in one snapshot", e.ID)
						return
					}
					seenID[e.ID] = true
					key := e.Client + "/" + e.Protocol
					if seenKey[key] {
						t.Errorf("entry w%s/%s appeared twice in one snapshot", e.Client, e.Protocol)
						return
					}
					seenKey[key] = true
				}
			}
		}()
	}
	start.Done()
	done.Wait()
	close(stop)
	readersWG.Wait()

	// With the writers done the ring must be a complete, ordered history.
	all := l.Recent(writers * perWriter)
	if len(all) != writers*perWriter {
		t.Fatalf("Recent returned %d entries, want %d", len(all), writers*perWriter)
	}
	for i, e := range all {
		want := writers*perWriter - i
		if e.ID != uint64(want) {
			t.Fatalf("entry %d has id %d, want %d (final snapshot must be gap free)", i, e.ID, want)
		}
	}
}

// TestSSEFanoutDeliversEachEntryOnce covers the live stream: every subscriber
// sees the same entries, in order, exactly once.
func TestSSEFanoutDeliversEachEntryOnce(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	const subs = 3
	chans := make([]<-chan Entry, 0, subs)
	cancels := make([]func(), 0, subs)
	for i := 0; i < subs; i++ {
		ch, cancel := l.Subscribe()
		chans = append(chans, ch)
		cancels = append(cancels, cancel)
	}
	if got := l.SubscriberCount(); got != subs {
		t.Fatalf("SubscriberCount() = %d, want %d", got, subs)
	}
	for i := 1; i <= 5; i++ {
		l.Log(entryFor(i))
	}
	for s, ch := range chans {
		for i := 1; i <= 5; i++ {
			select {
			case e := <-ch:
				if e.ID != uint64(i) {
					t.Errorf("subscriber %d: entry %d has id %d", s, i, e.ID)
				}
				if e.Name != fmt.Sprintf("host%d.test.", i) {
					t.Errorf("subscriber %d: entry %d name = %q", s, i, e.Name)
				}
			default:
				t.Fatalf("subscriber %d never got entry %d", s, i)
			}
		}
		select {
		case extra := <-ch:
			t.Errorf("subscriber %d got an extra entry: %+v", s, extra)
		default:
		}
	}
	for _, cancel := range cancels {
		cancel()
	}
}

// TestSSESlowSubscriberDoesNotBlockLog is the reason fanout is non-blocking: a
// consumer that stopped reading must never stall the query path.
func TestSSESlowSubscriberDoesNotBlockLog(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	slow, cancelSlow := l.Subscribe()
	defer cancelSlow()
	// Nothing ever reads from slow, so its 256-slot buffer fills and stays
	// full.
	for i := 0; i < 256; i++ {
		l.Log(entryFor(i + 1))
	}
	done := make(chan struct{})
	go func() {
		defer close(done)
		for i := 0; i < 50; i++ {
			l.Log(entryFor(i + 1))
		}
	}()
	select {
	case <-done:
	case <-time.After(10 * time.Second):
		t.Fatal("Log blocked on a subscriber that stopped reading")
	}
	// A healthy subscriber still gets everything.
	fast, cancelFast := l.Subscribe()
	defer cancelFast()
	l.Log(entryFor(999))
	select {
	case e := <-fast:
		if e.Name != "host999.test." {
			t.Errorf("fast subscriber got %q", e.Name)
		}
	case <-time.After(5 * time.Second):
		t.Fatal("fast subscriber did not receive the entry")
	}
	// The slow consumer's buffer only ever holds entries from the first
	// burst: everything logged after it filled up was dropped, not queued.
	drained := 0
	for {
		select {
		case e := <-slow:
			if e.ID > 256 {
				t.Fatalf("slow subscriber received a dropped-then-queued entry: %+v", e)
			}
			drained++
			continue
		default:
		}
		break
	}
	if drained != 256 {
		t.Errorf("slow subscriber buffered %d entries, want 256", drained)
	}
	select {
	case e := <-slow:
		t.Errorf("slow subscriber received a late entry: %+v", e)
	default:
	}
}

// TestSSEUnsubscribeStopsDelivery covers teardown: no delivery after the
// cancel func, a closed channel, and no leaked subscription slot.
func TestSSEUnsubscribeStopsDelivery(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	ch, cancel := l.Subscribe()
	l.Log(entryFor(1))
	if e := <-ch; e.ID != 1 {
		t.Fatalf("first entry id = %d, want 1", e.ID)
	}
	cancel()
	if got := l.SubscriberCount(); got != 0 {
		t.Fatalf("SubscriberCount() = %d after cancel, want 0", got)
	}
	l.Log(entryFor(2))
	// A closed channel yields immediately, so a plain receive is enough.
	select {
	case e, ok := <-ch:
		if ok {
			t.Fatalf("received %+v after unsubscribe", e)
		}
	case <-time.After(time.Second):
		t.Fatal("channel was not closed by the cancel func")
	}
	// Cancelling twice must not panic on a double close.
	cancel()
	if got := l.SubscriberCount(); got != 0 {
		t.Errorf("SubscriberCount() = %d, want 0", got)
	}
}

// TestFieldPreservationThroughMsg checks the question-derived fields come from
// the message and the flags are mirrored.
func TestFieldPreservationThroughMsg(t *testing.T) {
	l := openLogger(t, tempPath(t), nil)
	q := new(dns.Msg)
	q.SetQuestion("Blocked.Example.COM.", dns.TypeAAAA)
	m := new(dns.Msg)
	m.SetReply(q)
	m.Rcode = dns.RcodeNameError
	e := Entry{
		TS:       time.Date(2024, 5, 1, 12, 0, 0, 0, time.UTC),
		Client:   "2001:db8::5",
		Group:    "laptops",
		Duration: 7,
		Action:   ActionBlock,
		List:     "adlist",
		Protocol: "doh",
		Upstream: "",
	}
	e.FromMsg(m)
	l.Log(e)
	l.Flush()

	page, err := l.Search(Query{Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if len(page.Items) != 1 {
		t.Fatalf("items = %d, want 1", len(page.Items))
	}
	got := page.Items[0]
	if got.Name != "Blocked.Example.COM." {
		t.Errorf("Name = %q, want the name verbatim", got.Name)
	}
	if got.QType != dns.TypeAAAA || got.QTypeStr != "AAAA" {
		t.Errorf("QType = %d/%q, want AAAA/AAAA", got.QType, got.QTypeStr)
	}
	if got.RCode != dns.RcodeNameError || got.RCodeName() != "NXDOMAIN" {
		t.Errorf("RCode = %d/%q, want NXDOMAIN", got.RCode, got.RCodeName())
	}
	if !got.Blocked {
		t.Error("Blocked = false, want the mirror of ActionBlock")
	}
	if got.Client != "2001:db8::5" || got.Group != "laptops" || got.Duration != 7 {
		t.Errorf("client/group/duration = %q/%q/%d", got.Client, got.Group, got.Duration)
	}
	if got.List != "adlist" || got.Protocol != "doh" {
		t.Errorf("list/protocol = %q/%q", got.List, got.Protocol)
	}
	if got.Upstream != "" {
		t.Errorf("Upstream = %q, want empty (a blocked query never reaches one)", got.Upstream)
	}
	if got.TS.IsZero() {
		t.Error("TS was dropped")
	}
	// A blocked query is the mirror's only source, so a non-block must clear it.
	l.Log(entryFor(9))
	l.Flush()
	page, err = l.Search(Query{BlockedOnly: true, Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 1 || page.Items[0].Name != "Blocked.Example.COM." {
		t.Fatalf("BlockedOnly search = %+v, want just the blocked name", page.Items)
	}
}

// TestQueryStringStampsMissingFields covers the Log-time fixups: an entry
// built by hand gets a timestamp and a type name without the caller setting
// them.
func TestQueryStringStampsMissingFields(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	l.Log(Entry{Name: "stamped.test.", QType: dns.TypeMX, Action: ActionAllow})
	got := l.Recent(1)
	if len(got) != 1 {
		t.Fatalf("Recent(1) = %d entries, want 1", len(got))
	}
	if got[0].QTypeStr != "MX" {
		t.Errorf("QTypeStr = %q, want MX", got[0].QTypeStr)
	}
	if got[0].TS.IsZero() {
		t.Error("TS = zero, want the logger's clock")
	}
	if got[0].ID != 1 {
		t.Errorf("ID = %d, want 1", got[0].ID)
	}
}

// TestDisabledLoggerStillServesTheLiveRing covers the no-path configuration:
// nothing is persisted, but the SSE ring, the counters and the API filters
// still work.
func TestDisabledLoggerStillServesTheLiveRing(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	if l.Stats().Enabled {
		t.Error("Stats().Enabled = true without a path")
	}
	for i := 1; i <= 3; i++ {
		e := entryFor(i)
		e.Action = ActionBlock
		l.Log(e)
	}
	if got := l.Count(); got != 3 {
		t.Errorf("Count() = %d, want the 3 logged ids", got)
	}
	page, err := l.Search(Query{Action: "block", Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 3 {
		t.Fatalf("Total = %d, want 3 (search must fall back to the live ring)", page.Total)
	}
	// Offset and text filters work on the same fallback path.
	page, err = l.Search(Query{Text: "host2", Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 1 || page.Items[0].Name != "host2.test." {
		t.Fatalf("text search = %+v, want host2.test.", page.Items)
	}
	if err := l.Clear(); err != nil {
		t.Errorf("Clear() without persistence: %v", err)
	}
	if err := l.Close(); err != nil {
		t.Errorf("Close() without persistence: %v", err)
	}
}

// TestLogOnClosedLoggerIsANoOp covers the shutdown path: every read and write
// after Close must stay safe rather than panicking on a closed bbolt handle.
func TestLogOnClosedLoggerIsANoOp(t *testing.T) {
	l := openLogger(t, tempPath(t), nil)
	l.Log(entryFor(1))
	if err := l.Close(); err != nil {
		t.Fatalf("close: %v", err)
	}
	l.Log(entryFor(2))
	l.Flush()
	_ = l.Count()
	_ = l.Recent(10)
	if _, err := l.Search(Query{Limit: 10}); err == nil {
		t.Log("search on a closed store returned no error; acceptable")
	}
	if got := l.ErrorCount(); got > 1 {
		t.Errorf("ErrorCount() = %d, want at most the failed write", got)
	}
	// A nil logger is the "logging disabled" shape some callers hold; it must
	// swallow the call instead of panicking on the query path.
	var nilLogger *Logger
	nilLogger.Log(entryFor(3))
	if got := nilLogger.Recent(1); got != nil {
		t.Errorf("nil Recent() = %v, want nil", got)
	}
}

// TestShouldLogPolicy covers the sampling gate the engine consults.
func TestShouldLogPolicy(t *testing.T) {
	all := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	for _, a := range []Action{ActionAllow, ActionBlock, ActionCached, ActionError, ActionDrop, ActionRefused} {
		if !all.ShouldLog(a) {
			t.Errorf("ShouldLog(%q) = false with every category enabled", a)
		}
	}
	off := openLogger(t, tempPath(t), func(o *Options) {
		o.Path = ""
		o.LogBlocked = false
		o.LogCached = false
		o.LogErrors = false
	})
	if off.ShouldLog(ActionBlock) || off.ShouldLog(ActionCached) || off.ShouldLog(ActionError) || off.ShouldLog(ActionDrop) {
		t.Error("disabled categories must not be logged")
	}
	if !off.ShouldLog(ActionAllow) {
		t.Error("ordinary resolutions still pass a full sample rate")
	}
}

// TestClearEmptiesPersistedLog covers the admin API's "clear log" button.
func TestClearEmptiesPersistedLog(t *testing.T) {
	l := openLogger(t, tempPath(t), nil)
	for i := 1; i <= 4; i++ {
		l.Log(entryFor(i))
	}
	l.Flush()
	if err := l.Clear(); err != nil {
		t.Fatalf("clear: %v", err)
	}
	if got := l.Count(); got != 0 {
		t.Errorf("Count() = %d after Clear, want 0", got)
	}
	page, err := l.Search(Query{Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 0 {
		t.Errorf("Total = %d after Clear, want 0", page.Total)
	}
	// Logging keeps working afterwards, and the new entries are found.
	l.Log(entryFor(9))
	l.Flush()
	page, err = l.Search(Query{Limit: 10})
	if err != nil {
		t.Fatalf("search: %v", err)
	}
	if page.Total != 1 || page.Items[0].Name != "host9.test." {
		t.Fatalf("search after clear = %+v, want host9.test.", page.Items)
	}
}

// TestTopDomainsCounters covers the rolling per-domain panel: blocked counts
// are tracked separately from the total.
func TestTopDomainsCounters(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.Path = "" })
	for i := 0; i < 3; i++ {
		e := entryFor(1)
		e.Name = "ads.test."
		e.Action = ActionBlock
		l.Log(e)
	}
	for i := 0; i < 2; i++ {
		l.Log(entryFor(1))
	}
	blocked := l.TopBlocked(5)
	if len(blocked) != 1 {
		t.Fatalf("TopBlocked = %+v, want one domain", blocked)
	}
	if blocked[0].Name != "ads.test" || blocked[0].Count != 3 || blocked[0].Blocked != 3 {
		t.Errorf("TopBlocked[0] = %+v, want ads.test count 3 blocked 3", blocked[0])
	}
	if blocked[0].QTypeS != "A" {
		t.Errorf("QTypeS = %q, want A", blocked[0].QTypeS)
	}
	queried := l.TopQueried(5)
	if len(queried) != 2 {
		t.Fatalf("TopQueried = %+v, want two domains", queried)
	}
	if queried[0].Name != "ads.test" || queried[0].Count != 3 {
		t.Errorf("TopQueried[0] = %+v, want ads.test count 3 first", queried[0])
	}
	if got := l.TopDomains(5, true); len(got) != 1 {
		t.Errorf("TopDomains(blockedOnly) = %+v, want one entry", got)
	}
}

func BenchmarkLog(b *testing.B) {
	l, err := New(Options{Path: "", LiveBuffer: 4096, MaxEntries: 1024, TopDomains: 512, TopTTL: time.Minute})
	if err != nil {
		b.Fatal(err)
	}
	defer func() { _ = l.Close() }()
	e := entryFor(1)
	b.ReportAllocs()
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		l.Log(e)
	}
}

func BenchmarkRecent(b *testing.B) {
	l, err := New(Options{Path: "", LiveBuffer: 4096, MaxEntries: 1024, TopDomains: 512, TopTTL: time.Minute})
	if err != nil {
		b.Fatal(err)
	}
	defer func() { _ = l.Close() }()
	for i := 0; i < 4096; i++ {
		l.Log(entryFor(i%2000 + 1))
	}
	b.ReportAllocs()
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		_ = l.Recent(200)
	}
}

// TestEntriesWithNoTimestampAreStamped guards the LiveEntry field the SSE
// consumers render: an entry with no TS must not reach them as year 1.
func TestEntriesWithNoTimestampAreStamped(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) {
		o.Path = ""
		o.Now = func() time.Time { return time.Date(2024, 5, 1, 12, 0, 0, 0, time.UTC) }
	})
	l.Log(Entry{Name: "clock.test.", QType: dns.TypeA, Action: ActionAllow})
	got := l.Recent(1)
	if len(got) != 1 {
		t.Fatalf("Recent(1) = %d entries, want 1", len(got))
	}
	if !strings.HasSuffix(got[0].Name, "clock.test.") {
		t.Errorf("Name = %q", got[0].Name)
	}
	want := time.Date(2024, 5, 1, 12, 0, 0, 0, time.UTC)
	if !got[0].TS.Equal(want) {
		t.Errorf("TS = %v, want the injected clock %v", got[0].TS, want)
	}
}

// TestFlushDoesNotShareItsBatchWithNewEntries pins a race the detector finds:
// Flush took the pending slice and reset it to length zero, so entries logged
// while it was still marshalling the batch were appended over the same backing
// array. Under -race this fails without the fix; without -race it can store
// the wrong entries.
func TestFlushDoesNotShareItsBatchWithNewEntries(t *testing.T) {
	l := openLogger(t, tempPath(t), func(o *Options) { o.FlushInterval = time.Hour })
	for i := 0; i < 500; i++ {
		l.Log(entryFor(i % 50)) // a batch big enough to take a while to store
	}
	done := make(chan struct{})
	go func() {
		defer close(done)
		for i := 0; i < 1000; i++ {
			l.Log(entryFor(i % 50))
			if i%10 == 0 {
				time.Sleep(10 * time.Microsecond)
			}
		}
	}()
	for i := 0; i < 20; i++ {
		l.Flush()
	}
	<-done
	l.Flush()
}