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