all: imp upstream info in querylog

CHANGELOG.md

@@ -15,6 +15,7 @@ and this project adheres to
 
 ### Added
 
+- Upstream server information for responses from cache ([#3772]).
 - Finnish and Ukrainian translations.
 - Setting the timeout for IP address pinging in the "Fastest IP address" mode
   through the new `fastest_timeout` field in the configuration file ([#1992]).
@@ -47,6 +48,7 @@ and this project adheres to
 
 ### Changed
 
+- Responses from cache are now labeled ([#3772]).
 - Better error message for ED25519 private keys, which are not widely supported
   ([#3737]).
 - Cache now follows RFC more closely for negative answers ([#3707]).
@@ -221,6 +223,7 @@ In this release, the schema version has changed from 10 to 12.
 [#3655]: https://github.com/AdguardTeam/AdGuardHome/issues/3655
 [#3707]: https://github.com/AdguardTeam/AdGuardHome/issues/3707
 [#3744]: https://github.com/AdguardTeam/AdGuardHome/issues/3744
+[#3772]: https://github.com/AdguardTeam/AdGuardHome/issues/3772
 [#3815]: https://github.com/AdguardTeam/AdGuardHome/issues/3815
 
 

go.mod

@@ -3,8 +3,8 @@ module github.com/AdguardTeam/AdGuardHome
 go 1.16
 
 require (
-	github.com/AdguardTeam/dnsproxy v0.39.9
-	github.com/AdguardTeam/golibs v0.10.2
+	github.com/AdguardTeam/dnsproxy v0.39.12
+	github.com/AdguardTeam/golibs v0.10.3
 	github.com/AdguardTeam/urlfilter v0.15.0
 	github.com/NYTimes/gziphandler v1.1.1
 	github.com/ameshkov/dnscrypt/v2 v2.2.2

go.sum

@@ -9,13 +9,13 @@ dmitri.shuralyov.com/state v0.0.0-20180228185332-28bcc343414c/go.mod h1:0PRwlb0D
 git.apache.org/thrift.git v0.0.0-20180902110319-2566ecd5d999/go.mod h1:fPE2ZNJGynbRyZ4dJvy6G277gSllfV2HJqblrnkyeyg=
 github.com/AdguardTeam/dhcp v0.0.0-20210519141215-51808c73c0bf h1:gc042VRSIRSUzZ+Px6xQCRWNJZTaPkomisDfUZmoFNk=
 github.com/AdguardTeam/dhcp v0.0.0-20210519141215-51808c73c0bf/go.mod h1:TKl4jN3Voofo4UJIicyNhWGp/nlQqQkFxmwIFTvBkKI=
-github.com/AdguardTeam/dnsproxy v0.39.9 h1:lH4lKA7KHKFJZgzlij1YAVX6v7eIQpUFpYh9qV+WfGw=
-github.com/AdguardTeam/dnsproxy v0.39.9/go.mod h1:eDpJKAdkHORRwAedjuERv+7SWlcz4cn+5uwrbUAWHRY=
+github.com/AdguardTeam/dnsproxy v0.39.12 h1:BxAfdQLGnu0rqhD23K5nNw09sKQeqpT2AkFEE78WOqU=
+github.com/AdguardTeam/dnsproxy v0.39.12/go.mod h1:g7zjF1TWpKNeDVh6h3YrjQN8565zsWRd7zo++C/935c=
 github.com/AdguardTeam/golibs v0.4.0/go.mod h1:skKsDKIBB7kkFflLJBpfGX+G8QFTx0WKUzB6TIgtUj4=
 github.com/AdguardTeam/golibs v0.4.2/go.mod h1:skKsDKIBB7kkFflLJBpfGX+G8QFTx0WKUzB6TIgtUj4=
 github.com/AdguardTeam/golibs v0.9.2/go.mod h1:fCAMwPBJ8S7YMYbTWvYS+eeTLblP5E04IDtNAo7y7IY=
-github.com/AdguardTeam/golibs v0.10.2 h1:TAwnS4Y49sSUa4UX1yz/MWNGbIlXHqafrWr9MxdIh9A=
-github.com/AdguardTeam/golibs v0.10.2/go.mod h1:rSfQRGHIdgfxriDDNgNJ7HmE5zRoURq8R+VdR81Zuzw=
+github.com/AdguardTeam/golibs v0.10.3 h1:FBgk17zf35ESVWQKIqEUiqqB2bDaCBC8X5vMU760yB4=
+github.com/AdguardTeam/golibs v0.10.3/go.mod h1:rSfQRGHIdgfxriDDNgNJ7HmE5zRoURq8R+VdR81Zuzw=
 github.com/AdguardTeam/gomitmproxy v0.2.0/go.mod h1:Qdv0Mktnzer5zpdpi5rAwixNJzW2FN91LjKJCkVbYGU=
 github.com/AdguardTeam/urlfilter v0.15.0 h1:K3WWZE0K5nPTHe2l+TRXDFpYWJJnvkHdlWidt6NQUTk=
 github.com/AdguardTeam/urlfilter v0.15.0/go.mod h1:EwXwrYhowP7bedqmOrmKKmQtpBYFyDNEBFQ+lxdUgQU=
@@ -64,7 +64,6 @@ github.com/go-ole/go-ole v1.2.5 h1:t4MGB5xEDZvXI+0rMjjsfBsD7yAgp/s9ZDkL1JndXwY=
 github.com/go-ole/go-ole v1.2.5/go.mod h1:pprOEPIfldk/42T2oK7lQ4v4JSDwmV0As9GaiUsvbm0=
 github.com/go-ping/ping v0.0.0-20210506233800-ff8be3320020 h1:mdi6AbCEoKCA1xKCmp7UtRB5fvGFlP92PvlhxgdvXEw=
 github.com/go-ping/ping v0.0.0-20210506233800-ff8be3320020/go.mod h1:KmHOjTUmJh/l04ukqPoBWPEZr9jwN05h5NXQl5C+DyY=
-github.com/go-test/deep v1.0.5 h1:AKODKU3pDH1RzZzm6YZu77YWtEAq6uh1rLIAQlay2qc=
 github.com/go-test/deep v1.0.5/go.mod h1:QV8Hv/iy04NyLBxAdO9njL0iVPN1S4d/A3NVv1V36o8=
 github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ=
 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q=

internal/dnsforward/stats.go

@@ -28,8 +28,9 @@ func (s *Server) processQueryLogsAndStats(ctx *dnsContext) (rc resultCode) {
 	s.serverLock.RLock()
 	defer s.serverLock.RUnlock()
 
-	// Synchronize access to s.queryLog and s.stats so they won't be suddenly uninitialized while in use.
-	// This can happen after proxy server has been stopped, but its workers haven't yet exited.
+	// Synchronize access to s.queryLog and s.stats so they won't be suddenly
+	// uninitialized while in use.  This can happen after proxy server has been
+	// stopped, but its workers haven't yet exited.
 	if shouldLog && s.queryLog != nil {
 		ip, _ := netutil.IPAndPortFromAddr(pctx.Addr)
 		p := querylog.AddParams{
@@ -52,12 +53,14 @@ func (s *Server) processQueryLogsAndStats(ctx *dnsContext) (rc resultCode) {
 		case proxy.ProtoDNSCrypt:
 			p.ClientProto = querylog.ClientProtoDNSCrypt
 		default:
-			// Consider this a plain DNS-over-UDP or DNS-over-TCP
-			// request.
+			// Consider this a plain DNS-over-UDP or DNS-over-TCP request.
 		}
 
 		if pctx.Upstream != nil {
 			p.Upstream = pctx.Upstream.Address()
+		} else if cachedUps := pctx.CachedUpstreamAddr; cachedUps != "" {
+			p.Upstream = pctx.CachedUpstreamAddr
+			p.Cached = true
 		}
 
 		s.queryLog.Add(p)

internal/querylog/decode.go

@@ -44,8 +44,10 @@ var logEntryHandlers = map[string]logEntryHandler{
 		if !ok {
 			return nil
 		}
+
 		var err error
 		ent.Time, err = time.Parse(time.RFC3339, v)
+
 		return err
 	},
 	"QH": func(t json.Token, ent *logEntry) error {
@@ -69,54 +71,77 @@ var logEntryHandlers = map[string]logEntryHandler{
 		if !ok {
 			return nil
 		}
+
 		ent.QClass = v
+
 		return nil
 	},
 	"CP": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(string)
 		if !ok {
 			return nil
 		}
+
 		var err error
 		ent.ClientProto, err = NewClientProto(v)
+
 		return err
 	},
 	"Answer": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(string)
 		if !ok {
 			return nil
 		}
+
 		var err error
 		ent.Answer, err = base64.StdEncoding.DecodeString(v)
+
 		return err
 	},
 	"OrigAnswer": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(string)
 		if !ok {
 			return nil
 		}
+
 		var err error
 		ent.OrigAnswer, err = base64.StdEncoding.DecodeString(v)
+
 		return err
 	},
+	"Cached": func(t json.Token, ent *logEntry) error {
+		v, ok := t.(bool)
+		if !ok {
+			return nil
+		}
+
+		ent.Cached = v
+
+		return nil
+	},
 	"Upstream": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(string)
 		if !ok {
 			return nil
 		}
+
 		ent.Upstream = v
+
 		return nil
 	},
 	"Elapsed": func(t json.Token, ent *logEntry) error {
 		v, ok := t.(json.Number)
 		if !ok {
 			return nil
 		}
+
 		i, err := v.Int64()
 		if err != nil {
 			return err
 		}
+
 		ent.Elapsed = time.Duration(i)
+
 		return nil
 	},
 }

internal/querylog/decode_test.go

@@ -33,6 +33,7 @@ func TestDecodeLogEntry(t *testing.T) {
 			`"QC":"IN",` +
 			`"CP":"",` +
 			`"Answer":"` + ansStr + `",` +
+			`"Cached":true,` +
 			`"Result":{` +
 			`"IsFiltered":true,` +
 			`"Reason":3,` +
@@ -42,6 +43,7 @@ func TestDecodeLogEntry(t *testing.T) {
 			`"CanonName":"example.com",` +
 			`"ServiceName":"example.org",` +
 			`"DNSRewriteResult":{"RCode":0,"Response":{"1":["127.0.0.2"]}}},` +
+			`"Upstream":"https://some.upstream",` +
 			`"Elapsed":837429}`
 
 		ans, err := base64.StdEncoding.DecodeString(ansStr)
@@ -56,6 +58,7 @@ func TestDecodeLogEntry(t *testing.T) {
 			ClientID:    "cli42",
 			ClientProto: "",
 			Answer:      ans,
+			Cached:      true,
 			Result: filtering.Result{
 				IsFiltered: true,
 				Reason:     filtering.FilteredBlockList,
@@ -78,7 +81,8 @@ func TestDecodeLogEntry(t *testing.T) {
 					},
 				},
 			},
-			Elapsed: 837429,
+			Upstream: "https://some.upstream",
+			Elapsed:  837429,
 		}
 
 		got := &logEntry{}

internal/querylog/json.go

@@ -88,6 +88,7 @@ func (l *queryLog) logEntryToJSONEntry(entry *logEntry) (jsonEntry jobject) {
 		"client":       l.getClientIP(entry.IP),
 		"client_info":  entry.client,
 		"client_proto": entry.ClientProto,
+		"cached":       entry.Cached,
 		"upstream":     entry.Upstream,
 		"question":     question,
 	}

internal/querylog/qlog.go

@@ -84,10 +84,11 @@ 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"` // if empty, means it was cached
+	Upstream string `json:",omitempty"`
 }
 
 func (l *queryLog) Start() {
@@ -168,6 +169,7 @@ func (l *queryLog) Add(params AddParams) {
 		Result:      *params.Result,
 		Elapsed:     params.Elapsed,
 		Upstream:    params.Upstream,
+		Cached:      params.Cached,
 		ClientID:    params.ClientID,
 		ClientProto: params.ClientProto,
 	}

internal/querylog/querylog.go

@@ -69,16 +69,24 @@ type Config struct {
 	AnonymizeClientIP bool
 }
 
-// AddParams - parameters for Add()
+// AddParams is the parameters for adding an entry.
 type AddParams struct {
-	Question    *dns.Msg
-	Answer      *dns.Msg          // The response we sent to the client (optional)
-	OrigAnswer  *dns.Msg          // The response from an upstream server (optional)
-	Result      *filtering.Result // Filtering result (optional)
-	Elapsed     time.Duration     // Time spent for processing the request
-	ClientID    string
-	ClientIP    net.IP
-	Upstream    string // Upstream server URL
+	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
+	ClientID string
+	ClientIP net.IP
+	// Upstream is the URL of the upstream DNS server.
+	Upstream    string
 	ClientProto ClientProto
 }
 

openapi/CHANGELOG.md

@@ -4,6 +4,11 @@
 
 ## v0.107: API changes
 
+## The new field `"cached"` in `QueryLogItem`
+
+* The new field `"cached"` in `GET /control/querylog` is true if the response is
+  served from cache instead of being resolved by an upstream server.
+
 ### New possible value of `"name"` field in `QueryLogItemClient`
 
 * The value of `"name"` field in `GET /control/querylog` method is never empty:

openapi/openapi.yaml

@@ -1868,6 +1868,10 @@
           'description': 'Answer from upstream server (optional)'
           'items':
             '$ref': '#/components/schemas/DnsAnswer'
+        'cached':
+          'type': 'boolean'
+          'description': >
+            Defines if the response has been served from cache.
         'upstream':
           'type': 'string'
           'description': >