2020-05-26 13:37:37 +01:00
|
|
|
package querylog
|
|
|
|
|
|
|
|
import (
|
2021-02-09 12:17:02 +00:00
|
|
|
"fmt"
|
2020-11-30 10:32:58 +00:00
|
|
|
"math/rand"
|
2020-05-26 13:37:37 +01:00
|
|
|
"net"
|
2020-11-30 10:32:58 +00:00
|
|
|
"sort"
|
2020-05-26 13:37:37 +01:00
|
|
|
"testing"
|
2020-11-30 10:32:58 +00:00
|
|
|
"time"
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-04 17:35:13 +00:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/aghtest"
|
2020-10-30 10:32:02 +00:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/dnsfilter"
|
2021-03-11 09:17:54 +00:00
|
|
|
"github.com/AdguardTeam/dnsproxy/proxyutil"
|
2020-05-26 13:37:37 +01:00
|
|
|
"github.com/miekg/dns"
|
|
|
|
"github.com/stretchr/testify/assert"
|
2021-02-09 12:17:02 +00:00
|
|
|
"github.com/stretchr/testify/require"
|
2020-05-26 13:37:37 +01:00
|
|
|
)
|
|
|
|
|
2020-11-16 12:52:05 +00:00
|
|
|
func TestMain(m *testing.M) {
|
2021-02-04 17:35:13 +00:00
|
|
|
aghtest.DiscardLogOutput(m)
|
2020-11-16 12:52:05 +00:00
|
|
|
}
|
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
// TestQueryLog tests adding and loading (with filtering) entries from disk and
|
|
|
|
// memory.
|
2020-05-26 13:37:37 +01:00
|
|
|
func TestQueryLog(t *testing.T) {
|
2021-02-09 12:17:02 +00:00
|
|
|
l := newQueryLog(Config{
|
2020-05-28 13:29:36 +01:00
|
|
|
Enabled: true,
|
|
|
|
FileEnabled: true,
|
2021-04-02 15:30:39 +01:00
|
|
|
RotationIvl: 1,
|
2020-05-28 13:29:36 +01:00
|
|
|
MemSize: 100,
|
2021-03-29 09:40:04 +01:00
|
|
|
BaseDir: t.TempDir(),
|
2021-02-09 12:17:02 +00:00
|
|
|
})
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
// Add disk entries.
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "example.org", net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2021-02-09 12:17:02 +00:00
|
|
|
// Write to disk (first file).
|
|
|
|
require.Nil(t, l.flushLogBuffer(true))
|
|
|
|
// Start writing to the second file.
|
|
|
|
require.Nil(t, l.rotate())
|
|
|
|
// Add disk entries.
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "example.org", net.IPv4(1, 1, 1, 2), net.IPv4(2, 2, 2, 2))
|
2021-02-09 12:17:02 +00:00
|
|
|
// Write to disk.
|
|
|
|
require.Nil(t, l.flushLogBuffer(true))
|
|
|
|
// Add memory entries.
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "test.example.org", net.IPv4(1, 1, 1, 3), net.IPv4(2, 2, 2, 3))
|
|
|
|
addEntry(l, "example.com", net.IPv4(1, 1, 1, 4), net.IPv4(2, 2, 2, 4))
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
type tcAssertion struct {
|
|
|
|
num int
|
|
|
|
host string
|
|
|
|
answer, client net.IP
|
|
|
|
}
|
|
|
|
|
|
|
|
testCases := []struct {
|
|
|
|
name string
|
|
|
|
sCr []searchCriteria
|
|
|
|
want []tcAssertion
|
|
|
|
}{{
|
|
|
|
name: "all",
|
|
|
|
sCr: []searchCriteria{},
|
|
|
|
want: []tcAssertion{
|
|
|
|
{num: 0, host: "example.com", answer: net.IPv4(1, 1, 1, 4), client: net.IPv4(2, 2, 2, 4)},
|
|
|
|
{num: 1, host: "test.example.org", answer: net.IPv4(1, 1, 1, 3), client: net.IPv4(2, 2, 2, 3)},
|
|
|
|
{num: 2, host: "example.org", answer: net.IPv4(1, 1, 1, 2), client: net.IPv4(2, 2, 2, 2)},
|
|
|
|
{num: 3, host: "example.org", answer: net.IPv4(1, 1, 1, 1), client: net.IPv4(2, 2, 2, 1)},
|
|
|
|
},
|
|
|
|
}, {
|
|
|
|
name: "by_domain_strict",
|
|
|
|
sCr: []searchCriteria{{
|
|
|
|
criteriaType: ctDomainOrClient,
|
|
|
|
strict: true,
|
|
|
|
value: "TEST.example.org",
|
|
|
|
}},
|
|
|
|
want: []tcAssertion{{
|
|
|
|
num: 0, host: "test.example.org", answer: net.IPv4(1, 1, 1, 3), client: net.IPv4(2, 2, 2, 3),
|
|
|
|
}},
|
|
|
|
}, {
|
|
|
|
name: "by_domain_non-strict",
|
|
|
|
sCr: []searchCriteria{{
|
|
|
|
criteriaType: ctDomainOrClient,
|
|
|
|
strict: false,
|
|
|
|
value: "example.ORG",
|
|
|
|
}},
|
|
|
|
want: []tcAssertion{
|
|
|
|
{num: 0, host: "test.example.org", answer: net.IPv4(1, 1, 1, 3), client: net.IPv4(2, 2, 2, 3)},
|
|
|
|
{num: 1, host: "example.org", answer: net.IPv4(1, 1, 1, 2), client: net.IPv4(2, 2, 2, 2)},
|
|
|
|
{num: 2, host: "example.org", answer: net.IPv4(1, 1, 1, 1), client: net.IPv4(2, 2, 2, 1)},
|
|
|
|
},
|
|
|
|
}, {
|
|
|
|
name: "by_client_ip_strict",
|
|
|
|
sCr: []searchCriteria{{
|
|
|
|
criteriaType: ctDomainOrClient,
|
|
|
|
strict: true,
|
|
|
|
value: "2.2.2.2",
|
|
|
|
}},
|
|
|
|
want: []tcAssertion{{
|
|
|
|
num: 0, host: "example.org", answer: net.IPv4(1, 1, 1, 2), client: net.IPv4(2, 2, 2, 2),
|
|
|
|
}},
|
|
|
|
}, {
|
|
|
|
name: "by_client_ip_non-strict",
|
|
|
|
sCr: []searchCriteria{{
|
|
|
|
criteriaType: ctDomainOrClient,
|
|
|
|
strict: false,
|
|
|
|
value: "2.2.2",
|
|
|
|
}},
|
|
|
|
want: []tcAssertion{
|
|
|
|
{num: 0, host: "example.com", answer: net.IPv4(1, 1, 1, 4), client: net.IPv4(2, 2, 2, 4)},
|
|
|
|
{num: 1, host: "test.example.org", answer: net.IPv4(1, 1, 1, 3), client: net.IPv4(2, 2, 2, 3)},
|
|
|
|
{num: 2, host: "example.org", answer: net.IPv4(1, 1, 1, 2), client: net.IPv4(2, 2, 2, 2)},
|
|
|
|
{num: 3, host: "example.org", answer: net.IPv4(1, 1, 1, 1), client: net.IPv4(2, 2, 2, 1)},
|
|
|
|
},
|
|
|
|
}}
|
|
|
|
|
|
|
|
for _, tc := range testCases {
|
|
|
|
t.Run(tc.name, func(t *testing.T) {
|
|
|
|
params := newSearchParams()
|
|
|
|
params.searchCriteria = tc.sCr
|
|
|
|
|
|
|
|
entries, _ := l.search(params)
|
|
|
|
require.Len(t, entries, len(tc.want))
|
|
|
|
for _, want := range tc.want {
|
|
|
|
assertLogEntry(t, entries[want.num], want.host, want.answer, want.client)
|
|
|
|
}
|
|
|
|
})
|
|
|
|
}
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
func TestQueryLogOffsetLimit(t *testing.T) {
|
2021-02-09 12:17:02 +00:00
|
|
|
l := newQueryLog(Config{
|
2021-04-02 15:30:39 +01:00
|
|
|
Enabled: true,
|
|
|
|
RotationIvl: 1,
|
|
|
|
MemSize: 100,
|
|
|
|
BaseDir: t.TempDir(),
|
2021-02-09 12:17:02 +00:00
|
|
|
})
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
const (
|
|
|
|
entNum = 10
|
|
|
|
firstPageDomain = "first.example.org"
|
|
|
|
secondPageDomain = "second.example.org"
|
|
|
|
)
|
|
|
|
// Add entries to the log.
|
|
|
|
for i := 0; i < entNum; i++ {
|
|
|
|
addEntry(l, secondPageDomain, net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
2021-02-09 12:17:02 +00:00
|
|
|
// Write them to the first file.
|
|
|
|
require.Nil(t, l.flushLogBuffer(true))
|
|
|
|
// Add more to the in-memory part of log.
|
|
|
|
for i := 0; i < entNum; i++ {
|
|
|
|
addEntry(l, firstPageDomain, net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
params := newSearchParams()
|
2021-02-09 12:17:02 +00:00
|
|
|
|
|
|
|
testCases := []struct {
|
|
|
|
name string
|
|
|
|
offset int
|
|
|
|
limit int
|
|
|
|
wantLen int
|
|
|
|
want string
|
|
|
|
}{{
|
|
|
|
name: "page_1",
|
|
|
|
offset: 0,
|
|
|
|
limit: 10,
|
|
|
|
wantLen: 10,
|
|
|
|
want: firstPageDomain,
|
|
|
|
}, {
|
|
|
|
name: "page_2",
|
|
|
|
offset: 10,
|
|
|
|
limit: 10,
|
|
|
|
wantLen: 10,
|
|
|
|
want: secondPageDomain,
|
|
|
|
}, {
|
|
|
|
name: "page_2.5",
|
|
|
|
offset: 15,
|
|
|
|
limit: 10,
|
|
|
|
wantLen: 5,
|
|
|
|
want: secondPageDomain,
|
|
|
|
}, {
|
|
|
|
name: "page_3",
|
|
|
|
offset: 20,
|
|
|
|
limit: 10,
|
|
|
|
wantLen: 0,
|
|
|
|
}}
|
|
|
|
|
|
|
|
for _, tc := range testCases {
|
|
|
|
t.Run(tc.name, func(t *testing.T) {
|
|
|
|
params.offset = tc.offset
|
|
|
|
params.limit = tc.limit
|
|
|
|
entries, _ := l.search(params)
|
|
|
|
|
|
|
|
require.Len(t, entries, tc.wantLen)
|
|
|
|
|
|
|
|
if tc.wantLen > 0 {
|
|
|
|
assert.Equal(t, entries[0].QHost, tc.want)
|
|
|
|
assert.Equal(t, entries[tc.wantLen-1].QHost, tc.want)
|
|
|
|
}
|
|
|
|
})
|
|
|
|
}
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
func TestQueryLogMaxFileScanEntries(t *testing.T) {
|
2021-02-09 12:17:02 +00:00
|
|
|
l := newQueryLog(Config{
|
2020-05-28 13:29:36 +01:00
|
|
|
Enabled: true,
|
|
|
|
FileEnabled: true,
|
2021-04-02 15:30:39 +01:00
|
|
|
RotationIvl: 1,
|
2020-05-28 13:29:36 +01:00
|
|
|
MemSize: 100,
|
2021-03-29 09:40:04 +01:00
|
|
|
BaseDir: t.TempDir(),
|
2021-02-09 12:17:02 +00:00
|
|
|
})
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
const entNum = 10
|
|
|
|
// Add entries to the log.
|
|
|
|
for i := 0; i < entNum; i++ {
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "example.org", net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
2021-02-09 12:17:02 +00:00
|
|
|
// Write them to disk.
|
|
|
|
require.Nil(t, l.flushLogBuffer(true))
|
2020-05-26 13:37:37 +01:00
|
|
|
|
|
|
|
params := newSearchParams()
|
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
for _, maxFileScanEntries := range []int{5, 0} {
|
|
|
|
t.Run(fmt.Sprintf("limit_%d", maxFileScanEntries), func(t *testing.T) {
|
|
|
|
params.maxFileScanEntries = maxFileScanEntries
|
|
|
|
entries, _ := l.search(params)
|
|
|
|
assert.Len(t, entries, entNum-maxFileScanEntries)
|
|
|
|
})
|
|
|
|
}
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
|
|
|
|
2020-05-28 13:29:36 +01:00
|
|
|
func TestQueryLogFileDisabled(t *testing.T) {
|
2021-02-09 12:17:02 +00:00
|
|
|
l := newQueryLog(Config{
|
2020-05-28 13:29:36 +01:00
|
|
|
Enabled: true,
|
|
|
|
FileEnabled: false,
|
2021-04-02 15:30:39 +01:00
|
|
|
RotationIvl: 1,
|
2020-05-28 13:29:36 +01:00
|
|
|
MemSize: 2,
|
2021-03-29 09:40:04 +01:00
|
|
|
BaseDir: t.TempDir(),
|
2021-02-09 12:17:02 +00:00
|
|
|
})
|
2020-05-28 13:29:36 +01:00
|
|
|
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "example1.org", net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
|
|
|
addEntry(l, "example2.org", net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2021-02-09 12:17:02 +00:00
|
|
|
// The oldest entry is going to be removed from memory buffer.
|
2021-01-20 14:27:53 +00:00
|
|
|
addEntry(l, "example3.org", net.IPv4(1, 1, 1, 1), net.IPv4(2, 2, 2, 1))
|
2020-05-28 13:29:36 +01:00
|
|
|
|
|
|
|
params := newSearchParams()
|
|
|
|
ll, _ := l.search(params)
|
2021-02-09 12:17:02 +00:00
|
|
|
require.Len(t, ll, 2)
|
2020-05-28 13:29:36 +01:00
|
|
|
assert.Equal(t, "example3.org", ll[0].QHost)
|
|
|
|
assert.Equal(t, "example2.org", ll[1].QHost)
|
|
|
|
}
|
|
|
|
|
2021-01-20 14:27:53 +00:00
|
|
|
func addEntry(l *queryLog, host string, answerStr, client net.IP) {
|
2021-02-09 12:17:02 +00:00
|
|
|
q := dns.Msg{
|
|
|
|
Question: []dns.Question{{
|
|
|
|
Name: host + ".",
|
|
|
|
Qtype: dns.TypeA,
|
|
|
|
Qclass: dns.ClassINET,
|
|
|
|
}},
|
|
|
|
}
|
2020-05-26 13:37:37 +01:00
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
a := dns.Msg{
|
|
|
|
Question: q.Question,
|
|
|
|
Answer: []dns.RR{&dns.A{
|
|
|
|
Hdr: dns.RR_Header{
|
|
|
|
Name: q.Question[0].Name,
|
|
|
|
Rrtype: dns.TypeA,
|
|
|
|
Class: dns.ClassINET,
|
|
|
|
},
|
|
|
|
A: answerStr,
|
|
|
|
}},
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
2020-11-16 16:45:31 +00:00
|
|
|
res := dnsfilter.Result{
|
|
|
|
IsFiltered: true,
|
2020-12-28 15:41:50 +00:00
|
|
|
Reason: dnsfilter.Rewritten,
|
2020-11-16 16:45:31 +00:00
|
|
|
ServiceName: "SomeService",
|
2020-12-17 10:32:46 +00:00
|
|
|
Rules: []*dnsfilter.ResultRule{{
|
|
|
|
FilterListID: 1,
|
|
|
|
Text: "SomeRule",
|
|
|
|
}},
|
2020-11-16 16:45:31 +00:00
|
|
|
}
|
2020-05-26 13:37:37 +01:00
|
|
|
params := AddParams{
|
2020-11-16 16:45:31 +00:00
|
|
|
Question: &q,
|
|
|
|
Answer: &a,
|
|
|
|
OrigAnswer: &a,
|
|
|
|
Result: &res,
|
2021-01-20 14:27:53 +00:00
|
|
|
ClientIP: client,
|
2020-11-16 16:45:31 +00:00
|
|
|
Upstream: "upstream",
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
|
|
|
l.Add(params)
|
|
|
|
}
|
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
func assertLogEntry(t *testing.T, entry *logEntry, host string, answer, client net.IP) {
|
|
|
|
t.Helper()
|
|
|
|
|
|
|
|
require.NotNil(t, entry)
|
|
|
|
|
2020-05-26 13:37:37 +01:00
|
|
|
assert.Equal(t, host, entry.QHost)
|
|
|
|
assert.Equal(t, client, entry.IP)
|
|
|
|
assert.Equal(t, "A", entry.QType)
|
|
|
|
assert.Equal(t, "IN", entry.QClass)
|
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
msg := &dns.Msg{}
|
|
|
|
require.Nil(t, msg.Unpack(entry.Answer))
|
|
|
|
require.Len(t, msg.Answer, 1)
|
|
|
|
|
2021-01-20 14:27:53 +00:00
|
|
|
ip := proxyutil.GetIPFromDNSRecord(msg.Answer[0]).To16()
|
|
|
|
assert.Equal(t, answer, ip)
|
2020-05-26 13:37:37 +01:00
|
|
|
}
|
2020-11-30 10:32:58 +00:00
|
|
|
|
|
|
|
func testEntries() (entries []*logEntry) {
|
|
|
|
rsrc := rand.NewSource(time.Now().UnixNano())
|
|
|
|
rgen := rand.New(rsrc)
|
|
|
|
|
|
|
|
entries = make([]*logEntry, 1000)
|
|
|
|
for i := range entries {
|
|
|
|
min := rgen.Intn(60)
|
|
|
|
sec := rgen.Intn(60)
|
|
|
|
entries[i] = &logEntry{
|
|
|
|
Time: time.Date(2020, 1, 1, 0, min, sec, 0, time.UTC),
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
return entries
|
|
|
|
}
|
|
|
|
|
|
|
|
// logEntriesByTimeDesc is a wrapper over []*logEntry for sorting.
|
|
|
|
//
|
|
|
|
// NOTE(a.garipov): Weirdly enough, on my machine this gets consistently
|
|
|
|
// outperformed by sort.Slice, see the benchmark below. I'm leaving this
|
|
|
|
// implementation here, in tests, in case we want to make sure it outperforms on
|
|
|
|
// most machines, but for now this is unused in the actual code.
|
|
|
|
type logEntriesByTimeDesc []*logEntry
|
|
|
|
|
|
|
|
// Len implements the sort.Interface interface for logEntriesByTimeDesc.
|
|
|
|
func (les logEntriesByTimeDesc) Len() (n int) { return len(les) }
|
|
|
|
|
|
|
|
// Less implements the sort.Interface interface for logEntriesByTimeDesc.
|
|
|
|
func (les logEntriesByTimeDesc) Less(i, j int) (less bool) {
|
|
|
|
return les[i].Time.After(les[j].Time)
|
|
|
|
}
|
|
|
|
|
|
|
|
// Swap implements the sort.Interface interface for logEntriesByTimeDesc.
|
|
|
|
func (les logEntriesByTimeDesc) Swap(i, j int) { les[i], les[j] = les[j], les[i] }
|
|
|
|
|
|
|
|
func BenchmarkLogEntry_sort(b *testing.B) {
|
|
|
|
b.Run("methods", func(b *testing.B) {
|
|
|
|
for i := 0; i < b.N; i++ {
|
|
|
|
b.StopTimer()
|
|
|
|
entries := testEntries()
|
|
|
|
b.StartTimer()
|
|
|
|
|
|
|
|
sort.Stable(logEntriesByTimeDesc(entries))
|
|
|
|
}
|
|
|
|
})
|
|
|
|
|
|
|
|
b.Run("reflect", func(b *testing.B) {
|
|
|
|
for i := 0; i < b.N; i++ {
|
|
|
|
b.StopTimer()
|
|
|
|
entries := testEntries()
|
|
|
|
b.StartTimer()
|
|
|
|
|
|
|
|
sort.SliceStable(entries, func(i, j int) (less bool) {
|
|
|
|
return entries[i].Time.After(entries[j].Time)
|
|
|
|
})
|
|
|
|
}
|
|
|
|
})
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestLogEntriesByTime_sort(t *testing.T) {
|
|
|
|
entries := testEntries()
|
|
|
|
sort.Sort(logEntriesByTimeDesc(entries))
|
|
|
|
|
2021-02-09 12:17:02 +00:00
|
|
|
for i := range entries[1:] {
|
|
|
|
assert.False(t, entries[i+1].Time.After(entries[i].Time),
|
|
|
|
"%s %s", entries[i+1].Time, entries[i].Time)
|
2020-11-30 10:32:58 +00:00
|
|
|
}
|
|
|
|
}
|