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) } }