Pull request: AGDNS-2202-slog-proxy vol.2

Squashed commit of the following:

commit c11bc0e3ec7b6b03cafefa306fb4a69c8980ed4f
Author: Dimitry Kolyshev <[email protected]>
Date:   Fri Jun 21 13:39:12 2024 +0300

    proxy: imp code

commit 8408a3c79411207c286893d9e9a148f537e2d507
Author: Dimitry Kolyshev <[email protected]>
Date:   Fri Jun 21 10:09:41 2024 +0300

    proxy: imp code

commit 2266064e8f5b4bc210c5176e62638e321ef069a3
Author: Dimitry Kolyshev <[email protected]>
Date:   Fri Jun 21 09:55:20 2024 +0300

    proxy: imp code

commit 9b1a32ceec242edc618e6fa3351c72d626ab8d63
Author: Dimitry Kolyshev <[email protected]>
Date:   Fri Jun 21 09:39:43 2024 +0300

    proxy: imp code

commit 296019d27929dd2a27f22fe3d7c0791868b8a7c7
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 12:20:00 2024 +0300

    proxy: imp code

commit 1e83cf522b2bdfdb5fbf3ba911fece16c5808713
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 12:09:16 2024 +0300

    proxy: imp code

commit 9703fd4d89b9f488cff4515a798d13534088eb3f
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 11:51:39 2024 +0300

    proxy: imp code

commit cb0deeffa8eb72ca8c22ce28e9392f1f29f2cffe
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 11:34:37 2024 +0300

    proxy: imp code

commit 6729b94900821032858731ab3ebbcff52878ae12
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 11:22:07 2024 +0300

    proxy: imp code

commit 493547822e52610ed042c629a22fb2489bf7ddf5
Author: Dimitry Kolyshev <[email protected]>
Date:   Thu Jun 20 11:18:47 2024 +0300

    proxy: imp code

commit 44941283e7a42d3bf21d32d38acf0a20f073a6cd
Author: Dimitry Kolyshev <[email protected]>
Date:   Wed Jun 19 12:20:06 2024 +0300

    proxy: imp tests

commit 109a93d0e34fdde51a342a956881d5b04a4faa28
Author: Dimitry Kolyshev <[email protected]>
Date:   Wed Jun 19 11:36:34 2024 +0300

    proxy: imp tests

commit 802a282847c20f3d2725b9651a9e18fa35e08b3d
Author: Dimitry Kolyshev <[email protected]>
Date:   Wed Jun 19 11:13:01 2024 +0300

    proxy: imp code

commit 48f88302dba3e6dc918b4db60c3c50bd6d68f254
Author: Dimitry Kolyshev <[email protected]>
Date:   Tue Jun 18 15:50:25 2024 +0300

    proxy: slog

commit 22e1bb2d80f5bebff7fb72de9519e6b823f31a6b
Author: Dimitry Kolyshev <[email protected]>
Date:   Tue Jun 18 12:23:24 2024 +0300

    proxy: slog

commit da68b56d6afe1218a9887ce3db22ecf00de5fe66
Author: Dimitry Kolyshev <[email protected]>
Date:   Tue Jun 18 12:05:56 2024 +0300

    proxy: slog

commit 3815033f320f08ff7245f100cf83fdafacb6e677
Author: Dimitry Kolyshev <[email protected]>
Date:   Tue Jun 18 12:04:06 2024 +0300

    proxy: slog

commit 1e9569c4da132765f5de6f0d005a4247fff83762
Author: Dimitry Kolyshev <[email protected]>
Date:   Tue Jun 18 11:04:50 2024 +0300

    proxy: slog

commit 0d1460830f80d79307ae08d66cb2f164a2a6f4de
Author: Dimitry Kolyshev <[email protected]>
Date:   Mon Jun 17 14:35:38 2024 +0300

    proxy: imp tests
This commit is contained in:
Dimitry Kolyshev
2024-06-21 13:51:14 +03:00
parent 3d768a70de
commit 1e1fb3d7b9
16 changed files with 221 additions and 165 deletions
+32 -3
View File
@@ -29,6 +29,7 @@ import (
"github.com/AdguardTeam/golibs/timeutil"
"github.com/ameshkov/dnscrypt/v2"
goFlags "github.com/jessevdk/go-flags"
"github.com/miekg/dns"
"gopkg.in/yaml.v3"
)
@@ -365,8 +366,11 @@ func runProxy(ctx context.Context, l *slog.Logger, options *Options) (err error)
// Add extra handler if needed.
if options.IPv6Disabled {
ipv6Configuration := ipv6Configuration{ipv6Disabled: options.IPv6Disabled}
dnsProxy.RequestHandler = ipv6Configuration.handleDNSRequest
ipv6Config := ipv6Configuration{
logger: l,
ipv6Disabled: options.IPv6Disabled,
}
dnsProxy.RequestHandler = ipv6Config.handleDNSRequest
}
// Start the proxy server.
@@ -519,6 +523,7 @@ func (opts *Options) initUpstreams(
}
upsOpts := &upstream.Options{
Logger: l,
HTTPVersions: httpVersions,
InsecureSkipVerify: opts.Insecure,
Bootstrap: boot,
@@ -532,6 +537,7 @@ func (opts *Options) initUpstreams(
}
privateUpsOpts := &upstream.Options{
Logger: l,
HTTPVersions: httpVersions,
Bootstrap: boot,
Timeout: min(defaultLocalTimeout, timeout),
@@ -835,6 +841,9 @@ func (opts *Options) initPrivateSubnets(conf *proxy.Config) (err error) {
// ipv6Configuration represents IPv6 configuration.
type ipv6Configuration struct {
// logger is used for logging during requests handling. It is never nil.
logger *slog.Logger
// ipv6Disabled set all AAAA requests to be replied with NoError RCode and
// an empty answer.
ipv6Disabled bool
@@ -843,13 +852,33 @@ type ipv6Configuration struct {
// handleDNSRequest checks the IPv6 configuration for current session before
// resolving.
func (c *ipv6Configuration) handleDNSRequest(p *proxy.Proxy, ctx *proxy.DNSContext) (err error) {
if proxy.CheckDisabledAAAARequest(ctx, c.ipv6Disabled) {
if !c.isIPv6Enabled(ctx, !c.ipv6Disabled) {
return nil
}
return p.Resolve(ctx)
}
// retryNoError is the time for NoError SOA.
const retryNoError = 60
// isIPv6Enabled checks if AAAA requests should be enabled or not and sets
// NoError empty response to the given DNSContext if needed.
func (c *ipv6Configuration) isIPv6Enabled(ctx *proxy.DNSContext, ipv6Enabled bool) (enabled bool) {
if !ipv6Enabled && ctx.Req.Question[0].Qtype == dns.TypeAAAA {
c.logger.Debug(
"ipv6 is disabled; replying with empty response",
"req", ctx.Req.Question[0].Name,
)
ctx.Res = proxy.GenEmptyMessage(ctx.Req, dns.RcodeSuccess, retryNoError)
return false
}
return true
}
// NewTLSConfig returns the TLS config that includes a certificate. Use it for
// server TLS configuration or for a client certificate. If caPath is empty,
// system CAs will be used.
+12 -23
View File
@@ -13,7 +13,6 @@ import (
"github.com/AdguardTeam/dnsproxy/upstream"
glcache "github.com/AdguardTeam/golibs/cache"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/mathutil"
"github.com/miekg/dns"
)
@@ -35,11 +34,6 @@ type cache struct {
// itemsWithSubnet is the requests cache.
itemsWithSubnet glcache.Cache
// logger is used for logging in the cache. It is never nil.
//
// TODO(a.garipov): Consider removing logger from cache.
logger *slog.Logger
// optimistic defines if the cache should return expired items and resolve
// those again.
optimistic bool
@@ -60,9 +54,9 @@ type cacheItem struct {
}
// respToItem converts the pair of the response and upstream resolved the one
// into item for storing it in cache.
func (c *cache) respToItem(m *dns.Msg, u upstream.Upstream) (item *cacheItem) {
ttl := cacheTTL(m, c.logger)
// into item for storing it in cache. l must not be nil.
func (c *cache) respToItem(m *dns.Msg, u upstream.Upstream, l *slog.Logger) (item *cacheItem) {
ttl := cacheTTL(m, l)
if ttl == 0 {
return nil
}
@@ -181,22 +175,16 @@ func (p *Proxy) initCache() {
size := p.CacheSizeBytes
p.logger.Info("cache enabled", "size", size)
p.cache = newCache(
size,
p.EnableEDNSClientSubnet,
p.CacheOptimistic,
p.logger.With(slogutil.KeyPrefix, CacheLogPrefix),
)
p.cache = newCache(size, p.EnableEDNSClientSubnet, p.CacheOptimistic)
p.shortFlighter = newOptimisticResolver(p)
}
// newCache returns a properly initialized cache. logger must not be nil.
func newCache(size int, withECS, optimistic bool, logger *slog.Logger) (c *cache) {
func newCache(size int, withECS, optimistic bool) (c *cache) {
c = &cache{
itemsLock: &sync.RWMutex{},
itemsWithSubnetLock: &sync.RWMutex{},
items: createCache(size),
logger: logger,
optimistic: optimistic,
}
@@ -311,9 +299,9 @@ func createCache(cacheSize int) (glc glcache.Cache) {
return glcache.New(conf)
}
// set stores response and upstream in the cache.
func (c *cache) set(m *dns.Msg, u upstream.Upstream) {
item := c.respToItem(m, u)
// set stores response and upstream in the cache. l must not be nil.
func (c *cache) set(m *dns.Msg, u upstream.Upstream, l *slog.Logger) {
item := c.respToItem(m, u, l)
if item == nil {
return
}
@@ -328,9 +316,10 @@ func (c *cache) set(m *dns.Msg, u upstream.Upstream) {
}
// setWithSubnet stores response and upstream with subnet in the cache. The
// given subnet mask and IP address are used to calculate the cache key.
func (c *cache) setWithSubnet(m *dns.Msg, u upstream.Upstream, subnet *net.IPNet) {
item := c.respToItem(m, u)
// given subnet mask and IP address are used to calculate the cache key. l must
// not be nil.
func (c *cache) setWithSubnet(m *dns.Msg, u upstream.Upstream, subnet *net.IPNet, l *slog.Logger) {
item := c.respToItem(m, u, l)
if item == nil {
return
}
+31 -23
View File
@@ -2,7 +2,6 @@ package proxy
import (
"context"
"log/slog"
"net"
"net/netip"
"strings"
@@ -11,6 +10,7 @@ import (
"time"
"github.com/AdguardTeam/dnsproxy/upstream"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil"
"github.com/AdguardTeam/golibs/testutil"
"github.com/stretchr/testify/assert"
@@ -56,7 +56,7 @@ func TestServeCached(t *testing.T) {
}).SetQuestion("google.com.", dns.TypeA)
reply.SetEdns0(defaultUDPBufSize, false)
dnsProxy.cache.set(reply, upstreamWithAddr)
dnsProxy.cache.set(reply, upstreamWithAddr, slogutil.NewDiscardLogger())
// Create a DNS-over-UDP client connection.
addr := dnsProxy.Addr(ProtoUDP)
@@ -120,7 +120,7 @@ func TestCache_expired(t *testing.T) {
optimistic: true,
}}
testCache := newCache(testCacheSize, false, false, slog.Default())
testCache := newCache(testCacheSize, false, false)
for _, tc := range testCases {
ans.Hdr.Ttl = tc.ttl
req := (&dns.Msg{}).SetQuestion(host, dns.TypeA)
@@ -157,7 +157,7 @@ func TestCache_expired(t *testing.T) {
}
func TestCacheDO(t *testing.T) {
testCache := newCache(testCacheSize, false, false, slog.Default())
testCache := newCache(testCacheSize, false, false)
// Fill the cache.
reply := (&dns.Msg{
@@ -169,7 +169,7 @@ func TestCacheDO(t *testing.T) {
reply.SetEdns0(4096, true)
// Store in cache.
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, slogutil.NewDiscardLogger())
// Make a request.
request := (&dns.Msg{}).SetQuestion("google.com.", dns.TypeA)
@@ -200,7 +200,9 @@ func TestCacheDO(t *testing.T) {
}
func TestCacheCNAME(t *testing.T) {
testCache := newCache(testCacheSize, false, false, slog.Default())
l := slogutil.NewDiscardLogger()
testCache := newCache(testCacheSize, false, false)
// Fill the cache
reply := (&dns.Msg{
@@ -209,7 +211,7 @@ func TestCacheCNAME(t *testing.T) {
},
Answer: []dns.RR{newRR(t, "google.com.", dns.TypeCNAME, 3600, "test.google.com.")},
}).SetQuestion("google.com.", dns.TypeA)
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, l)
// Create a DNS request.
request := (&dns.Msg{}).SetQuestion("google.com.", dns.TypeA)
@@ -222,7 +224,7 @@ func TestCacheCNAME(t *testing.T) {
// Now fill the cache with a cacheable CNAME response.
reply.Answer = append(reply.Answer, newRR(t, "google.com.", dns.TypeA, 3600, net.IP{8, 8, 8, 8}))
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, l)
// We are testing that a proper CNAME response gets cached
t.Run("cnames_exist", func(t *testing.T) {
@@ -237,7 +239,7 @@ func TestCacheCNAME(t *testing.T) {
}
func TestCache_uncacheable(t *testing.T) {
testCache := newCache(testCacheSize, false, false, slog.Default())
testCache := newCache(testCacheSize, false, false)
// Create a DNS request.
request := (&dns.Msg{}).SetQuestion("google.com.", dns.TypeA)
@@ -245,7 +247,7 @@ func TestCache_uncacheable(t *testing.T) {
reply := (&dns.Msg{}).SetRcode(request, dns.RcodeBadAlg)
// We are testing that SERVFAIL responses aren't cached
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, slogutil.NewDiscardLogger())
r, expired, _ := testCache.get(request)
assert.Nil(t, r)
@@ -253,7 +255,7 @@ func TestCache_uncacheable(t *testing.T) {
}
func TestCache_concurrent(t *testing.T) {
testCache := newCache(testCacheSize, false, false, slog.Default())
testCache := newCache(testCacheSize, false, false)
hosts := map[string]string{
dns.Fqdn("yandex.com"): "213.180.204.62",
@@ -276,7 +278,7 @@ func TestCache_concurrent(t *testing.T) {
const (
// cacheTick is a cache check period.
cacheTick = 50 * time.Millisecond
cacheTick = 100 * time.Millisecond
// cacheTimeout is the timeout of cache check.
cacheTimeout = 20 * cacheTick
@@ -300,6 +302,8 @@ func TestCacheExpiration(t *testing.T) {
require.NoError(t, err)
testutil.CleanupAndRequireSuccess(t, func() (err error) { return dnsProxy.Shutdown(ctx) })
l := slogutil.NewDiscardLogger()
// Create dns messages with TTL of 1 second.
rrs := []dns.RR{
newRR(t, "youtube.com.", dns.TypeA, 1, net.IP{173, 194, 221, 198}),
@@ -314,7 +318,7 @@ func TestCacheExpiration(t *testing.T) {
},
Answer: []dns.RR{dns.Copy(rr)},
}).SetQuestion(rr.Header().Name, dns.TypeA)
dnsProxy.cache.set(rep, upstreamWithAddr)
dnsProxy.cache.set(rep, upstreamWithAddr, l)
replies[i] = rep
}
@@ -526,7 +530,9 @@ func TestCache(t *testing.T) {
}
func (tests testCases) run(t *testing.T) {
testCache := newCache(testCacheSize, false, false, slog.Default())
l := slogutil.NewDiscardLogger()
testCache := newCache(testCacheSize, false, false)
for _, res := range tests.cache {
reply := (&dns.Msg{
@@ -535,7 +541,7 @@ func (tests testCases) run(t *testing.T) {
},
Answer: res.a,
}).SetQuestion(res.q, res.t)
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, l)
}
for _, tc := range tests.cases {
@@ -558,7 +564,7 @@ func (tests testCases) run(t *testing.T) {
Answer: tc.a,
}).SetQuestion(tc.q, tc.t)
testCache.set(reply, upstreamWithAddr)
testCache.set(reply, upstreamWithAddr, l)
requireEqualMsgs(t, ci.m, reply)
}
@@ -605,7 +611,7 @@ func setAndGetCache(t *testing.T, c *cache, g *sync.WaitGroup, host, ip string)
Answer: []dns.RR{newRR(t, host, dns.TypeA, 1, ipAddr)},
}).SetQuestion(host, dns.TypeA)
c.set(dnsMsg, upstreamWithAddr)
c.set(dnsMsg, upstreamWithAddr, slogutil.NewDiscardLogger())
for range 2 {
ci, expired, key := c.get(dnsMsg)
@@ -631,8 +637,9 @@ func TestCache_getWithSubnet(t *testing.T) {
req := (&dns.Msg{}).SetQuestion(testFQDN, dns.TypeA)
mask16 := net.CIDRMask(16, netutil.IPv4BitLen)
mask24 := net.CIDRMask(24, netutil.IPv4BitLen)
l := slogutil.NewDiscardLogger()
c := newCache(testCacheSize, true, false, slog.Default())
c := newCache(testCacheSize, true, false)
t.Run("empty", func(t *testing.T) {
ci, expired, _ := c.getWithSubnet(req, &net.IPNet{IP: ip1234, Mask: mask24})
@@ -644,7 +651,7 @@ func TestCache_getWithSubnet(t *testing.T) {
resp := (&dns.Msg{
Answer: []dns.RR{newRR(t, testFQDN, dns.TypeA, 1, net.IP{1, 1, 1, 1})},
}).SetReply(req)
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: ip1234, Mask: mask16})
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: ip1234, Mask: mask16}, slogutil.NewDiscardLogger())
t.Run("different_ip", func(t *testing.T) {
ci, expired, key := c.getWithSubnet(req, &net.IPNet{IP: ip2234, Mask: mask24})
@@ -657,13 +664,13 @@ func TestCache_getWithSubnet(t *testing.T) {
resp = (&dns.Msg{
Answer: []dns.RR{newRR(t, testFQDN, dns.TypeA, 1, net.IP{2, 2, 2, 2})},
}).SetReply(req)
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: ip2234, Mask: mask16})
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: ip2234, Mask: mask16}, l)
// Add a response entry without subnet.
resp = (&dns.Msg{
Answer: []dns.RR{newRR(t, testFQDN, dns.TypeA, 1, net.IP{3, 3, 3, 3})},
}).SetReply(req)
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: nil, Mask: nil})
c.setWithSubnet(resp, upstreamWithAddr, &net.IPNet{IP: nil, Mask: nil}, l)
t.Run("with_subnet_1", func(t *testing.T) {
ci, expired, key := c.getWithSubnet(req, &net.IPNet{IP: ip1234, Mask: mask24})
@@ -718,7 +725,7 @@ func TestCache_getWithSubnet_mask(t *testing.T) {
ansIP := net.IP{4, 4, 4, 4}
c := newCache(testCacheSize, true, true, slog.Default())
c := newCache(testCacheSize, true, true)
req := (&dns.Msg{}).SetQuestion(testFQDN, dns.TypeA)
resp := (&dns.Msg{
@@ -730,6 +737,7 @@ func TestCache_getWithSubnet_mask(t *testing.T) {
resp,
upstreamWithAddr,
&net.IPNet{IP: cachedIP, Mask: cidrMask},
slogutil.NewDiscardLogger(),
)
t.Run("mask_matched", func(t *testing.T) {
@@ -957,7 +965,7 @@ func TestCache_IsCacheable_negative(t *testing.T) {
for _, tc := range testCases {
t.Run(tc.name, func(t *testing.T) {
assert.Equal(t, tc.wantTTL, cacheTTL(tc.req, slog.Default()))
assert.Equal(t, tc.wantTTL, cacheTTL(tc.req, slogutil.NewDiscardLogger()))
})
}
}
+1 -6
View File
@@ -1,8 +1,6 @@
package proxy
import (
"cmp"
"log/slog"
"net"
"net/http"
"net/netip"
@@ -202,14 +200,11 @@ func NewCustomUpstreamConfig(
cacheEnabled bool,
cacheSize int,
enableEDNSClientSubnet bool,
cacheLogger *slog.Logger,
) (c *CustomUpstreamConfig) {
var customCache *cache
if cacheEnabled {
logger := cmp.Or(cacheLogger, slog.Default())
// TODO(d.kolyshev): Support optimistic with newOptimisticResolver.
customCache = newCache(cacheSize, enableEDNSClientSubnet, false, logger)
customCache = newCache(cacheSize, enableEDNSClientSubnet, false)
}
return &CustomUpstreamConfig{
+22 -18
View File
@@ -6,7 +6,7 @@ import (
"github.com/AdguardTeam/dnsproxy/upstream"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/miekg/dns"
"gonum.org/v1/gonum/stat/sampleuv"
)
@@ -34,7 +34,7 @@ func (p *Proxy) exchangeUpstreams(
if len(ups) == 1 {
u = ups[0]
resp, _, err = exchange(u, req, p.time)
resp, _, err = p.exchange(u, req, p.time)
// TODO(e.burkov): p.updateRTT(u.Address(), elapsed)
return resp, u, err
@@ -46,7 +46,7 @@ func (p *Proxy) exchangeUpstreams(
u = ups[i]
var elapsed time.Duration
resp, elapsed, err = exchange(u, req, p.time)
resp, elapsed, err = p.exchange(u, req, p.time)
if err == nil {
p.updateRTT(u.Address(), elapsed)
@@ -68,33 +68,37 @@ func (p *Proxy) exchangeUpstreams(
// exchange returns the result of the DNS request exchange with the given
// upstream and the elapsed time in milliseconds. It uses the given clock to
// measure the request duration.
func exchange(u upstream.Upstream, req *dns.Msg, c clock) (resp *dns.Msg, dur time.Duration, err error) {
func (p *Proxy) exchange(
u upstream.Upstream,
req *dns.Msg,
c clock,
) (resp *dns.Msg, dur time.Duration, err error) {
startTime := c.Now()
reply, err := u.Exchange(req)
resp, err = u.Exchange(req)
// Don't use [time.Since] because it uses [time.Now].
dur = c.Now().Sub(startTime)
addr := u.Address()
q := &req.Question[0]
if err != nil {
log.Error(
"dnsproxy: upstream %s failed to exchange %s in %s: %s",
addr,
req.Question[0].String(),
dur,
err,
p.logger.Error(
"exchange failed",
"upstream", addr,
"question", q,
"duration", dur,
slogutil.KeyError, err,
)
} else {
log.Debug(
"dnsproxy: upstream %s successfully finished exchange of %s; elapsed %s",
addr,
req.Question[0].String(),
dur,
p.logger.Debug(
"exchange successfully finished",
"upstream", addr,
"question", q,
"duration", dur,
)
}
return reply, dur, err
return resp, dur, err
}
// upstreamRTTStats is the statistics for a single upstream's round-trip time.
+6 -9
View File
@@ -3,18 +3,20 @@ package proxy
import (
"net"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/netutil"
"github.com/miekg/dns"
)
const retryNoError = 60 // Retry time for NoError SOA
// CheckDisabledAAAARequest checks if AAAA requests should be disabled or not and sets NoError empty response to given DNSContext if needed
// CheckDisabledAAAARequest checks if AAAA requests should be disabled or not
// and sets NoError empty response to given DNSContext if needed.
//
// Deprecated: Use [RequestHandler] instead.
func CheckDisabledAAAARequest(ctx *DNSContext, ipv6Disabled bool) bool {
if ipv6Disabled && ctx.Req.Question[0].Qtype == dns.TypeAAAA {
log.Debug("IPv6 is disabled. Reply with NoError to %s AAAA request", ctx.Req.Question[0].Name)
ctx.Res = genEmptyNoError(ctx.Req)
ctx.Res = GenEmptyMessage(ctx.Req, dns.RcodeSuccess, retryNoError)
return true
}
@@ -30,11 +32,6 @@ func GenEmptyMessage(request *dns.Msg, rCode int, retry uint32) *dns.Msg {
return &resp
}
// genEmptyNoError returns response without answer and NoError RCode
func genEmptyNoError(request *dns.Msg) *dns.Msg {
return GenEmptyMessage(request, dns.RcodeSuccess, retryNoError)
}
// genSOA returns SOA for an authority section
func genSOA(request *dns.Msg, retry uint32) []dns.RR {
zone := ""
+15 -7
View File
@@ -8,7 +8,7 @@ import (
"github.com/AdguardTeam/dnsproxy/proxyutil"
"github.com/AdguardTeam/dnsproxy/upstream"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil"
"github.com/miekg/dns"
)
@@ -21,15 +21,23 @@ type lookupResult struct {
// lookupIPAddr resolves the specified host IP addresses. It is intended to be
// used as a goroutine.
func (p *Proxy) lookupIPAddr(host string, qtype uint16, ch chan *lookupResult) {
defer log.OnPanic("Proxy.lookupIPAddr")
func (p *Proxy) lookupIPAddr(
ctx context.Context,
host string,
qtype uint16,
ch chan *lookupResult,
) {
defer slogutil.RecoverAndLog(ctx, p.logger)
req := (&dns.Msg{}).SetQuestion(host, qtype)
// TODO(d.kolyshev): Investigate why the client address is not defined.
d := p.newDNSContext(ProtoUDP, req, netip.AddrPort{})
err := p.Resolve(d)
ch <- &lookupResult{d.Res, err}
ch <- &lookupResult{
resp: d.Res,
err: err,
}
}
// ErrEmptyHost is returned by LookupIPAddr when the host is empty and can't be
@@ -43,7 +51,7 @@ var _ upstream.Resolver = (*Proxy)(nil)
// resolves the specified host IP addresses by sending two DNS queries (A and
// AAAA) in parallel. It returns both results for those two queries.
func (p *Proxy) LookupNetIP(
_ context.Context,
ctx context.Context,
_ string,
host string,
) (addrs []netip.Addr, err error) {
@@ -54,8 +62,8 @@ func (p *Proxy) LookupNetIP(
host = dns.Fqdn(host)
ch := make(chan *lookupResult)
go p.lookupIPAddr(host, dns.TypeA, ch)
go p.lookupIPAddr(host, dns.TypeAAAA, ch)
go p.lookupIPAddr(ctx, host, dns.TypeA, ch)
go p.lookupIPAddr(ctx, host, dns.TypeAAAA, ch)
var errs []error
for range 2 {
+7 -5
View File
@@ -1,10 +1,12 @@
package proxy
import (
"context"
"encoding/hex"
"log/slog"
"sync"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
)
// cachingResolver is the DNS resolver that is also able to cache responses.
@@ -40,12 +42,12 @@ func newOptimisticResolver(cr cachingResolver) (s *optimisticResolver) {
// unit is a convenient alias for struct{}.
type unit = struct{}
// ResolveOnce tries to resolve the request from dctx but only a single request
// resolveOnce tries to resolve the request from dctx but only a single request
// with the same key at the same period of time. It runs in a separate
// goroutine. Do not pass the *DNSContext which is used elsewhere since it
// isn't intended to be used concurrently.
func (s *optimisticResolver) ResolveOnce(dctx *DNSContext, key []byte) {
defer log.OnPanic("optimistic resolver")
func (s *optimisticResolver) resolveOnce(dctx *DNSContext, key []byte, l *slog.Logger) {
defer slogutil.RecoverAndLog(context.TODO(), l)
keyHexed := hex.EncodeToString(key)
if _, ok := s.reqs.LoadOrStore(keyHexed, unit{}); ok {
@@ -55,7 +57,7 @@ func (s *optimisticResolver) ResolveOnce(dctx *DNSContext, key []byte) {
ok, err := s.cr.replyFromUpstream(dctx)
if err != nil {
log.Debug("resolving request for optimistic cache: %s", err)
l.Debug("resolving request for optimistic cache", slogutil.KeyError, err)
}
if ok {
+18 -17
View File
@@ -2,11 +2,12 @@ package proxy
import (
"bytes"
"log/slog"
"sync"
"testing"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/stretchr/testify/assert"
)
@@ -52,7 +53,7 @@ func TestOptimisticResolver_ResolveOnce(t *testing.T) {
sameKey := []byte{1, 2, 3}
// Start the primary goroutine.
go s.ResolveOnce(nil, sameKey)
go s.resolveOnce(nil, sameKey, slogutil.NewDiscardLogger())
// Block until the primary goroutine reaches the resolve function.
<-out
@@ -64,7 +65,7 @@ func TestOptimisticResolver_ResolveOnce(t *testing.T) {
go func() {
defer wg.Done()
s.ResolveOnce(nil, sameKey)
s.resolveOnce(nil, sameKey, slogutil.NewDiscardLogger())
}()
}
@@ -81,25 +82,25 @@ func TestOptimisticResolver_ResolveOnce_unsuccessful(t *testing.T) {
key := []byte{1, 2, 3}
t.Run("error", func(t *testing.T) {
// TODO(d.kolyshev): Consider adding mock handler to golibs.
logOutput := &bytes.Buffer{}
l := slog.New(slog.NewTextHandler(logOutput, &slog.HandlerOptions{
AddSource: false,
Level: slog.LevelDebug,
ReplaceAttr: nil,
}))
prevLevel := log.GetLevel()
prevOutput := log.Writer()
log.SetLevel(log.DEBUG)
log.SetOutput(logOutput)
t.Cleanup(func() {
log.SetLevel(prevLevel)
log.SetOutput(prevOutput)
})
const rErr errors.Error = "sample resolving error"
const rerr errors.Error = "sample resolving error"
cached := false
s := newOptimisticResolver(&testCachingResolver{
onReplyFromUpstream: func(_ *DNSContext) (ok bool, err error) { return true, rerr },
onCacheResp: func(_ *DNSContext) {},
onReplyFromUpstream: func(_ *DNSContext) (ok bool, err error) { return true, rErr },
onCacheResp: func(_ *DNSContext) { cached = true },
})
s.ResolveOnce(nil, key)
s.resolveOnce(nil, key, l)
assert.Contains(t, logOutput.String(), rerr.Error())
assert.True(t, cached)
assert.Contains(t, logOutput.String(), rErr.Error())
})
t.Run("not_ok", func(t *testing.T) {
@@ -108,7 +109,7 @@ func TestOptimisticResolver_ResolveOnce_unsuccessful(t *testing.T) {
onReplyFromUpstream: func(_ *DNSContext) (ok bool, err error) { return false, nil },
onCacheResp: func(_ *DNSContext) { cached = true },
})
s.ResolveOnce(nil, key)
s.resolveOnce(nil, key, slogutil.NewDiscardLogger())
assert.False(t, cached)
})
+11 -10
View File
@@ -8,7 +8,6 @@ import (
"crypto/x509"
"crypto/x509/pkix"
"encoding/pem"
"log/slog"
"math/big"
"net"
"net/netip"
@@ -19,6 +18,7 @@ import (
"github.com/AdguardTeam/dnsproxy/upstream"
glcache "github.com/AdguardTeam/golibs/cache"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil"
"github.com/AdguardTeam/golibs/testutil"
"github.com/miekg/dns"
@@ -230,6 +230,7 @@ func newTestUpstreamConfigWithBoot(
require.NoError(t, err)
upsConf, err := ParseUpstreamsConfig(addrs, &upstream.Options{
Logger: slogutil.NewDiscardLogger(),
Timeout: timeout,
Bootstrap: upstream.NewCachingResolver(googleRslv),
})
@@ -247,7 +248,10 @@ func newTestUpstreamConfig(
) (u *UpstreamConfig) {
t.Helper()
upsConf, err := ParseUpstreamsConfig(addrs, &upstream.Options{Timeout: timeout})
upsConf, err := ParseUpstreamsConfig(addrs, &upstream.Options{
Logger: slogutil.NewDiscardLogger(),
Timeout: timeout,
})
require.NoError(t, err)
return upsConf
@@ -832,10 +836,10 @@ func TestFallbackFromInvalidBootstrap(t *testing.T) {
require.NoError(t, err)
// Prepare the proxy server
upsConf, err := ParseUpstreamsConfig(
[]string{"tls://dns.adguard.com"},
&upstream.Options{Bootstrap: invalidRslv, Timeout: testTimeout},
)
upsConf, err := ParseUpstreamsConfig([]string{"tls://dns.adguard.com"}, &upstream.Options{
Logger: slogutil.NewDiscardLogger(),
Bootstrap: invalidRslv, Timeout: testTimeout,
})
require.NoError(t, err)
dnsProxy := mustNew(t, &Config{
@@ -1042,7 +1046,6 @@ func TestProxy_ReplyFromUpstream_badResponse(t *testing.T) {
false,
0,
false,
nil,
),
Req: newHostTestMessage("host"),
Addr: netip.MustParseAddrPort("1.2.3.0:1234"),
@@ -1078,7 +1081,6 @@ func TestExchangeCustomUpstreamConfig(t *testing.T) {
false,
0,
false,
nil,
),
Req: newHostTestMessage("host"),
Addr: netip.MustParseAddrPort("1.2.3.0:1234"),
@@ -1137,7 +1139,6 @@ func TestExchangeCustomUpstreamConfigCache(t *testing.T) {
true,
defaultCacheSize,
prx.EnableEDNSClientSubnet,
nil,
)
d := DNSContext{
@@ -1432,7 +1433,7 @@ func TestProxy_Resolve_withOptimisticResolver(t *testing.T) {
CacheEnabled: true,
CacheOptimistic: true,
},
logger: slog.Default(),
logger: slogutil.NewDiscardLogger(),
}
p.initCache()
+24 -17
View File
@@ -4,7 +4,7 @@ import (
"net"
"slices"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
)
// cacheForContext returns cache object for the given context.
@@ -22,20 +22,17 @@ func (p *Proxy) replyFromCache(d *DNSContext) (hit bool) {
dctxCache := p.cacheForContext(d)
var ci *cacheItem
var hitMsg string
var cacheSource string
var expired bool
var key []byte
// TODO(d.kolyshev): Use EnableEDNSClientSubnet from dctxCache.
if !p.Config.EnableEDNSClientSubnet {
ci, expired, key = dctxCache.get(d.Req)
hitMsg = "serving cached response"
} else if d.ReqECS != nil {
if p.Config.EnableEDNSClientSubnet && d.ReqECS != nil {
ci, expired, key = dctxCache.getWithSubnet(d.Req, d.ReqECS)
hitMsg = "serving response from subnet cache"
cacheSource = "subnet cache"
} else {
ci, expired, key = dctxCache.get(d.Req)
hitMsg = "serving response from general cache"
cacheSource = "general cache"
}
if hit = ci != nil; !hit {
@@ -45,7 +42,12 @@ func (p *Proxy) replyFromCache(d *DNSContext) (hit bool) {
d.Res = ci.m
d.CachedUpstreamAddr = ci.u
log.Debug("dnsproxy: cache: %s", hitMsg)
p.logger.Debug(
"replying from cache",
slogutil.KeyPrefix, CacheLogPrefix,
"source", cacheSource,
"ecs_enabled", p.Config.EnableEDNSClientSubnet,
)
if dctxCache.optimistic && expired {
// Build a reduced clone of the current context to avoid data race.
@@ -60,7 +62,7 @@ func (p *Proxy) replyFromCache(d *DNSContext) (hit bool) {
addDO(minCtxClone.Req)
}
go p.shortFlighter.ResolveOnce(minCtxClone, key)
go p.shortFlighter.resolveOnce(minCtxClone, key, p.logger)
}
return hit
@@ -84,7 +86,7 @@ func (p *Proxy) cacheResp(d *DNSContext) {
dctxCache := p.cacheForContext(d)
if !p.EnableEDNSClientSubnet {
dctxCache.set(d.Res, d.Upstream)
dctxCache.set(d.Res, d.Upstream, p.logger)
return
}
@@ -103,7 +105,12 @@ func (p *Proxy) cacheResp(d *DNSContext) {
// TODO(a.meshkov): The whole response MUST be dropped if ECS in it
// doesn't correspond.
if !ecs.IP.Mask(ecs.Mask).Equal(d.ReqECS.IP.Mask(d.ReqECS.Mask)) || ones != reqOnes {
log.Debug("dnsproxy: cache: bad response: ecs %s does not match %s", ecs, d.ReqECS)
p.logger.Debug(
"ecs does not match",
slogutil.KeyPrefix, CacheLogPrefix,
"ecs", ecs,
"req_ecs", d.ReqECS,
)
return
}
@@ -118,15 +125,15 @@ func (p *Proxy) cacheResp(d *DNSContext) {
ecs.IP = ecs.IP.Mask(ecs.Mask)
}
log.Debug("dnsproxy: cache: ecs option in response: %s", ecs)
p.logger.Debug("ecs option in response", slogutil.KeyPrefix, CacheLogPrefix, "ecs", ecs)
dctxCache.setWithSubnet(d.Res, d.Upstream, ecs)
dctxCache.setWithSubnet(d.Res, d.Upstream, ecs, p.logger)
case d.ReqECS != nil:
// Cache the response for all subnets since the server doesn't support
// EDNS Client Subnet option.
dctxCache.setWithSubnet(d.Res, d.Upstream, &net.IPNet{IP: nil, Mask: nil})
dctxCache.setWithSubnet(d.Res, d.Upstream, &net.IPNet{IP: nil, Mask: nil}, p.logger)
default:
dctxCache.set(d.Res, d.Upstream)
dctxCache.set(d.Res, d.Upstream, p.logger)
}
}
@@ -135,6 +142,6 @@ func (p *Proxy) ClearCache() {
if p.cache != nil {
p.cache.clearItems()
p.cache.clearItemsWithSubnet()
log.Debug("dnsproxy: cache: cleared")
p.logger.Debug("cleared", slogutil.KeyPrefix, CacheLogPrefix)
}
}
+7 -2
View File
@@ -1,11 +1,12 @@
package proxy
import (
"fmt"
"net/netip"
"slices"
"time"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
rate "github.com/beefsack/go-rate"
gocache "github.com/patrickmn/go-cache"
)
@@ -53,7 +54,11 @@ func (p *Proxy) isRatelimited(addr netip.Addr) (ok bool) {
value := p.limiterForIP(ipStr)
rl, ok := value.(*rate.RateLimiter)
if !ok {
log.Error("dnsproxy: %T found in ratelimit cache", value)
p.logger.Error(
"invalid value found in ratelimit cache",
slogutil.KeyError,
fmt.Errorf("bad type %T", value),
)
return false
}
+3 -2
View File
@@ -3,10 +3,11 @@ package proxy
import (
"bytes"
"encoding/binary"
"log/slog"
"testing"
"time"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil"
"github.com/miekg/dns"
"github.com/stretchr/testify/assert"
@@ -177,7 +178,7 @@ func msgToSignatureSlow(msg *dns.Msg) (sig []byte) {
}
copy(signature.name[:], q.Name)
if err := binary.Write(b, binary.BigEndian, signature); err != nil {
log.Debug("writing message signature: %s", err)
slog.Default().Debug("writing message signature", slogutil.KeyError, err)
}
return b.Bytes()
+13 -7
View File
@@ -1,15 +1,16 @@
package proxy
import (
"cmp"
"fmt"
"io"
"log/slog"
"slices"
"strings"
"github.com/AdguardTeam/dnsproxy/upstream"
"github.com/AdguardTeam/golibs/container"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/mapsutil"
"github.com/AdguardTeam/golibs/netutil"
)
@@ -99,6 +100,7 @@ func ParseUpstreamsConfig(
p := &configParser{
options: opts,
logger: cmp.Or(opts.Logger, slog.Default()),
upstreamsIndex: map[string]upstream.Upstream{},
domainReservedUpstreams: map[string][]upstream.Upstream{},
specifiedDomainUpstreams: map[string][]upstream.Upstream{},
@@ -138,6 +140,9 @@ type configParser struct {
// options contains upstream properties.
options *upstream.Options
// logger is used for logging during parsing. It's never nil.
logger *slog.Logger
// upstreamsIndex is used to avoid creating duplicates of upstreams.
upstreamsIndex map[string]upstream.Upstream
@@ -266,14 +271,15 @@ func (p *configParser) specifyUpstream(domains []string, u string, idx int) (err
p.upstreams = append(p.upstreams, dnsUpstream)
// TODO(s.chzhen): Logs without index.
log.Debug("dnsproxy: upstream at index %d: %s", idx, addr)
p.logger.Debug("set upstream", "idx", idx, "addr", addr)
} else {
p.includeToReserved(dnsUpstream, domains)
log.Debug("dnsproxy: upstream at index %d: %s is reserved for %d domains",
idx,
addr,
len(domains),
p.logger.Debug(
"upstream is reserved",
"idx", idx,
"addr", addr,
"domains_num", len(domains),
)
}
@@ -303,7 +309,7 @@ func (p *configParser) includeToReserved(dnsUpstream upstream.Upstream, domains
host = host[len("*."):]
p.subdomainsOnlyExclusions.Add(host)
log.Debug("domain %q is added to exclusions list", host)
p.logger.Debug("domain is added to exclusions list", "domain", host)
p.subdomainsOnlyUpstreams[host] = append(p.subdomainsOnlyUpstreams[host], dnsUpstream)
} else {
+13 -16
View File
@@ -5,6 +5,7 @@ import (
"github.com/AdguardTeam/dnsproxy/upstream"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil"
"github.com/AdguardTeam/golibs/testutil"
"github.com/stretchr/testify/assert"
@@ -272,14 +273,12 @@ func TestValidatePrivateConfig(t *testing.T) {
func TestGetUpstreamsForDomainWithoutDuplicates(t *testing.T) {
upstreams := []string{"[/example.com/]1.1.1.1", "[/example.org/]1.1.1.1"}
config, err := ParseUpstreamsConfig(
upstreams,
&upstream.Options{
InsecureSkipVerify: false,
Bootstrap: nil,
Timeout: testTimeout,
},
)
config, err := ParseUpstreamsConfig(upstreams, &upstream.Options{
Logger: slogutil.NewDiscardLogger(),
InsecureSkipVerify: false,
Bootstrap: nil,
Timeout: testTimeout,
})
assert.NoError(t, err)
assert.Len(t, config.Upstreams, 0)
assert.Len(t, config.DomainReservedUpstreams, 2)
@@ -449,14 +448,12 @@ func BenchmarkGetUpstreamsForDomain(b *testing.B) {
"[/www.google.com/]tls://1.1.1.1",
}
config, _ := ParseUpstreamsConfig(
upstreams,
&upstream.Options{
InsecureSkipVerify: false,
Bootstrap: nil,
Timeout: testTimeout,
},
)
config, _ := ParseUpstreamsConfig(upstreams, &upstream.Options{
Logger: slogutil.NewDiscardLogger(),
InsecureSkipVerify: false,
Bootstrap: nil,
Timeout: testTimeout,
})
domains := []string{
"www.google.com.",
+6
View File
@@ -8,6 +8,7 @@ import (
"crypto/x509"
"fmt"
"io"
"log/slog"
"net"
"net/netip"
"net/url"
@@ -52,6 +53,11 @@ type QUICTraceFunc func(
// Options for AddressToUpstream func. With these options we can configure the
// upstream properties.
type Options struct {
// Logger is used for logging during parsing.
//
// TODO(d.kolyshev): Use logger in this package.
Logger *slog.Logger
// VerifyServerCertificate is used to set the VerifyPeerCertificate property
// of the *tls.Config for DNS-over-HTTPS, DNS-over-QUIC, and DNS-over-TLS.
VerifyServerCertificate func(rawCerts [][]byte, verifiedChains [][]*x509.Certificate) error