aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--CHANGELOG.adoc9
-rw-r--r--lib/dns/answer.go44
-rw-r--r--lib/dns/answer_test.go74
-rw-r--r--lib/dns/answers.go13
-rw-r--r--lib/dns/answers_test.go26
-rw-r--r--lib/dns/caches.go45
-rw-r--r--lib/dns/caches_test.go24
-rw-r--r--lib/dns/request.go7
-rw-r--r--lib/dns/server.go188
9 files changed, 207 insertions, 223 deletions
diff --git a/CHANGELOG.adoc b/CHANGELOG.adoc
index 24f1d833..6d647edf 100644
--- a/CHANGELOG.adoc
+++ b/CHANGELOG.adoc
@@ -38,6 +38,15 @@ Legend,
[#v0_61_0]
== pakakeh.go v0.61.0 (2026-xx-xx)
+**lib/dns: print the answer TTL in DebugLevelCache**
+
+The log level cache changed to the following format,
+
+ ... {MSG_ID QNAME TYPE TTL} ...
+
+where MSG_ID is the message ID, QNAME is the question name, TYPE is the
+type of question, and TTL is the time-to-live of the answer.
+
**🌼 lib/dns: simplify log message for DebugLevelCache**
For each logged request, there should be one line of response logged,
diff --git a/lib/dns/answer.go b/lib/dns/answer.go
index dc81e359..fd5c431d 100644
--- a/lib/dns/answer.go
+++ b/lib/dns/answer.go
@@ -5,6 +5,7 @@ package dns
import (
"container/list"
+ "fmt"
"strings"
"time"
)
@@ -14,8 +15,8 @@ type Answer struct {
// el contains pointer to the cache in LRU.
el *list.Element
- // msg contains the unpacked DNS message.
- msg *Message
+ // Message contains the unpacked DNS message.
+ Message *Message
// QName contains DNS question name, a copy of msg.Question.Name.
QName string
@@ -34,6 +35,9 @@ type Answer struct {
// RClass contains record class, a copy of msg.Question.Class.
RClass RecordClass
+
+ // TTL contains the first TTL on RR Answer.
+ TTL uint32
}
// newAnswer create new answer from Message.
@@ -42,10 +46,10 @@ type Answer struct {
func newAnswer(msg *Message, isLocal bool) (an *Answer) {
an = &Answer{
// Trim the dot at the end for Message that is come from zone.
- QName: strings.TrimSuffix(msg.Question.Name, `.`),
- RType: msg.Question.Type,
- RClass: msg.Question.Class,
- msg: msg,
+ QName: strings.TrimSuffix(msg.Question.Name, `.`),
+ RType: msg.Question.Type,
+ RClass: msg.Question.Class,
+ Message: msg,
}
if isLocal {
return
@@ -53,12 +57,24 @@ func newAnswer(msg *Message, isLocal bool) (an *Answer) {
var at = time.Now().Unix()
an.ReceivedAt = at
an.AccessedAt = at
+ if len(msg.Answer) != 0 {
+ an.TTL = msg.Answer[0].TTL
+ }
return
}
+func (an *Answer) String() string {
+ var id uint16
+ if an.Message != nil {
+ id = an.Message.Header.ID
+ }
+ return fmt.Sprintf(`{%d %s %s %d}`, id, an.QName,
+ RecordTypeNames[an.RType], an.TTL)
+}
+
// clear the answer fields.
func (an *Answer) clear() {
- an.msg = nil
+ an.Message = nil
an.el = nil
}
@@ -69,14 +85,14 @@ func (an *Answer) clear() {
func (an *Answer) get() (packet []byte) {
an.updateTTL()
- packet = make([]byte, len(an.msg.packet))
- copy(packet, an.msg.packet)
+ packet = make([]byte, len(an.Message.packet))
+ copy(packet, an.Message.packet)
return
}
// update the answer with new message.
func (an *Answer) update(nu *Answer) {
- if nu == nil || nu.msg == nil {
+ if nu == nil || nu.Message == nil {
return
}
@@ -85,8 +101,8 @@ func (an *Answer) update(nu *Answer) {
an.AccessedAt = nu.AccessedAt
}
- an.msg = nu.msg
- nu.msg = nil
+ an.Message = nu.Message
+ an.TTL = nu.TTL
}
// updateTTL decrease the answer TTLs based on time when message received.
@@ -96,6 +112,6 @@ func (an *Answer) updateTTL() {
}
an.AccessedAt = time.Now().Unix()
- var ttl = uint32(an.AccessedAt - an.ReceivedAt)
- an.msg.SubTTL(ttl)
+ an.TTL = uint32(an.AccessedAt - an.ReceivedAt)
+ an.Message.SubTTL(an.TTL)
}
diff --git a/lib/dns/answer_test.go b/lib/dns/answer_test.go
index f21c14c5..6147917f 100644
--- a/lib/dns/answer_test.go
+++ b/lib/dns/answer_test.go
@@ -54,10 +54,10 @@ func TestNewAnswer(t *testing.T) {
msg: msg1,
isLocal: true,
exp: &Answer{
- QName: "test",
- RType: 1,
- RClass: 1,
- msg: msg1,
+ QName: "test",
+ RType: 1,
+ RClass: 1,
+ Message: msg1,
},
expQName: "test",
expRType: 1,
@@ -67,10 +67,10 @@ func TestNewAnswer(t *testing.T) {
desc: "With non local message",
msg: msg1,
exp: &Answer{
- QName: "test",
- RType: 1,
- RClass: 1,
- msg: msg1,
+ QName: "test",
+ RType: 1,
+ RClass: 1,
+ Message: msg1,
},
expQName: "test",
expRType: 1,
@@ -99,7 +99,7 @@ func TestNewAnswer(t *testing.T) {
test.Assert(t, "newAnswer.QName", c.expQName, got.QName)
test.Assert(t, "newAnswer.RType", c.expRType, got.RType)
test.Assert(t, "newAnswer.RClass", c.expRClass, got.RClass)
- test.Assert(t, "newAnswer.msg", c.expMsg, got.msg)
+ test.Assert(t, "newAnswer.Message", c.expMsg, got.Message)
}
}
@@ -110,8 +110,8 @@ func TestAnswerClear(t *testing.T) {
Value: 1,
}
an = &Answer{
- msg: msg,
- el: el,
+ Message: msg,
+ el: el,
}
expMsg *Message
@@ -120,7 +120,7 @@ func TestAnswerClear(t *testing.T) {
an.clear()
- test.Assert(t, "answer.msg", expMsg, an.msg)
+ test.Assert(t, "answer.Message", expMsg, an.Message)
test.Assert(t, "answer.el", expEl, an.el)
}
@@ -212,12 +212,10 @@ func TestAnswerGet(t *testing.T) {
func TestAnswerUpdate(t *testing.T) {
type testCase struct {
- an *Answer
- nu *Answer
- expMsg *Message
- desc string
- expReceivedAt int64
- expAccessedAt int64
+ an *Answer
+ nu *Answer
+ exp *Answer
+ desc string
}
var (
@@ -242,41 +240,47 @@ func TestAnswerUpdate(t *testing.T) {
an: &Answer{
ReceivedAt: 1,
AccessedAt: 1,
- msg: msg1,
+ Message: msg1,
+ },
+ exp: &Answer{
+ ReceivedAt: 1,
+ AccessedAt: 1,
+ Message: msg1,
},
- expReceivedAt: 1,
- expAccessedAt: 1,
- expMsg: msg1,
}, {
desc: "With local answer",
an: &Answer{
ReceivedAt: 0,
AccessedAt: 0,
- msg: msg1,
+ Message: msg1,
},
nu: &Answer{
ReceivedAt: at,
AccessedAt: at,
- msg: msg2,
+ Message: msg2,
+ },
+ exp: &Answer{
+ ReceivedAt: 0,
+ AccessedAt: 0,
+ Message: msg2,
},
- expReceivedAt: 0,
- expAccessedAt: 0,
- expMsg: nil,
}, {
desc: "With non local answer",
an: &Answer{
ReceivedAt: 1,
AccessedAt: 1,
- msg: msg1,
+ Message: msg1,
},
nu: &Answer{
ReceivedAt: at,
AccessedAt: at,
- msg: msg2,
+ Message: msg2,
+ },
+ exp: &Answer{
+ ReceivedAt: at,
+ AccessedAt: at,
+ Message: msg2,
},
- expReceivedAt: at,
- expAccessedAt: at,
- expMsg: nil,
}}
for _, c = range cases {
@@ -284,10 +288,6 @@ func TestAnswerUpdate(t *testing.T) {
c.an.update(c.nu)
- test.Assert(t, "ReceivedAt", c.expReceivedAt, c.an.ReceivedAt)
- test.Assert(t, "AccessedAt", c.expAccessedAt, c.an.AccessedAt)
- if c.nu != nil {
- test.Assert(t, "c.nu.msg", c.expMsg, c.nu.msg)
- }
+ test.Assert(t, "ReceivedAt", c.exp, c.an)
}
}
diff --git a/lib/dns/answers.go b/lib/dns/answers.go
index a29fdf86..412002d1 100644
--- a/lib/dns/answers.go
+++ b/lib/dns/answers.go
@@ -15,7 +15,7 @@ func newAnswers(an *Answer) (ans *answers) {
ans = &answers{
v: make([]*Answer, 0, 1),
}
- if an != nil && an.msg != nil {
+ if an != nil && an.Message != nil {
ans.v = append(ans.v, an)
}
return
@@ -54,10 +54,9 @@ func (ans *answers) remove(rtype RecordType, rclass RecordClass) {
}
// upsert update or insert new answer to list.
-// If new answer is updated, it will return the old answer.
-// If new answer is inserted, it will return nil instead.
-func (ans *answers) upsert(nu *Answer) (an *Answer) {
- if nu == nil || nu.msg == nil {
+// It return the new inserted answer or update answer.
+func (ans *answers) upsert(nu *Answer) (an *Answer, isInsert bool) {
+ if nu == nil || nu.Message == nil {
return
}
an, _ = ans.get(nu.RType, nu.RClass)
@@ -65,6 +64,8 @@ func (ans *answers) upsert(nu *Answer) (an *Answer) {
an.update(nu)
} else {
ans.v = append(ans.v, nu)
+ an = nu
+ isInsert = true
}
- return
+ return an, isInsert
}
diff --git a/lib/dns/answers_test.go b/lib/dns/answers_test.go
index 77912fa7..96418779 100644
--- a/lib/dns/answers_test.go
+++ b/lib/dns/answers_test.go
@@ -34,11 +34,11 @@ func TestNewAnswers(t *testing.T) {
}, {
desc: "With valid answer",
an: &Answer{
- msg: &Message{},
+ Message: &Message{},
},
expLen: 1,
expV: []*Answer{{
- msg: &Message{},
+ Message: &Message{},
}},
}}
@@ -188,26 +188,26 @@ func TestAnswersUpdate(t *testing.T) {
an1 = &Answer{
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 1,
},
},
}
an2 = &Answer{
- RType: 2,
- RClass: 1,
- msg: &Message{},
+ RType: 2,
+ RClass: 1,
+ Message: &Message{},
}
an3 = &Answer{
- RType: 1,
- RClass: 2,
- msg: &Message{},
+ RType: 1,
+ RClass: 2,
+ Message: &Message{},
}
an4 = &Answer{
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 2,
},
@@ -247,9 +247,9 @@ func TestAnswersUpdate(t *testing.T) {
exp: &answers{
v: []*Answer{
{
- RType: 1,
- RClass: 1,
- msg: an4.msg,
+ RType: 1,
+ RClass: 1,
+ Message: an4.Message,
},
an2,
an3,
diff --git a/lib/dns/caches.go b/lib/dns/caches.go
index 3d4d5142..e6d5f58f 100644
--- a/lib/dns/caches.go
+++ b/lib/dns/caches.go
@@ -109,7 +109,7 @@ func (c *Caches) ExternalLoad(r io.Reader) (answers []*Answer, err error) {
return nil, fmt.Errorf("%s: %w", logp, err)
}
for _, answer = range answers {
- _ = c.upsert(answer)
+ c.upsert(answer)
}
return answers, nil
}
@@ -198,7 +198,7 @@ func (c *Caches) ExternalSave(w io.Writer) (n int, err error) {
item = &cachesFileV1{
ReceivedAt: answer.ReceivedAt,
AccessedAt: answer.AccessedAt,
- Packet: answer.msg.packet,
+ Packet: answer.Message.packet,
}
err = enc.Encode(item)
if err != nil {
@@ -225,7 +225,7 @@ func (c *Caches) ExternalSearch(re *regexp.Regexp) (listMsg []*Message) {
for dname, ans = range c.external {
if re.MatchString(dname) {
for _, an = range ans.v {
- listMsg = append(listMsg, an.msg)
+ listMsg = append(listMsg, an.Message)
}
}
}
@@ -270,10 +270,10 @@ out:
return nil
}
an = &Answer{
- msg: msg,
+ Message: msg,
}
- _ = an.msg.AddAuthority(zone.soaRecord())
- an.msg.SetResponseCode(RCodeErrName)
+ _ = an.Message.AddAuthority(zone.soaRecord())
+ an.Message.SetResponseCode(RCodeErrName)
}
return an
}
@@ -303,7 +303,7 @@ func (c *Caches) InternalPopulate(msgs []*Message, from string) {
for _, msg = range msgs {
an = newAnswer(msg, isLocal)
- inserted = c.upsert(an)
+ _, inserted = c.upsert(an)
if inserted {
n++
}
@@ -382,7 +382,7 @@ func (c *Caches) InternalRemoveRecord(rr *ResourceRecord) (rrOut *ResourceRecord
if an.RClass != rr.Class {
continue
}
- rrOut, err = an.msg.RemoveAnswer(rr)
+ rrOut, err = an.Message.RemoveAnswer(rr)
break
}
return rrOut, err
@@ -437,7 +437,7 @@ func (c *Caches) internalUpsertRecord(rr *ResourceRecord) (err error) {
return nil
}
- return an.msg.AddAnswer(rr)
+ return an.Message.AddAnswer(rr)
}
// prune old, external answers that have access time less or equal than
@@ -460,7 +460,7 @@ func (c *Caches) prune(exp int64) (listAnswer []*Answer) {
}
if c.debug&DebugLevelCache != 0 {
- log.Printf(`dns: - 0:%s`, answer.msg.Question.String())
+ log.Printf(`dns: - 0:%s`, answer.Message.Question.String())
}
next = el.Next()
@@ -531,15 +531,12 @@ func (c *Caches) read(r io.Reader) (answers []*Answer, err error) {
//
// If the answer is inserted it will return true, otherwise it will return
// false.
-func (c *Caches) upsert(nu *Answer) (inserted bool) {
- if nu == nil || nu.msg == nil {
- return
+func (c *Caches) upsert(nu *Answer) (an *Answer, inserted bool) {
+ if nu == nil || nu.Message == nil {
+ return nil, false
}
- var (
- answers *answers
- an *Answer
- )
+ var answers *answers
c.Lock()
defer c.Unlock()
@@ -550,11 +547,9 @@ func (c *Caches) upsert(nu *Answer) (inserted bool) {
answers = newAnswers(nu)
c.internal[nu.QName] = answers
inserted = true
+ an = nu
} else {
- an = answers.upsert(nu)
- if an == nil {
- inserted = true
- }
+ an, inserted = answers.upsert(nu)
}
} else {
answers = c.external[nu.QName]
@@ -562,11 +557,9 @@ func (c *Caches) upsert(nu *Answer) (inserted bool) {
answers = newAnswers(nu)
c.external[nu.QName] = answers
inserted = true
+ an = nu
} else {
- an = answers.upsert(nu)
- if an == nil {
- inserted = true
- }
+ an, inserted = answers.upsert(nu)
}
if inserted {
// Push the new answer to LRU if new answer is
@@ -575,7 +568,7 @@ func (c *Caches) upsert(nu *Answer) (inserted bool) {
}
}
- return inserted
+ return an, inserted
}
// worker for pruning unused caches.
diff --git a/lib/dns/caches_test.go b/lib/dns/caches_test.go
index 3dc64fbd..d166f349 100644
--- a/lib/dns/caches_test.go
+++ b/lib/dns/caches_test.go
@@ -26,7 +26,7 @@ func TestCachesQuery(t *testing.T) {
QName: "test",
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 1,
},
@@ -37,7 +37,7 @@ func TestCachesQuery(t *testing.T) {
QName: "test",
RType: 2,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 2,
},
@@ -48,7 +48,7 @@ func TestCachesQuery(t *testing.T) {
QName: "test",
RType: 3,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 3,
},
@@ -113,7 +113,7 @@ func TestCachesPrune(t *testing.T) {
QName: "test",
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 1,
},
@@ -125,7 +125,7 @@ func TestCachesPrune(t *testing.T) {
QName: "test",
RType: 2,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 2,
},
@@ -137,7 +137,7 @@ func TestCachesPrune(t *testing.T) {
QName: "test",
RType: 3,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 3,
},
@@ -193,7 +193,7 @@ func TestCaches_ExternalSave(t *testing.T) {
srv.Caches.init(0, 0, 0)
- _ = srv.Caches.upsert(answer)
+ srv.Caches.upsert(answer)
n, err = srv.Caches.ExternalSave(&w)
if err != nil {
@@ -202,7 +202,7 @@ func TestCaches_ExternalSave(t *testing.T) {
test.Assert(t, "Caches.ExternalSave", 1, n)
- msg, err = UnpackMessage(answer.msg.packet)
+ msg, err = UnpackMessage(answer.Message.packet)
if err != nil {
t.Fatal(err)
}
@@ -237,7 +237,7 @@ func TestCachesUpsert(t *testing.T) {
QName: "test",
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 1,
},
@@ -249,7 +249,7 @@ func TestCachesUpsert(t *testing.T) {
QName: "test",
RType: 1,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 3,
},
@@ -261,7 +261,7 @@ func TestCachesUpsert(t *testing.T) {
QName: "test",
RType: 2,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 2,
},
@@ -273,7 +273,7 @@ func TestCachesUpsert(t *testing.T) {
QName: "test",
RType: 2,
RClass: 1,
- msg: &Message{
+ Message: &Message{
Header: MessageHeader{
ID: 4,
},
diff --git a/lib/dns/request.go b/lib/dns/request.go
index 7bfacd28..dd1b0925 100644
--- a/lib/dns/request.go
+++ b/lib/dns/request.go
@@ -4,6 +4,7 @@
package dns
import (
+ "fmt"
"io"
"log"
"time"
@@ -44,6 +45,12 @@ func newRequest() (req *request) {
return req
}
+func (req *request) String() string {
+ return fmt.Sprintf(`{%d %s %s}`, req.message.Header.ID,
+ req.message.Question.Name,
+ RecordTypeNames[req.message.Question.Type])
+}
+
// error set the request message as an error.
func (req *request) error(rcode ResponseCode) {
var err error
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)
}
}