Add debugging for failed lookups (#199)

This PR adds debug support for failed lookups. I.e. when a record
is outside the configured domain, we do a forward lookup. If this
fails the error is silently dropped. This PR adds it back as an error
in when debugging is enabled.

Fixes #197

middleware/etcd/README.md

@@ -40,19 +40,7 @@ etcd [zones...] {
   the proxy middleware.
 * `tls` followed the cert, key and the CA's cert filenames.
 * `debug` allow debug queries. Prefix the name with `o-o.debug.` to retrieve extra information in the
-  additional section of the reply in the form of text records:
-
-    skydns.test.skydns.dom.a.	300	CH	TXT	"127.0.0.1:0(10,0,,false)[0,]"
-
-  This shows the complete key as the owername, the rdata of the TXT record has:
-  `host:port(priority,weight,txt content,mail)[targetstrip,group]`.
-
-  Any errors seen doing parsing will show up like this:
-
-    . 0 CH TXT "/skydns/local/skydns/r/a: invalid character '.' after object key:value pair"
-
-  which shows `a.r.skydns.local.` has a json encoding problem.
-
+  additional section of the reply in the form of text records.
 
 ## Examples
 
@@ -117,3 +105,26 @@ Or with *debug* queries enabled:
 ;; ADDITIONAL SECTION:
 127.0.0.10.in-addr.arpa. 300    CH      TXT     "reverse.atoom.net.:0(10,0,,false)[0,]"
 ~~~
+
+## Debug queries
+
+When debug queries are enabled CoreDNS will return errors and etcd records encountered during the resolution
+process in the response. The general form looks like this:
+
+    skydns.test.skydns.dom.a.	300	CH	TXT	"127.0.0.1:0(10,0,,false)[0,]"
+
+  This shows the complete key as the owername, the rdata of the TXT record has:
+  `host:port(priority,weight,txt content,mail)[targetstrip,group]`.
+
+  Any errors seen doing parsing will show up like this:
+
+    . 0 CH TXT "/skydns/local/skydns/r/a: invalid character '.' after object key:value pair"
+
+  which shows `a.r.skydns.local.` has a json encoding problem.
+
+  Errors when communicating with an upstream will be returned as:
+
+    . 0 CH TXT "example.org. IN A: unreachable backend"
+
+  Signalling that an A record for example.org. was sought, but it failed
+  with that error.

middleware/etcd/lookup.go

@@ -1,6 +1,7 @@
 package etcd
 
 import (
+	"errors"
 	"fmt"
 	"math"
 	"net"
@@ -73,8 +74,12 @@ func (e Etcd) A(zone string, state middleware.State, previousRecords []dns.RR, o
 			}
 			m1, e1 := e.Proxy.Lookup(state, target, state.QType())
 			if e1 != nil {
+				if opt.Debug != "" {
+					debugTxt := errorToTxt(errors.New(target + " IN " + state.Type() + ":" + e1.Error()))
+					records = append(records, debugTxt)
 					continue
 				}
+			}
 			// Len(m1.Answer) > 0 here is well?
 			records = append(records, newRecord)
 			records = append(records, m1.Answer...)
@@ -133,6 +138,8 @@ func (e Etcd) AAAA(zone string, state middleware.State, previousRecords []dns.RR
 			}
 			m1, e1 := e.Proxy.Lookup(state, target, state.QType())
 			if e1 != nil {
+				debugTxt := errorToTxt(errors.New(target + " IN " + state.Type() + ": " + e1.Error()))
+				records = append(records, debugTxt)
 				continue
 			}
 			// Len(m1.Answer) > 0 here is well?
@@ -195,7 +202,11 @@ func (e Etcd) SRV(zone string, state middleware.State, opt Options) (records, ex
 				m1, e1 := e.Proxy.Lookup(state, srv.Target, dns.TypeA)
 				if e1 == nil {
 					extra = append(extra, m1.Answer...)
+				} else {
+					debugTxt := errorToTxt(errors.New(srv.Target + " IN A: " + e1.Error()))
+					extra = append(extra, debugTxt)
 				}
+
 				m1, e1 = e.Proxy.Lookup(state, srv.Target, dns.TypeAAAA)
 				if e1 == nil {
 					// If we have seen CNAME's we *assume* that they are already added.
@@ -204,6 +215,9 @@ func (e Etcd) SRV(zone string, state middleware.State, opt Options) (records, ex
 							extra = append(extra, a)
 						}
 					}
+				} else {
+					debugTxt := errorToTxt(errors.New(srv.Target + " IN AAAA: " + e1.Error()))
+					extra = append(extra, debugTxt)
 				}
 				break
 			}
@@ -261,6 +275,9 @@ func (e Etcd) MX(zone string, state middleware.State, opt Options) (records, ext
 				m1, e1 := e.Proxy.Lookup(state, mx.Mx, dns.TypeA)
 				if e1 == nil {
 					extra = append(extra, m1.Answer...)
+				} else {
+					debugTxt := errorToTxt(errors.New(mx.Mx + " IN A: " + e1.Error()))
+					extra = append(extra, debugTxt)
 				}
 				m1, e1 = e.Proxy.Lookup(state, mx.Mx, dns.TypeAAAA)
 				if e1 == nil {
@@ -270,6 +287,9 @@ func (e Etcd) MX(zone string, state middleware.State, opt Options) (records, ext
 							extra = append(extra, a)
 						}
 					}
+				} else {
+					debugTxt := errorToTxt(errors.New(mx.Mx + " IN AAAA: " + e1.Error()))
+					extra = append(extra, debugTxt)
 				}
 				break
 			}

middleware/etcd/proxy_lookup_test.go

@@ -0,0 +1,77 @@
+// +build etcd
+
+package etcd
+
+import (
+	"sort"
+	"testing"
+
+	"github.com/miekg/coredns/middleware"
+	"github.com/miekg/coredns/middleware/etcd/msg"
+	"github.com/miekg/coredns/middleware/proxy"
+	"github.com/miekg/coredns/middleware/test"
+
+	"github.com/miekg/dns"
+)
+
+func TestProxyLookupFailDebug(t *testing.T) {
+	for _, serv := range servicesProxy {
+		set(t, etc, serv.Key, 0, serv)
+		defer delete(t, etc, serv.Key)
+	}
+
+	prxy := etc.Proxy
+	etc.Proxy = proxy.New([]string{"127.0.0.0:154"})
+	etc.Debug = true
+
+	defer func() { etc.Debug = false }()
+	defer func() { etc.Proxy = prxy }()
+
+	for _, tc := range dnsTestCasesProxy {
+		m := tc.Msg()
+
+		rec := middleware.NewResponseRecorder(&test.ResponseWriter{})
+		_, err := etc.ServeDNS(ctxt, rec, m)
+		if err != nil {
+			t.Errorf("expected no error, got %v\n", err)
+			continue
+		}
+		resp := rec.Msg()
+
+		sort.Sort(test.RRSet(resp.Answer))
+		sort.Sort(test.RRSet(resp.Ns))
+		sort.Sort(test.RRSet(resp.Extra))
+
+		if !test.Header(t, tc, resp) {
+			t.Logf("%v\n", resp)
+			continue
+		}
+		if !test.Section(t, tc, test.Answer, resp.Answer) {
+			t.Logf("%v\n", resp)
+		}
+		if !test.Section(t, tc, test.Ns, resp.Ns) {
+			t.Logf("%v\n", resp)
+		}
+		if !test.Section(t, tc, test.Extra, resp.Extra) {
+			t.Logf("%v\n", resp)
+		}
+	}
+}
+
+// Note the key is encoded as DNS name, while in "reality" it is a etcd path.
+var servicesProxy = []*msg.Service{
+	{Host: "www.example.org", Key: "a.dom.skydns.test."},
+}
+
+var dnsTestCasesProxy = []test.Case{
+	{
+		Qname: "dom.skydns.test.", Qtype: dns.TypeSRV,
+		Answer: []dns.RR{
+			test.SRV("dom.skydns.test. 300 IN SRV 10 100 0 www.example.org."),
+		},
+		Extra: []dns.RR{
+			test.TXT(".	0	CH	TXT	\"www.example.org. IN A: unreachable backend\""),
+			test.TXT(".	0	CH	TXT	\"www.example.org. IN AAAA: unreachable backend\""),
+		},
+	},
+}

middleware/etcd/setup_test.go

@@ -13,9 +13,9 @@ import (
 	"github.com/miekg/coredns/middleware/proxy"
 	"github.com/miekg/coredns/middleware/singleflight"
 	"github.com/miekg/coredns/middleware/test"
-	"github.com/miekg/dns"
 
 	etcdc "github.com/coreos/etcd/client"
+	"github.com/miekg/dns"
 	"golang.org/x/net/context"
 )