AdGuardHome/internal/dnsforward/stats.go
Stanislav Chzhen d3862614e5 Pull request 2054: 6220-average-processing-time
Updates #6220.

Squashed commit of the following:

commit 2ad87979b4f8ade2cad8a1b86b8e0663dd53b098
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Thu Nov 9 13:55:09 2023 +0300

    all: upd go

commit 387200c3de899e6f59e8d2455cb2aa2b7194b311
Merge: 37f2855ed f8fe9bfc8
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Thu Nov 9 13:49:59 2023 +0300

    Merge branch 'master' into 6220-average-processing-time

commit 37f2855ed104c20faa3f4d57d48bd221a59cacb3
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Wed Nov 8 17:08:13 2023 +0300

    client: upd locales

commit a09be4183811cef29b594f9916dc76b87f89d304
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Tue Nov 7 20:46:24 2023 +0300

    all: imp docs

commit f0b85ac1fef366da37b996d53e29d76d6279691f
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Fri Nov 3 14:17:32 2023 +0300

    all: add todo

commit 48a5879865a1625410787edef6d78b309056af7b
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Fri Nov 3 13:38:14 2023 +0300

    all: add upstream time

commit 4d7431c00e24f8a9d3e86160851b5ef3bd9d03fa
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Tue Oct 31 17:27:19 2023 +0300

    all: upd chlog

commit 040b6b9cdebea2c9789d4d38f2a0a40ef4cb26d7
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Tue Oct 31 15:42:04 2023 +0300

    all: imp average processing time
2023-11-09 16:14:05 +03:00

167 lines
4.6 KiB
Go

package dnsforward
import (
"net"
"time"
"github.com/AdguardTeam/AdGuardHome/internal/aghnet"
"github.com/AdguardTeam/AdGuardHome/internal/filtering"
"github.com/AdguardTeam/AdGuardHome/internal/querylog"
"github.com/AdguardTeam/AdGuardHome/internal/stats"
"github.com/AdguardTeam/dnsproxy/proxy"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/netutil"
"github.com/miekg/dns"
"golang.org/x/exp/slices"
)
// Write Stats data and logs
func (s *Server) processQueryLogsAndStats(dctx *dnsContext) (rc resultCode) {
log.Debug("dnsforward: started processing querylog and stats")
defer log.Debug("dnsforward: finished processing querylog and stats")
pctx := dctx.proxyCtx
q := pctx.Req.Question[0]
host := aghnet.NormalizeDomain(q.Name)
processingTime := time.Since(dctx.startTime)
ip, _ := netutil.IPAndPortFromAddr(pctx.Addr)
ip = slices.Clone(ip)
s.anonymizer.Load()(ip)
log.Debug("dnsforward: client ip for stats and querylog: %s", ip)
ipStr := ip.String()
ids := []string{ipStr, dctx.clientID}
qt, cl := q.Qtype, q.Qclass
// 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.
s.serverLock.RLock()
defer s.serverLock.RUnlock()
if s.shouldLog(host, qt, cl, ids) {
s.logQuery(dctx, ip, processingTime)
} else {
log.Debug(
"dnsforward: request %s %s %q from %s ignored; not adding to querylog",
dns.Class(cl),
dns.Type(qt),
host,
ip,
)
}
if s.shouldCountStat(host, qt, cl, ids) {
s.updateStats(dctx, ipStr, processingTime)
} else {
log.Debug(
"dnsforward: request %s %s %q from %s ignored; not counting in stats",
dns.Class(cl),
dns.Type(qt),
host,
ip,
)
}
return resultCodeSuccess
}
// shouldLog returns true if the query with the given data should be logged in
// the query log. s.serverLock is expected to be locked.
func (s *Server) shouldLog(host string, qt, cl uint16, ids []string) (ok bool) {
if qt == dns.TypeANY && s.conf.RefuseAny {
return false
}
// TODO(s.chzhen): Use dnsforward.dnsContext when it will start containing
// persistent client.
return s.queryLog != nil && s.queryLog.ShouldLog(host, qt, cl, ids)
}
// shouldCountStat returns true if the query with the given data should be
// counted in the statistics. s.serverLock is expected to be locked.
func (s *Server) shouldCountStat(host string, qt, cl uint16, ids []string) (ok bool) {
// TODO(s.chzhen): Use dnsforward.dnsContext when it will start containing
// persistent client.
return s.stats != nil && s.stats.ShouldCount(host, qt, cl, ids)
}
// logQuery pushes the request details into the query log.
func (s *Server) logQuery(dctx *dnsContext, ip net.IP, processingTime time.Duration) {
pctx := dctx.proxyCtx
p := &querylog.AddParams{
Question: pctx.Req,
ReqECS: pctx.ReqECS,
Answer: pctx.Res,
OrigAnswer: dctx.origResp,
Result: dctx.result,
ClientID: dctx.clientID,
ClientIP: ip,
Elapsed: processingTime,
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.
func (s *Server) updateStats(dctx *dnsContext, clientIP string, processingTime time.Duration) {
pctx := dctx.proxyCtx
e := &stats.Entry{
Domain: aghnet.NormalizeDomain(pctx.Req.Question[0].Name),
Result: stats.RNotFiltered,
ProcessingTime: processingTime,
UpstreamTime: pctx.QueryDuration,
}
if pctx.Upstream != nil {
e.Upstream = pctx.Upstream.Address()
}
if clientID := dctx.clientID; clientID != "" {
e.Client = clientID
} else {
e.Client = clientIP
}
switch dctx.result.Reason {
case filtering.FilteredSafeBrowsing:
e.Result = stats.RSafeBrowsing
case filtering.FilteredParental:
e.Result = stats.RParental
case filtering.FilteredSafeSearch:
e.Result = stats.RSafeSearch
case
filtering.FilteredBlockList,
filtering.FilteredInvalid,
filtering.FilteredBlockedService:
e.Result = stats.RFiltered
}
s.stats.Update(e)
}