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