2020-05-08 16:39:37 +01:00
|
|
|
package dnsforward
|
|
|
|
|
|
|
|
import (
|
2021-12-06 14:26:43 +00:00
|
|
|
"net"
|
2020-05-08 16:39:37 +01:00
|
|
|
"strings"
|
|
|
|
"time"
|
|
|
|
|
2021-05-21 14:15:47 +01:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/filtering"
|
2020-11-03 12:39:55 +00:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/querylog"
|
2020-10-30 10:32:02 +00:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/stats"
|
2020-05-08 16:39:37 +01:00
|
|
|
"github.com/AdguardTeam/dnsproxy/proxy"
|
2021-12-06 14:26:43 +00:00
|
|
|
"github.com/AdguardTeam/golibs/log"
|
2021-08-09 14:03:37 +01:00
|
|
|
"github.com/AdguardTeam/golibs/netutil"
|
2020-11-03 12:39:55 +00:00
|
|
|
"github.com/miekg/dns"
|
2022-10-21 18:42:00 +01:00
|
|
|
"golang.org/x/exp/slices"
|
2020-05-08 16:39:37 +01:00
|
|
|
)
|
|
|
|
|
|
|
|
// Write Stats data and logs
|
2021-12-13 15:06:01 +00:00
|
|
|
func (s *Server) processQueryLogsAndStats(dctx *dnsContext) (rc resultCode) {
|
|
|
|
elapsed := time.Since(dctx.startTime)
|
|
|
|
pctx := dctx.proxyCtx
|
2020-05-08 16:39:37 +01:00
|
|
|
|
|
|
|
shouldLog := true
|
2021-01-27 15:32:13 +00:00
|
|
|
msg := pctx.Req
|
2023-02-07 14:50:39 +00:00
|
|
|
q := msg.Question[0]
|
|
|
|
host := strings.ToLower(strings.TrimSuffix(q.Name, "."))
|
2020-05-08 16:39:37 +01:00
|
|
|
|
|
|
|
// don't log ANY request if refuseAny is enabled
|
2023-02-07 14:50:39 +00:00
|
|
|
if q.Qtype == dns.TypeANY && s.conf.RefuseAny {
|
2020-05-08 16:39:37 +01:00
|
|
|
shouldLog = false
|
|
|
|
}
|
|
|
|
|
2021-12-07 14:43:51 +00:00
|
|
|
ip, _ := netutil.IPAndPortFromAddr(pctx.Addr)
|
2022-10-21 18:42:00 +01:00
|
|
|
ip = slices.Clone(ip)
|
2021-12-07 14:43:51 +00:00
|
|
|
|
2021-05-26 15:55:19 +01:00
|
|
|
s.serverLock.RLock()
|
|
|
|
defer s.serverLock.RUnlock()
|
|
|
|
|
2021-12-06 14:26:43 +00:00
|
|
|
s.anonymizer.Load()(ip)
|
|
|
|
|
|
|
|
log.Debug("client ip: %s", ip)
|
|
|
|
|
|
|
|
// Synchronize access to s.queryLog and s.stats so they won't be suddenly
|
|
|
|
// uninitialized while in use. This can happen after proxy server has been
|
|
|
|
// stopped, but its workers haven't yet exited.
|
2023-02-07 14:50:39 +00:00
|
|
|
if shouldLog &&
|
|
|
|
s.queryLog != nil &&
|
|
|
|
s.queryLog.ShouldLog(host, q.Qtype, q.Qclass) {
|
2022-03-03 14:52:11 +00:00
|
|
|
s.logQuery(dctx, pctx, elapsed, ip)
|
2023-02-07 14:50:39 +00:00
|
|
|
} else {
|
|
|
|
log.Debug("request for %s from %s ignored; not logging", host, ip)
|
2020-05-08 16:39:37 +01:00
|
|
|
}
|
|
|
|
|
2022-03-03 14:52:11 +00:00
|
|
|
if s.stats != nil {
|
|
|
|
s.updateStats(dctx, elapsed, *dctx.result, ip)
|
|
|
|
}
|
2020-05-08 16:39:37 +01:00
|
|
|
|
2021-01-27 15:32:13 +00:00
|
|
|
return resultCodeSuccess
|
2020-05-08 16:39:37 +01:00
|
|
|
}
|
|
|
|
|
2022-03-03 14:52:11 +00:00
|
|
|
// logQuery pushes the request details into the query log.
|
|
|
|
func (s *Server) logQuery(
|
|
|
|
dctx *dnsContext,
|
|
|
|
pctx *proxy.DNSContext,
|
|
|
|
elapsed time.Duration,
|
|
|
|
ip net.IP,
|
|
|
|
) {
|
|
|
|
p := &querylog.AddParams{
|
|
|
|
Question: pctx.Req,
|
|
|
|
ReqECS: pctx.ReqECS,
|
|
|
|
Answer: pctx.Res,
|
|
|
|
OrigAnswer: dctx.origResp,
|
|
|
|
Result: dctx.result,
|
|
|
|
ClientID: dctx.clientID,
|
|
|
|
ClientIP: ip,
|
2022-05-25 16:00:50 +01:00
|
|
|
Elapsed: elapsed,
|
2022-03-03 14:52:11 +00:00
|
|
|
AuthenticatedData: dctx.responseAD,
|
|
|
|
}
|
|
|
|
|
|
|
|
switch pctx.Proto {
|
|
|
|
case proxy.ProtoHTTPS:
|
|
|
|
p.ClientProto = querylog.ClientProtoDoH
|
|
|
|
case proxy.ProtoQUIC:
|
|
|
|
p.ClientProto = querylog.ClientProtoDoQ
|
|
|
|
case proxy.ProtoTLS:
|
|
|
|
p.ClientProto = querylog.ClientProtoDoT
|
|
|
|
case proxy.ProtoDNSCrypt:
|
|
|
|
p.ClientProto = querylog.ClientProtoDNSCrypt
|
|
|
|
default:
|
|
|
|
// Consider this a plain DNS-over-UDP or DNS-over-TCP request.
|
|
|
|
}
|
|
|
|
|
|
|
|
if pctx.Upstream != nil {
|
|
|
|
p.Upstream = pctx.Upstream.Address()
|
|
|
|
} else if cachedUps := pctx.CachedUpstreamAddr; cachedUps != "" {
|
|
|
|
p.Upstream = pctx.CachedUpstreamAddr
|
|
|
|
p.Cached = true
|
|
|
|
}
|
|
|
|
|
|
|
|
s.queryLog.Add(p)
|
|
|
|
}
|
|
|
|
|
|
|
|
// updatesStats writes the request into statistics.
|
2021-12-06 14:26:43 +00:00
|
|
|
func (s *Server) updateStats(
|
|
|
|
ctx *dnsContext,
|
|
|
|
elapsed time.Duration,
|
|
|
|
res filtering.Result,
|
|
|
|
clientIP net.IP,
|
|
|
|
) {
|
2021-01-27 15:32:13 +00:00
|
|
|
pctx := ctx.proxyCtx
|
2020-05-08 16:39:37 +01:00
|
|
|
e := stats.Entry{}
|
2021-01-27 15:32:13 +00:00
|
|
|
e.Domain = strings.ToLower(pctx.Req.Question[0].Name)
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Domain = e.Domain[:len(e.Domain)-1] // remove last "."
|
2021-01-27 15:32:13 +00:00
|
|
|
|
|
|
|
if clientID := ctx.clientID; clientID != "" {
|
|
|
|
e.Client = clientID
|
2021-12-06 14:26:43 +00:00
|
|
|
} else if clientIP != nil {
|
|
|
|
e.Client = clientIP.String()
|
2020-05-08 16:39:37 +01:00
|
|
|
}
|
2021-01-27 15:32:13 +00:00
|
|
|
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Time = uint32(elapsed / 1000)
|
|
|
|
e.Result = stats.RNotFiltered
|
|
|
|
|
|
|
|
switch res.Reason {
|
2021-05-21 14:15:47 +01:00
|
|
|
case filtering.FilteredSafeBrowsing:
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Result = stats.RSafeBrowsing
|
2021-05-21 14:15:47 +01:00
|
|
|
case filtering.FilteredParental:
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Result = stats.RParental
|
2021-05-21 14:15:47 +01:00
|
|
|
case filtering.FilteredSafeSearch:
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Result = stats.RSafeSearch
|
2021-05-21 16:30:57 +01:00
|
|
|
case filtering.FilteredBlockList,
|
|
|
|
filtering.FilteredInvalid,
|
|
|
|
filtering.FilteredBlockedService:
|
2020-05-08 16:39:37 +01:00
|
|
|
e.Result = stats.RFiltered
|
|
|
|
}
|
|
|
|
|
|
|
|
s.stats.Update(e)
|
|
|
|
}
|