2020-11-03 15:39:55 +03:00
|
|
|
// Package querylog provides query log functions and interfaces.
|
2019-08-26 11:54:38 +03:00
|
|
|
package querylog
|
2018-12-05 14:03:41 +03:00
|
|
|
|
|
|
|
import (
|
2020-11-03 15:39:55 +03:00
|
|
|
"fmt"
|
2021-01-20 17:27:53 +03:00
|
|
|
"net"
|
2019-08-26 11:54:38 +03:00
|
|
|
"os"
|
2018-12-05 14:03:41 +03:00
|
|
|
"strings"
|
|
|
|
"sync"
|
|
|
|
"time"
|
|
|
|
|
2021-12-06 17:26:43 +03:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/aghnet"
|
2021-05-21 16:15:47 +03:00
|
|
|
"github.com/AdguardTeam/AdGuardHome/internal/filtering"
|
2021-05-24 17:28:11 +03:00
|
|
|
"github.com/AdguardTeam/golibs/errors"
|
2019-02-25 16:44:22 +03:00
|
|
|
"github.com/AdguardTeam/golibs/log"
|
2021-09-30 21:17:54 +03:00
|
|
|
"github.com/AdguardTeam/golibs/timeutil"
|
2018-12-05 14:03:41 +03:00
|
|
|
"github.com/miekg/dns"
|
|
|
|
)
|
|
|
|
|
|
|
|
const (
|
2019-08-26 11:54:38 +03:00
|
|
|
queryLogFileName = "querylog.json" // .gz added during compression
|
2018-12-05 14:03:41 +03:00
|
|
|
)
|
|
|
|
|
2019-02-10 20:47:43 +03:00
|
|
|
// queryLog is a structure that writes and reads the DNS query log
|
|
|
|
type queryLog struct {
|
2021-04-02 17:30:39 +03:00
|
|
|
findClient func(ids []string) (c *Client, err error)
|
|
|
|
|
2019-11-12 15:36:17 +03:00
|
|
|
conf *Config
|
|
|
|
lock sync.Mutex
|
2019-08-08 12:56:02 +03:00
|
|
|
logFile string // path to the log file
|
2019-02-10 20:47:43 +03:00
|
|
|
|
2021-04-02 17:30:39 +03:00
|
|
|
// bufferLock protects buffer.
|
|
|
|
bufferLock sync.RWMutex
|
|
|
|
// buffer contains recent log entries.
|
|
|
|
buffer []*logEntry
|
|
|
|
|
2019-05-15 13:11:36 +03:00
|
|
|
fileFlushLock sync.Mutex // synchronize a file-flushing goroutine and main thread
|
|
|
|
flushPending bool // don't start another goroutine while the previous one is still running
|
2019-09-27 18:58:57 +03:00
|
|
|
fileWriteLock sync.Mutex
|
2021-12-06 17:26:43 +03:00
|
|
|
|
|
|
|
anonymizer *aghnet.IPMut
|
2019-02-10 20:47:43 +03:00
|
|
|
}
|
|
|
|
|
2020-11-03 15:39:55 +03:00
|
|
|
// ClientProto values are names of the client protocols.
|
|
|
|
type ClientProto string
|
|
|
|
|
|
|
|
// Client protocol names.
|
|
|
|
const (
|
2021-06-18 18:13:36 +03:00
|
|
|
ClientProtoDoH ClientProto = "doh"
|
|
|
|
ClientProtoDoQ ClientProto = "doq"
|
|
|
|
ClientProtoDoT ClientProto = "dot"
|
2021-01-27 18:32:13 +03:00
|
|
|
ClientProtoDNSCrypt ClientProto = "dnscrypt"
|
|
|
|
ClientProtoPlain ClientProto = ""
|
2020-11-03 15:39:55 +03:00
|
|
|
)
|
|
|
|
|
|
|
|
// NewClientProto validates that the client protocol name is valid and returns
|
|
|
|
// the name as a ClientProto.
|
|
|
|
func NewClientProto(s string) (cp ClientProto, err error) {
|
|
|
|
switch cp = ClientProto(s); cp {
|
|
|
|
case
|
2021-06-18 18:13:36 +03:00
|
|
|
ClientProtoDoH,
|
|
|
|
ClientProtoDoQ,
|
|
|
|
ClientProtoDoT,
|
2021-02-11 13:46:59 +03:00
|
|
|
ClientProtoDNSCrypt,
|
2020-11-03 15:39:55 +03:00
|
|
|
ClientProtoPlain:
|
|
|
|
|
|
|
|
return cp, nil
|
|
|
|
default:
|
|
|
|
return "", fmt.Errorf("invalid client proto: %q", s)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2020-05-26 15:37:37 +03:00
|
|
|
// logEntry - represents a single log entry
|
|
|
|
type logEntry struct {
|
2021-04-02 17:30:39 +03:00
|
|
|
// client is the found client information, if any.
|
|
|
|
client *Client
|
|
|
|
|
2020-05-26 15:37:37 +03:00
|
|
|
Time time.Time `json:"T"`
|
|
|
|
|
|
|
|
QHost string `json:"QH"`
|
|
|
|
QType string `json:"QT"`
|
|
|
|
QClass string `json:"QC"`
|
|
|
|
|
2022-03-03 17:52:11 +03:00
|
|
|
ReqECS string `json:"ECS,omitempty"`
|
|
|
|
|
2021-01-27 18:32:13 +03:00
|
|
|
ClientID string `json:"CID,omitempty"`
|
2020-11-03 15:39:55 +03:00
|
|
|
ClientProto ClientProto `json:"CP"`
|
2020-05-29 11:15:22 +03:00
|
|
|
|
2020-05-26 15:37:37 +03:00
|
|
|
Answer []byte `json:",omitempty"` // sometimes empty answers happen like binerdunt.top or rev2.globalrootservers.net
|
|
|
|
OrigAnswer []byte `json:",omitempty"`
|
|
|
|
|
2021-05-21 16:15:47 +03:00
|
|
|
Result filtering.Result
|
2021-12-07 17:43:51 +03:00
|
|
|
Upstream string `json:",omitempty"`
|
2021-12-13 18:06:01 +03:00
|
|
|
|
|
|
|
IP net.IP `json:"IP"`
|
|
|
|
|
|
|
|
Elapsed time.Duration
|
|
|
|
|
|
|
|
Cached bool `json:",omitempty"`
|
|
|
|
AuthenticatedData bool `json:"AD,omitempty"`
|
2020-05-26 15:37:37 +03:00
|
|
|
}
|
|
|
|
|
2020-01-16 14:25:40 +03:00
|
|
|
func (l *queryLog) Start() {
|
2019-09-27 18:58:57 +03:00
|
|
|
if l.conf.HTTPRegister != nil {
|
|
|
|
l.initWeb()
|
|
|
|
}
|
|
|
|
go l.periodicRotate()
|
2019-08-26 11:54:38 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
func (l *queryLog) Close() {
|
|
|
|
_ = l.flushLogBuffer(true)
|
|
|
|
}
|
|
|
|
|
2021-07-01 18:50:28 +03:00
|
|
|
func checkInterval(ivl time.Duration) (ok bool) {
|
|
|
|
// The constants for possible values of query log's rotation interval.
|
|
|
|
const (
|
2021-09-30 21:17:54 +03:00
|
|
|
quarterDay = timeutil.Day / 4
|
|
|
|
day = timeutil.Day
|
|
|
|
week = timeutil.Day * 7
|
|
|
|
month = timeutil.Day * 30
|
|
|
|
threeMonths = timeutil.Day * 90
|
2021-07-01 18:50:28 +03:00
|
|
|
)
|
|
|
|
|
|
|
|
return ivl == quarterDay || ivl == day || ivl == week || ivl == month || ivl == threeMonths
|
2019-09-27 18:58:57 +03:00
|
|
|
}
|
|
|
|
|
2020-05-28 15:29:36 +03:00
|
|
|
func (l *queryLog) WriteDiskConfig(c *Config) {
|
|
|
|
*c = *l.conf
|
2019-09-27 18:58:57 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
// Clear memory buffer and remove log files
|
|
|
|
func (l *queryLog) clear() {
|
2019-08-26 11:54:38 +03:00
|
|
|
l.fileFlushLock.Lock()
|
|
|
|
defer l.fileFlushLock.Unlock()
|
|
|
|
|
2019-09-27 18:58:57 +03:00
|
|
|
l.bufferLock.Lock()
|
|
|
|
l.buffer = nil
|
2019-08-26 11:54:38 +03:00
|
|
|
l.flushPending = false
|
2019-09-27 18:58:57 +03:00
|
|
|
l.bufferLock.Unlock()
|
2019-08-26 11:54:38 +03:00
|
|
|
|
2021-01-27 18:32:13 +03:00
|
|
|
oldLogFile := l.logFile + ".1"
|
|
|
|
err := os.Remove(oldLogFile)
|
|
|
|
if err != nil && !errors.Is(err, os.ErrNotExist) {
|
|
|
|
log.Error("removing old log file %q: %s", oldLogFile, err)
|
2019-02-10 20:47:43 +03:00
|
|
|
}
|
2019-08-26 11:54:38 +03:00
|
|
|
|
|
|
|
err = os.Remove(l.logFile)
|
2021-01-27 18:32:13 +03:00
|
|
|
if err != nil && !errors.Is(err, os.ErrNotExist) {
|
|
|
|
log.Error("removing log file %q: %s", l.logFile, err)
|
2019-08-26 11:54:38 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
log.Debug("Query log: cleared")
|
2019-02-10 20:47:43 +03:00
|
|
|
}
|
2018-12-05 14:03:41 +03:00
|
|
|
|
2021-12-13 18:06:01 +03:00
|
|
|
func (l *queryLog) Add(params *AddParams) {
|
2019-09-27 18:58:57 +03:00
|
|
|
if !l.conf.Enabled {
|
|
|
|
return
|
|
|
|
}
|
|
|
|
|
2021-12-13 18:06:01 +03:00
|
|
|
err := params.validate()
|
2021-04-02 17:30:39 +03:00
|
|
|
if err != nil {
|
|
|
|
log.Error("querylog: adding record: %s, skipping", err)
|
|
|
|
|
2019-11-12 18:14:33 +03:00
|
|
|
return
|
|
|
|
}
|
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
if params.Result == nil {
|
2021-05-21 16:15:47 +03:00
|
|
|
params.Result = &filtering.Result{}
|
2018-12-06 17:27:38 +03:00
|
|
|
}
|
|
|
|
|
2018-12-05 14:03:41 +03:00
|
|
|
now := time.Now()
|
2021-12-13 18:06:01 +03:00
|
|
|
q := params.Question.Question[0]
|
2018-12-05 14:03:41 +03:00
|
|
|
entry := logEntry{
|
2019-10-24 20:00:58 +03:00
|
|
|
Time: now,
|
|
|
|
|
2021-12-13 18:06:01 +03:00
|
|
|
QHost: strings.ToLower(q.Name[:len(q.Name)-1]),
|
|
|
|
QType: dns.Type(q.Qtype).String(),
|
|
|
|
QClass: dns.Class(q.Qclass).String(),
|
|
|
|
|
2021-01-27 18:32:13 +03:00
|
|
|
ClientID: params.ClientID,
|
2020-05-29 11:15:22 +03:00
|
|
|
ClientProto: params.ClientProto,
|
2021-12-13 18:06:01 +03:00
|
|
|
|
|
|
|
Result: *params.Result,
|
|
|
|
Upstream: params.Upstream,
|
|
|
|
|
|
|
|
IP: params.ClientIP,
|
|
|
|
|
|
|
|
Elapsed: params.Elapsed,
|
|
|
|
|
|
|
|
Cached: params.Cached,
|
|
|
|
AuthenticatedData: params.AuthenticatedData,
|
2018-12-05 14:03:41 +03:00
|
|
|
}
|
|
|
|
|
2022-03-03 17:52:11 +03:00
|
|
|
if params.ReqECS != nil {
|
|
|
|
entry.ReqECS = params.ReqECS.String()
|
|
|
|
}
|
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
if params.Answer != nil {
|
2021-04-02 17:30:39 +03:00
|
|
|
var a []byte
|
|
|
|
a, err = params.Answer.Pack()
|
2019-11-21 16:13:19 +03:00
|
|
|
if err != nil {
|
2021-04-02 17:30:39 +03:00
|
|
|
log.Error("querylog: Answer.Pack(): %s", err)
|
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
return
|
|
|
|
}
|
2021-04-02 17:30:39 +03:00
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
entry.Answer = a
|
|
|
|
}
|
|
|
|
|
|
|
|
if params.OrigAnswer != nil {
|
2021-04-02 17:30:39 +03:00
|
|
|
var a []byte
|
|
|
|
a, err = params.OrigAnswer.Pack()
|
2019-11-21 16:13:19 +03:00
|
|
|
if err != nil {
|
2021-04-02 17:30:39 +03:00
|
|
|
log.Error("querylog: OrigAnswer.Pack(): %s", err)
|
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
return
|
|
|
|
}
|
2021-04-02 17:30:39 +03:00
|
|
|
|
2019-11-21 16:13:19 +03:00
|
|
|
entry.OrigAnswer = a
|
|
|
|
}
|
|
|
|
|
2019-09-27 18:58:57 +03:00
|
|
|
l.bufferLock.Lock()
|
|
|
|
l.buffer = append(l.buffer, &entry)
|
2019-05-15 13:11:36 +03:00
|
|
|
needFlush := false
|
2020-05-28 15:29:36 +03:00
|
|
|
|
|
|
|
if !l.conf.FileEnabled {
|
|
|
|
if len(l.buffer) > int(l.conf.MemSize) {
|
|
|
|
// writing to file is disabled - just remove the oldest entry from array
|
2021-12-13 21:12:27 +03:00
|
|
|
//
|
|
|
|
// TODO(a.garipov): This should be replaced by a proper ring buffer,
|
|
|
|
// but it's currently difficult to do that.
|
|
|
|
l.buffer[0] = nil
|
2020-05-28 15:29:36 +03:00
|
|
|
l.buffer = l.buffer[1:]
|
|
|
|
}
|
|
|
|
} else if !l.flushPending {
|
2019-11-08 12:31:50 +03:00
|
|
|
needFlush = len(l.buffer) >= int(l.conf.MemSize)
|
2019-05-15 13:11:36 +03:00
|
|
|
if needFlush {
|
|
|
|
l.flushPending = true
|
|
|
|
}
|
2018-12-05 14:03:41 +03:00
|
|
|
}
|
2019-09-27 18:58:57 +03:00
|
|
|
l.bufferLock.Unlock()
|
2018-12-05 14:03:41 +03:00
|
|
|
|
|
|
|
// if buffer needs to be flushed to disk, do it now
|
2019-05-15 13:11:36 +03:00
|
|
|
if needFlush {
|
2020-05-28 15:29:36 +03:00
|
|
|
go func() {
|
|
|
|
_ = l.flushLogBuffer(false)
|
|
|
|
}()
|
2018-12-05 14:03:41 +03:00
|
|
|
}
|
|
|
|
}
|