log/forward plugins: Extend dns query logging (#2240)

Automatically submitted.

7 files changed, 55 insertions, 5 deletions

diff --git a/plugin/forward/README.md b/plugin/forward/README.md
index c0a426aab..39c00bce8 100644
--- a/plugin/forward/README.md
+++ b/plugin/forward/README.md
@@ -91,6 +91,10 @@ On each endpoint, the timeouts of the communication are set by default and autom
 * dialTimeout by default is 30 sec, and can decrease automatically down to 100ms
 * readTimeout by default is 2 sec, and can decrease automatically down to 200ms
 
+## Metadata
+
+* forward/resolving_proxy : provide the IP address and port of the upstream resolver used to resolve the current DNS query.
+
 ## Metrics
 
 If monitoring is enabled (via the *prometheus* directive) then the following metric are exported:
diff --git a/plugin/forward/forward.go b/plugin/forward/forward.go
index dfa1aaca1..02824d184 100644
--- a/plugin/forward/forward.go
+++ b/plugin/forward/forward.go
@@ -12,6 +12,7 @@ import (
 
 	"github.com/coredns/coredns/plugin"
 	"github.com/coredns/coredns/plugin/debug"
+	"github.com/coredns/coredns/plugin/metadata"
 	clog "github.com/coredns/coredns/plugin/pkg/log"
 	"github.com/coredns/coredns/request"
 
@@ -59,6 +60,15 @@ func (f *Forward) Len() int { return len(f.proxies) }
 // Name implements plugin.Handler.
 func (f *Forward) Name() string { return "forward" }
 
+//declareMetadata adds to the context a metadata parameter which will return the passed value.
+func (f *Forward) declareMetadata(ctx context.Context, name string, value string) bool {
+	label := f.Name()+"/"+name
+	if metadata.IsLabel(label) {
+		return metadata.SetValueFunc(ctx, label, func() string { return value })
+	}
+	return false
+}
+
 // ServeDNS implements plugin.Handler.
 func (f *Forward) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
 
@@ -148,10 +158,12 @@ func (f *Forward) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg
 
 			formerr := state.ErrorMessage(dns.RcodeFormatError)
 			w.WriteMsg(formerr)
+			f.declareMetadata(ctx, "resolving_proxy", proxy.addr)
 			return 0, nil
 		}
 
 		w.WriteMsg(ret)
+		f.declareMetadata(ctx, "resolving_proxy", proxy.addr)
 		return 0, nil
 	}
 
diff --git a/plugin/log/README.md b/plugin/log/README.md
index 65cca19c8..787ec49a2 100644
--- a/plugin/log/README.md
+++ b/plugin/log/README.md
@@ -72,6 +72,10 @@ The following place holders are supported:
 * `{>do}`: is the EDNS0 DO (DNSSEC OK) bit set in the query
 * `{>id}`: query ID
 * `{>opcode}`: query OPCODE
+* `{local}`: server's IP address, for IPv6 addresses these are enclosed in brackets: `[::1]`
+* `{A}`: number of the A type answers in the response
+* `{AAAA}`: number of the AAAA type answers in the response
+* `{forward/resolving_proxy}`: if the query was forwarded to a resolver, the IP address and port of that replied resolver, else empty. The metadata plugin needs to be enabled to use this placeholder
 
 The default Common Log Format is:
 
diff --git a/plugin/log/log.go b/plugin/log/log.go
index f52a70344..028188d51 100644
--- a/plugin/log/log.go
+++ b/plugin/log/log.go
@@ -57,7 +57,7 @@ func (l Logger) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg)
 		// If we don't set up a class in config, the default "all" will be added
 		// and we shouldn't have an empty rule.Class.
 		if rule.Class[response.All] || rule.Class[class] {
-			rep := replacer.New(r, rrw, CommonLogEmptyValue)
+			rep := replacer.New(ctx, r, rrw, CommonLogEmptyValue)
 			rule.Log.Println(rep.Replace(rule.Format))
 		}
 
diff --git a/plugin/pkg/replacer/replacer.go b/plugin/pkg/replacer/replacer.go
index b9e1fcaa6..1d65967e0 100644
--- a/plugin/pkg/replacer/replacer.go
+++ b/plugin/pkg/replacer/replacer.go
@@ -1,11 +1,13 @@
 package replacer
 
 import (
+	"context"
 	"strconv"
 	"strings"
 	"time"
 
 	"github.com/coredns/coredns/plugin/pkg/dnstest"
+	"github.com/coredns/coredns/plugin/metadata"
 	"github.com/coredns/coredns/request"
 
 	"github.com/miekg/dns"
@@ -31,7 +33,7 @@ type replacer struct {
 // values into the replacer. rr may be nil if it is not
 // available. emptyValue should be the string that is used
 // in place of empty string (can still be empty string).
-func New(r *dns.Msg, rr *dnstest.Recorder, emptyValue string) Replacer {
+func New(ctx context.Context, r *dns.Msg, rr *dnstest.Recorder, emptyValue string) Replacer {
 	req := request.Request{W: rr, Req: r}
 	rep := replacer{
 		replacements: map[string]string{
@@ -45,6 +47,8 @@ func New(r *dns.Msg, rr *dnstest.Recorder, emptyValue string) Replacer {
 			"{size}":   strconv.Itoa(req.Len()),
 			"{remote}": addrToRFC3986(req.IP()),
 			"{port}":   req.Port(),
+			"{local}":  addrToRFC3986(req.LocalIP()),
+			"{forward/resolving_proxy}": getMetadata(ctx, "forward/resolving_proxy"),
 		},
 		emptyValue: emptyValue,
 	}
@@ -58,6 +62,8 @@ func New(r *dns.Msg, rr *dnstest.Recorder, emptyValue string) Replacer {
 		rep.replacements["{duration}"] = strconv.FormatFloat(time.Since(rr.Start).Seconds(), 'f', -1, 64) + "s"
 		if rr.Msg != nil {
 			rep.replacements[headerReplacer+"rflags}"] = flagsToString(rr.Msg.MsgHdr)
+			rep.replacements["{A}"] = answersCount(rr.Msg, dns.TypeA)
+			rep.replacements["{AAAA}"] = answersCount(rr.Msg, dns.TypeAAAA)
 		}
 	}
 
@@ -163,6 +169,30 @@ func addrToRFC3986(addr string) string {
 	return addr
 }
 
+//getMetadata will return value from Metadata or empty string
+func getMetadata(ctx context.Context, label string) string {
+	if ctx != nil {
+		valueFunc := metadata.ValueFunc(ctx, label)
+		if valueFunc != nil {
+			return valueFunc()
+		}
+	}
+	return ""
+}
+
+//answersCount will calculate a number of answers which have the type passed
+func answersCount(m *dns.Msg, rtype uint16) string {
+	count := 0
+	if m != nil {
+		for i := 0; i < len(m.Answer); i++ {
+			if m.Answer[i].Header().Rrtype == rtype {
+				count++
+			}
+		}
+	}
+	return strconv.Itoa(count)
+}
+
 const (
 	timeFormat     = "02/Jan/2006:15:04:05 -0700"
 	headerReplacer = "{>"
diff --git a/plugin/pkg/replacer/replacer_test.go b/plugin/pkg/replacer/replacer_test.go
index 2fcaafc92..53b41510f 100644
--- a/plugin/pkg/replacer/replacer_test.go
+++ b/plugin/pkg/replacer/replacer_test.go
@@ -17,7 +17,7 @@ func TestNewReplacer(t *testing.T) {
 	r.SetQuestion("example.org.", dns.TypeHINFO)
 	r.MsgHdr.AuthenticatedData = true
 
-	replaceValues := New(r, w, "")
+	replaceValues := New(nil, r, w, "")
 
 	switch v := replaceValues.(type) {
 	case replacer:
@@ -47,7 +47,7 @@ func TestSet(t *testing.T) {
 	r.SetQuestion("example.org.", dns.TypeHINFO)
 	r.MsgHdr.AuthenticatedData = true
 
-	repl := New(r, w, "")
+	repl := New(nil, r, w, "")
 
 	repl.Set("name", "coredns.io.")
 	repl.Set("type", "A")
diff --git a/plugin/rewrite/condition.go b/plugin/rewrite/condition.go
index f8d2a9f08..fc5bd2c66 100644
--- a/plugin/rewrite/condition.go
+++ b/plugin/rewrite/condition.go
@@ -22,7 +22,7 @@ const (
 	NotMatch   = "not_match"
 )
 
-func newReplacer(r *dns.Msg) replacer.Replacer { return replacer.New(r, nil, "") }
+func newReplacer(r *dns.Msg) replacer.Replacer { return replacer.New(nil, r, nil, "") }
 
 // condition is a rewrite condition.
 type condition func(string, string) bool