aboutsummaryrefslogtreecommitdiff
path: root/lib/dns/server.go
diff options
context:
space:
mode:
Diffstat (limited to 'lib/dns/server.go')
-rw-r--r--lib/dns/server.go188
1 files changed, 73 insertions, 115 deletions
diff --git a/lib/dns/server.go b/lib/dns/server.go
index 005a28b0..ca2baa5b 100644
--- a/lib/dns/server.go
+++ b/lib/dns/server.go
@@ -66,18 +66,21 @@ const (
//
// Following the prefix is
//
-// SOURCE FWD-NAME NS MSG-ID:QUESTION ELAPSED TOTAL_Q AVG_ELAPSED
+// SOURCE FWD_NAME NS {MSG_ID QNAME TYPE TTL} ELAPSED TOTAL_Q AVG_ELAPSED
//
// where each field is, in order,
-// - source of connection (UDP, TCP, DoH, or DoT),
-// - forwarder name (for example, UDP-0 if request handled by the
-// first parent name server using UDP) or "-" if its from cache,
-// - parent name server address for forwarded query or "-" if its from
-// cache,
-// - message-ID and question separated by ":",
-// - elapsed time,
-// - total query per-forwarder, and
-// - average elapsed time
+// - SOURCE: source of connection (UDP, TCP, DoH, or DoT)
+// - FWD_NAME: forwarder name (for example, UDP-0 means request handled by
+// the first parent name server using UDP) or "-" if its from cache
+// - NS: parent name server address for forwarded query or "-" if its from
+// cache
+// - MSG_ID: message ID
+// - QNAME: the question
+// - TYPE: type of question
+// - TTL: time to live of the answer, 0 if its log is request
+// - ELAPSED: elapsed time
+// - TOTAL_Q: total query per-forwarder
+// - AVG_ELAPSED: average elapsed time per-forwarder
type Server struct {
HostsFiles map[string]*HostsFile
Caches Caches
@@ -591,10 +594,8 @@ func (srv *Server) processRequest() {
}
if srv.opts.Debug&DebugLevelCache != 0 {
- log.Printf(`> %s - - %d:%s - - -`,
- connTypeNames[req.kind],
- req.message.Header.ID,
- req.message.Question.String())
+ log.Printf(`> %s - - %s - - -`,
+ connTypeNames[req.kind], req.String())
}
an = srv.Caches.query(req.message)
@@ -608,17 +609,16 @@ func (srv *Server) processRequest() {
}
default:
if srv.opts.Debug&DebugLevelCache != 0 {
- log.Printf(`* %s - - %d:%s - - -: no active forwarders`,
+ log.Printf(`* %s - - %s - - -: no active forwarders`,
connTypeNames[req.kind],
- req.message.Header.ID,
- req.message.Question.String())
+ req.String())
}
req.error(RCodeErrServer)
}
continue
}
- if an.msg.IsExpired() {
+ if an.Message.IsExpired() {
switch {
case srv.hasForwarders():
if req.kind == connTypeTCP {
@@ -629,60 +629,51 @@ func (srv *Server) processRequest() {
default:
if srv.opts.Debug&DebugLevelCache != 0 {
- log.Printf(`* %s - - %d:%s - - -: answer is expired and no active forwarders`,
+ log.Printf(`* %s - - %s - - -: answer is expired and no active forwarders`,
connTypeNames[req.kind],
- req.message.Header.ID,
- req.message.Question.String())
+ req.String())
}
req.error(RCodeErrServer)
}
continue
}
- an.msg.SetID(req.message.Header.ID)
+ an.Message.SetID(req.message.Header.ID)
an.updateTTL()
- res = an.msg
+ res = an.Message
_, err = req.writer.Write(res.packet)
if err != nil {
- log.Printf(`! %s - - %d:%s - - -: %s`,
- connTypeNames[req.kind],
- req.message.Header.ID,
- req.message.Question.String(), err)
+ log.Printf(`! %s - - %s - - -: %s`,
+ connTypeNames[req.kind], an.String(), err)
continue
}
if srv.opts.Debug&DebugLevelCache != 0 {
- log.Printf(`< %s - - %d:%s - - -`, connTypeNames[req.kind],
- res.Header.ID, res.Question.String())
+ log.Printf(`< %s - - %s - - -`,
+ connTypeNames[req.kind], an.String())
}
}
}
-func (srv *Server) processResponse(req *request, res *Message) (inserted bool, err error) {
+func (srv *Server) processResponse(req *request, res *Message) (an *Answer, inserted bool, err error) {
if !isResponseValid(req, res) {
req.error(RCodeErrServer)
- return false, nil
+ return nil, false, errors.New(`invalid response`)
}
- var an *Answer
-
_, err = req.writer.Write(res.packet)
if err != nil {
- return false, err
+ return nil, false, err
}
if res.Header.RCode != 0 {
- if srv.opts.Debug&DebugLevelDNS != 0 {
- err = errors.New(`response has error code ` + rcodeNames[res.Header.RCode])
- }
- return false, err
+ err = errors.New(`response has error code ` + rcodeNames[res.Header.RCode])
+ return nil, false, err
}
if res.Header.IsTC {
- if srv.opts.Debug&DebugLevelDNS != 0 {
- err = errors.New(`response truncated`)
- }
- return false, err
+ err = errors.New(`response truncated`)
+ return nil, false, err
}
if res.Header.ANCount == 0 {
// Ignore empty answers.
@@ -694,16 +685,14 @@ func (srv *Server) processResponse(req *request, res *Message) (inserted bool, e
// Once they connect to Y again, any request to MY.Y will not
// be possible because rescached caches contains empty answer
// for MY.Y.
- if srv.opts.Debug&DebugLevelDNS != 0 {
- err = errors.New(`empty RR answer`)
- }
- return false, err
+ err = errors.New(`empty RR answer`)
+ return nil, false, err
}
an = newAnswer(res, false)
- inserted = srv.Caches.upsert(an)
+ an, inserted = srv.Caches.upsert(an)
- return inserted, nil
+ return an, inserted, nil
}
func (srv *Server) startAllForwarders() {
@@ -790,11 +779,9 @@ func (srv *Server) dohForwarder(tag, nameserver string) {
}
res, err = forwarder.Query(req.message)
if err != nil {
- log.Printf(`! %s %s %s %d:%s: forward failed %s`,
+ log.Printf(`! %s %s %s %s - - -: forward failed %s`,
connTypeNames[req.kind],
- tag, nameserver,
- req.message.Header.ID,
- req.message.Question.String(),
+ tag, nameserver, req.String(),
err)
if !errors.Is(err, errInvalidMessage) {
isRunning = false
@@ -802,34 +789,28 @@ func (srv *Server) dohForwarder(tag, nameserver string) {
continue
}
- isInserted, err := srv.processResponse(req, res)
+ an, isInserted, err := srv.processResponse(req, res)
elapsed := time.Since(req.startAt)
totalElapsed += int64(elapsed)
totalQuery++
avgElapsed := time.Duration(totalElapsed / totalQuery)
if err != nil {
- log.Printf(`! %s %s %s %d:%s %v %d %v: %s`,
+ log.Printf(`! %s %s %s %s %v %d %v: %s`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, req.String(),
elapsed, totalQuery, avgElapsed, err)
continue
}
if srv.opts.Debug&DebugLevelCache != 0 {
if isInserted {
- log.Printf(`+ %s %s %s %d:%s %v %d %v`,
+ log.Printf(`+ %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
} else {
- log.Printf(`# %s %s %s %d:%s %v %d %v`,
+ log.Printf(`# %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
}
}
@@ -902,11 +883,9 @@ func (srv *Server) tlsForwarder(tag, nameserver string) {
res, err = forwarder.Query(req.message)
if err != nil {
- log.Printf(`! %s %s %s %d:%s: forward failed %s`,
+ log.Printf(`! %s %s %s %s - - -: forward failed %s`,
connTypeNames[req.kind],
- logp, tag,
- req.message.Header.ID,
- req.message.Question.String(),
+ logp, tag, req.String(),
err)
if !errors.Is(err, errInvalidMessage) {
isRunning = false
@@ -914,34 +893,29 @@ func (srv *Server) tlsForwarder(tag, nameserver string) {
continue
}
- isInserted, err := srv.processResponse(req, res)
+ an, isInserted, err := srv.processResponse(req, res)
elapsed := time.Since(req.startAt)
totalElapsed += int64(elapsed)
totalQuery++
avgElapsed := time.Duration(totalElapsed / totalQuery)
if err != nil {
- log.Printf(`! %s %s %s %d:%s %v %d %v: %s`,
+ log.Printf(`! %s %s %s %s %v %d %v: %s`,
connTypeNames[req.kind],
tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ req.String(),
elapsed, totalQuery, avgElapsed, err)
continue
}
if srv.opts.Debug&DebugLevelCache != 0 {
if isInserted {
- log.Printf(`+ %s %s %s %d:%s %v %d %v`,
+ log.Printf(`+ %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
} else {
- log.Printf(`# %s %s %s %d:%s %v %d %v`,
+ log.Printf(`# %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
}
}
@@ -1006,42 +980,34 @@ func (srv *Server) tcpForwarder(tag, nameserver string) {
res, err = cl.Query(req.message)
cl.Close()
if err != nil {
- log.Printf(`! %s %s %s %d:%s: forward failed %s`,
+ log.Printf(`! %s %s %s %s - - -: forward failed %s`,
connTypeNames[req.kind],
- tag, nameserver,
- req.message.Header.ID,
- req.message.Question.String(), err)
+ tag, nameserver, req.String(), err)
continue
}
- isInserted, err := srv.processResponse(req, res)
+ an, isInserted, err := srv.processResponse(req, res)
elapsed := time.Since(req.startAt)
totalElapsed += int64(elapsed)
totalQuery++
avgElapsed := time.Duration(totalElapsed / totalQuery)
if err != nil {
- log.Printf(`! %s %s %s %d:%s %v %d %v: %s`,
+ log.Printf(`! %s %s %s %s %v %d %v: %s`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, req.String(),
elapsed, totalQuery, avgElapsed, err)
continue
}
if srv.opts.Debug&DebugLevelCache != 0 {
if isInserted {
- log.Printf(`+ %s %s %s %d:%s %v %d %v`,
+ log.Printf(`+ %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
} else {
- log.Printf(`# %s %s %s %d:%s: %v %d %v`,
+ log.Printf(`# %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
}
}
@@ -1116,11 +1082,9 @@ func (srv *Server) udpForwarder(tag, nameserver string) {
res, err = forwarder.Query(req.message)
if err != nil {
- log.Printf(`! %s %s %s %d:%s: forward failed %s`,
+ log.Printf(`! %s %s %s %s - - -: forward failed %s`,
connTypeNames[req.kind],
- tag, nameserver,
- req.message.Header.ID,
- req.message.Question.String(),
+ tag, nameserver, req.String(),
err)
if !errors.Is(err, errInvalidMessage) {
isRunning = false
@@ -1128,34 +1092,28 @@ func (srv *Server) udpForwarder(tag, nameserver string) {
continue
}
- isInserted, err := srv.processResponse(req, res)
+ an, isInserted, err := srv.processResponse(req, res)
elapsed := time.Since(req.startAt)
totalElapsed += int64(elapsed)
totalQuery++
avgElapsed := time.Duration(totalElapsed / totalQuery)
if err != nil {
- log.Printf(`! %s %s %s %d:%s %v %d %v: %s`,
+ log.Printf(`! %s %s %s %s %v %d %v: %s`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, req.String(),
elapsed, totalQuery, avgElapsed, err)
continue
}
if srv.opts.Debug&DebugLevelCache != 0 {
if isInserted {
- log.Printf(`+ %s %s %s %d:%s %v %d %v`,
+ log.Printf(`+ %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
} else {
- log.Printf(`# %s %s %s %d:%s %v %d %v`,
+ log.Printf(`# %s %s %s %s %v %d %v`,
connTypeNames[req.kind],
- tag, nameserver,
- res.Header.ID,
- res.Question.String(),
+ tag, nameserver, an.String(),
elapsed, totalQuery, avgElapsed)
}
}