Pull request: all: simplify dnssec logic

Closes #3904.

Squashed commit of the following:

commit 5948f0d3519299a1253e388f4bc83e2e55847f68
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Dec 13 17:53:40 2021 +0300

    querylog: imp

commit 852cc7dbdb495a17ff51b99ab12901b846f8be09
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Dec 13 17:44:41 2021 +0300

    querylog: fix entry write

commit 9d58046899f35162596bfc94fe88fa944309b2fd
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Dec 13 16:45:56 2021 +0300

    all: simplify dnssec logic

internal/querylog/decode.go

@@ -119,6 +119,16 @@ var logEntryHandlers = map[string]logEntryHandler{
 
 		return nil
 	},
+	"AD": func(t json.Token, ent *logEntry) error {
+		v, ok := t.(bool)
+		if !ok {
+			return nil
+		}
+
+		ent.AuthenticatedData = v
+
+		return nil
+	},
 	"Upstream": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(string)
 		if !ok {

internal/querylog/decode_test.go

@@ -34,6 +34,7 @@ func TestDecodeLogEntry(t *testing.T) {
 			`"CP":"",` +
 			`"Answer":"` + ansStr + `",` +
 			`"Cached":true,` +
+			`"AD":true,` +
 			`"Result":{` +
 			`"IsFiltered":true,` +
 			`"Reason":3,` +
@@ -81,8 +82,9 @@ func TestDecodeLogEntry(t *testing.T) {
 					},
 				},
 			},
-			Upstream: "https://some.upstream",
-			Elapsed:  837429,
+			Upstream:          "https://some.upstream",
+			Elapsed:           837429,
+			AuthenticatedData: true,
 		}
 
 		got := &logEntry{}

internal/querylog/json.go

@@ -40,29 +40,19 @@ func (l *queryLog) entriesToJSON(entries []*logEntry, oldest time.Time) (res job
 	return res
 }
 
+// entryToJSON converts a log entry's data into an entry for the JSON API.
 func (l *queryLog) entryToJSON(entry *logEntry, anonFunc aghnet.IPMutFunc) (jsonEntry jobject) {
-	var msg *dns.Msg
-
-	if len(entry.Answer) > 0 {
-		msg = new(dns.Msg)
-		if err := msg.Unpack(entry.Answer); err != nil {
-			log.Debug("Failed to unpack dns message answer: %s: %s", err, string(entry.Answer))
-			msg = nil
-		}
-	}
-
 	hostname := entry.QHost
 	question := jobject{
 		"type":  entry.QType,
 		"class": entry.QClass,
 		"name":  hostname,
 	}
-	if qhost, err := idna.ToUnicode(hostname); err == nil {
-		if qhost != hostname && qhost != "" {
-			question["unicode_name"] = qhost
-		}
-	} else {
-		log.Debug("translating %q into unicode: %s", hostname, err)
+
+	if qhost, err := idna.ToUnicode(hostname); err != nil {
+		log.Debug("querylog: translating %q into unicode: %s", hostname, err)
+	} else if qhost != hostname && qhost != "" {
+		question["unicode_name"] = qhost
 	}
 
 	eip := netutil.CloneIP(entry.IP)
@@ -77,7 +67,9 @@ func (l *queryLog) entryToJSON(entry *logEntry, anonFunc aghnet.IPMutFunc) (json
 		"cached":       entry.Cached,
 		"upstream":     entry.Upstream,
 		"question":     question,
+		"rules":        resultRulesToJSONRules(entry.Result.Rules),
 	}
+
 	if eip.Equal(entry.IP) {
 		jsonEntry["client_info"] = entry.client
 	}
@@ -86,50 +78,65 @@ func (l *queryLog) entryToJSON(entry *logEntry, anonFunc aghnet.IPMutFunc) (json
 		jsonEntry["client_id"] = entry.ClientID
 	}
 
-	if msg != nil {
-		jsonEntry["status"] = dns.RcodeToString[msg.Rcode]
-
-		opt := msg.IsEdns0()
-		dnssecOk := false
-		if opt != nil {
-			dnssecOk = opt.Do()
+	if len(entry.Result.Rules) > 0 {
+		if r := entry.Result.Rules[0]; len(r.Text) > 0 {
+			jsonEntry["rule"] = r.Text
+			jsonEntry["filterId"] = r.FilterListID
 		}
-
-		jsonEntry["answer_dnssec"] = dnssecOk
-	}
-
-	jsonEntry["rules"] = resultRulesToJSONRules(entry.Result.Rules)
-
-	if len(entry.Result.Rules) > 0 && len(entry.Result.Rules[0].Text) > 0 {
-		jsonEntry["rule"] = entry.Result.Rules[0].Text
-		jsonEntry["filterId"] = entry.Result.Rules[0].FilterListID
 	}
 
 	if len(entry.Result.ServiceName) != 0 {
 		jsonEntry["service_name"] = entry.Result.ServiceName
 	}
 
-	answers := answerToMap(msg)
-	if answers != nil {
-		jsonEntry["answer"] = answers
-	}
-
-	if len(entry.OrigAnswer) != 0 {
-		a := new(dns.Msg)
-		err := a.Unpack(entry.OrigAnswer)
-		if err == nil {
-			answers = answerToMap(a)
-			if answers != nil {
-				jsonEntry["original_answer"] = answers
-			}
-		} else {
-			log.Debug("Querylog: msg.Unpack(entry.OrigAnswer): %s: %s", err, string(entry.OrigAnswer))
-		}
-	}
+	l.setMsgData(entry, jsonEntry)
+	l.setOrigAns(entry, jsonEntry)
 
 	return jsonEntry
 }
 
+// setMsgData sets the message data in jsonEntry.
+func (l *queryLog) setMsgData(entry *logEntry, jsonEntry jobject) {
+	if len(entry.Answer) == 0 {
+		return
+	}
+
+	msg := &dns.Msg{}
+	if err := msg.Unpack(entry.Answer); err != nil {
+		log.Debug("querylog: failed to unpack dns msg answer: %v: %s", entry.Answer, err)
+
+		return
+	}
+
+	jsonEntry["status"] = dns.RcodeToString[msg.Rcode]
+	// Old query logs may still keep AD flag value in the message.  Try to get
+	// it from there as well.
+	jsonEntry["answer_dnssec"] = entry.AuthenticatedData || msg.AuthenticatedData
+
+	if a := answerToMap(msg); a != nil {
+		jsonEntry["answer"] = a
+	}
+}
+
+// setOrigAns sets the original answer data in jsonEntry.
+func (l *queryLog) setOrigAns(entry *logEntry, jsonEntry jobject) {
+	if len(entry.OrigAnswer) == 0 {
+		return
+	}
+
+	orig := &dns.Msg{}
+	err := orig.Unpack(entry.OrigAnswer)
+	if err != nil {
+		log.Debug("querylog: orig.Unpack(entry.OrigAnswer): %v: %s", entry.OrigAnswer, err)
+
+		return
+	}
+
+	if a := answerToMap(orig); a != nil {
+		jsonEntry["original_answer"] = a
+	}
+}
+
 func resultRulesToJSONRules(rules []*filtering.ResultRule) (jsonRules []jobject) {
 	jsonRules = make([]jobject, len(rules))
 	for i, r := range rules {

internal/querylog/qlog.go

@@ -75,7 +75,6 @@ type logEntry struct {
 	// client is the found client information, if any.
 	client *Client
 
-	IP   net.IP    `json:"IP"` // Client IP
 	Time time.Time `json:"T"`
 
 	QHost  string `json:"QH"`
@@ -87,11 +86,16 @@ type logEntry struct {
 
 	Answer     []byte `json:",omitempty"` // sometimes empty answers happen like binerdunt.top or rev2.globalrootservers.net
 	OrigAnswer []byte `json:",omitempty"`
-	Cached     bool   `json:",omitempty"`
 
 	Result   filtering.Result
-	Elapsed  time.Duration
 	Upstream string `json:",omitempty"`
+
+	IP net.IP `json:"IP"`
+
+	Elapsed time.Duration
+
+	Cached            bool `json:",omitempty"`
+	AuthenticatedData bool `json:"AD,omitempty"`
 }
 
 func (l *queryLog) Start() {
@@ -146,14 +150,12 @@ func (l *queryLog) clear() {
 	log.Debug("Query log: cleared")
 }
 
-func (l *queryLog) Add(params AddParams) {
-	var err error
-
+func (l *queryLog) Add(params *AddParams) {
 	if !l.conf.Enabled {
 		return
 	}
 
-	err = params.validate()
+	err := params.validate()
 	if err != nil {
 		log.Error("querylog: adding record: %s, skipping", err)
 
@@ -165,21 +167,27 @@ func (l *queryLog) Add(params AddParams) {
 	}
 
 	now := time.Now()
+	q := params.Question.Question[0]
 	entry := logEntry{
-		IP:   params.ClientIP,
 		Time: now,
 
-		Result:      *params.Result,
-		Elapsed:     params.Elapsed,
-		Upstream:    params.Upstream,
-		Cached:      params.Cached,
+		QHost:  strings.ToLower(q.Name[:len(q.Name)-1]),
+		QType:  dns.Type(q.Qtype).String(),
+		QClass: dns.Class(q.Qclass).String(),
+
 		ClientID:    params.ClientID,
 		ClientProto: params.ClientProto,
+
+		Result:   *params.Result,
+		Upstream: params.Upstream,
+
+		IP: params.ClientIP,
+
+		Elapsed: params.Elapsed,
+
+		Cached:            params.Cached,
+		AuthenticatedData: params.AuthenticatedData,
 	}
-	q := params.Question.Question[0]
-	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()
 
 	if params.Answer != nil {
 		var a []byte

internal/querylog/qlog_test.go

@@ -269,6 +269,7 @@ func addEntry(l *queryLog, host string, answerStr, client net.IP) {
 			A: answerStr,
 		}},
 	}
+
 	res := filtering.Result{
 		IsFiltered:  true,
 		Reason:      filtering.Rewritten,
@@ -278,7 +279,8 @@ func addEntry(l *queryLog, host string, answerStr, client net.IP) {
 			Text:         "SomeRule",
 		}},
 	}
-	params := AddParams{
+
+	params := &AddParams{
 		Question:   &q,
 		Answer:     &a,
 		OrigAnswer: &a,
@@ -286,6 +288,7 @@ func addEntry(l *queryLog, host string, answerStr, client net.IP) {
 		ClientIP:   client,
 		Upstream:   "upstream",
 	}
+
 	l.Add(params)
 }
 

internal/querylog/querylog.go

@@ -22,7 +22,7 @@ type QueryLog interface {
 	Close()
 
 	// Add a log entry
-	Add(params AddParams)
+	Add(params *AddParams)
 
 	// WriteDiskConfig - write configuration
 	WriteDiskConfig(c *Config)
@@ -76,22 +76,34 @@ type Config struct {
 // AddParams is the parameters for adding an entry.
 type AddParams struct {
 	Question *dns.Msg
+
 	// Answer is the response which is sent to the client, if any.
 	Answer *dns.Msg
+
 	// OrigAnswer is the response from an upstream server.  It's only set if the
 	// answer has been modified by filtering.
 	OrigAnswer *dns.Msg
-	// Cached indicates if the response is served from cache.
-	Cached bool
+
 	// Result is the filtering result (optional).
 	Result *filtering.Result
+
 	// Elapsed is the time spent for processing the request.
-	Elapsed  time.Duration
+	Elapsed time.Duration
+
 	ClientID string
+
 	ClientIP net.IP
+
 	// Upstream is the URL of the upstream DNS server.
-	Upstream    string
+	Upstream string
+
 	ClientProto ClientProto
+
+	// Cached indicates if the response is served from cache.
+	Cached bool
+
+	// AuthenticatedData shows if the response had the AD bit set.
+	AuthenticatedData bool
 }
 
 // validate returns an error if the parameters aren't valid.

internal/querylog/search_test.go

@@ -52,20 +52,20 @@ func TestQueryLog_Search_findClient(t *testing.T) {
 		}},
 	}
 
-	l.Add(AddParams{
+	l.Add(&AddParams{
 		Question: q,
 		ClientID: knownClientID,
 		ClientIP: net.IP{1, 2, 3, 4},
 	})
 
 	// Add the same thing again to test the cache.
-	l.Add(AddParams{
+	l.Add(&AddParams{
 		Question: q,
 		ClientID: knownClientID,
 		ClientIP: net.IP{1, 2, 3, 4},
 	})
 
-	l.Add(AddParams{
+	l.Add(&AddParams{
 		Question: q,
 		ClientID: unknownClientID,
 		ClientIP: net.IP{1, 2, 3, 5},