mw/proxy: simplify google code (#1019)

* mw/proxy: simplify google code

Minimize bootstrap code a bit, and block on the first resolve of the
google https endpont. Add more logging and include actual error in the
returned errors.

Also re-resolve every 120 seconds, instead of 300 (might eventually make
this an option).

* fix test

5 files changed, 46 insertions, 41 deletions

diff --git a/middleware/etcd/proxy_lookup_test.go b/middleware/etcd/proxy_lookup_test.go
index aa9de9281..ccda417c2 100644
--- a/middleware/etcd/proxy_lookup_test.go
+++ b/middleware/etcd/proxy_lookup_test.go
@@ -50,8 +50,8 @@ var dnsTestCasesProxy = []test.Case{
 		},
 		Extra: []dns.RR{
 			test.TXT("a.dom.skydns.test.	300	CH	TXT	\"www.example.org:0(10,0,,false)[0,]\""),
-			test.TXT("www.example.org.	0	CH	TXT	\"www.example.org.:0(0,0, IN A: unreachable backend,false)[0,]\""),
-			test.TXT("www.example.org.	0	CH	TXT	\"www.example.org.:0(0,0, IN AAAA: unreachable backend,false)[0,]\""),
+			test.TXT("www.example.org.	0	CH	TXT	\"www.example.org.:0(0,0, IN A: unreachable backend: no upstream host,false)[0,]\""),
+			test.TXT("www.example.org.	0	CH	TXT	\"www.example.org.:0(0,0, IN AAAA: unreachable backend: no upstream host,false)[0,]\""),
 		},
 	},
 }
diff --git a/middleware/proxy/google.go b/middleware/proxy/google.go
index 7b215f517..205b09379 100644
--- a/middleware/proxy/google.go
+++ b/middleware/proxy/google.go
@@ -112,11 +112,8 @@ func (g *google) exchangeJSON(addr, json string) ([]byte, error) {
 	return buf, nil
 }
 
-func (g *google) Transport() string {
-	return "tcp"
-}
-
-func (g *google) Protocol() string { return "https_google" }
+func (g *google) Transport() string { return "tcp" }
+func (g *google) Protocol() string  { return "https_google" }
 
 func (g *google) OnShutdown(p *Proxy) error {
 	g.quit <- true
@@ -130,52 +127,56 @@ func (g *google) OnStartup(p *Proxy) error {
 	req.SetQuestion(g.endpoint, dns.TypeA)
 	state := request.Request{W: new(fakeBootWriter), Req: req}
 
-	new, err := g.bootstrapProxy.Lookup(state, g.endpoint, dns.TypeA)
+	if len(*p.Upstreams) == 0 {
+		return fmt.Errorf("no upstreams defined")
+	}
 
-	var oldUpstream Upstream
+	oldUpstream := (*p.Upstreams)[0]
 
-	// ignore errors here, as we want to keep on trying.
+	log.Printf("[INFO] Bootstrapping A records %q", g.endpoint)
+
+	new, err := g.bootstrapProxy.Lookup(state, g.endpoint, dns.TypeA)
 	if err != nil {
 		log.Printf("[WARNING] Failed to bootstrap A records %q: %s", g.endpoint, err)
 	} else {
 		addrs, err1 := extractAnswer(new)
 		if err1 != nil {
-			log.Printf("[WARNING] Failed to bootstrap A records %q: %s", g.endpoint, err)
-		}
+			log.Printf("[WARNING] Failed to bootstrap A records %q: %s", g.endpoint, err1)
+		} else {
 
-		if len(*p.Upstreams) > 0 {
-			oldUpstream = (*p.Upstreams)[0]
 			up := newUpstream(addrs, oldUpstream.(*staticUpstream))
 			p.Upstreams = &[]Upstream{up}
-		} else {
-			log.Printf("[WARNING] Failed to bootstrap upstreams %q", g.endpoint)
+
+			log.Printf("[INFO] Bootstrapping A records %q found: %v", g.endpoint, addrs)
 		}
 	}
 
 	go func() {
-		tick := time.NewTicker(300 * time.Second)
+		tick := time.NewTicker(120 * time.Second)
 
 		for {
 			select {
 			case <-tick.C:
 
+				log.Printf("[INFO] Resolving A records %q", g.endpoint)
+
 				new, err := g.bootstrapProxy.Lookup(state, g.endpoint, dns.TypeA)
 				if err != nil {
-					log.Printf("[WARNING] Failed to bootstrap A records %q: %s", g.endpoint, err)
-				} else {
-					addrs, err1 := extractAnswer(new)
-					if err1 != nil {
-						log.Printf("[WARNING] Failed to bootstrap A records %q: %s", g.endpoint, err)
-						continue
-					}
+					log.Printf("[WARNING] Failed to resolve A records %q: %s", g.endpoint, err)
+					continue
+				}
 
-					// TODO(miek): can this actually happen?
-					if oldUpstream != nil {
-						up := newUpstream(addrs, oldUpstream.(*staticUpstream))
-						p.Upstreams = &[]Upstream{up}
-					}
+				addrs, err1 := extractAnswer(new)
+				if err1 != nil {
+					log.Printf("[WARNING] Failed to resolve A records %q: %s", g.endpoint, err1)
+					continue
 				}
 
+				up := newUpstream(addrs, oldUpstream.(*staticUpstream))
+				p.Upstreams = &[]Upstream{up}
+
+				log.Printf("[INFO] Resolving A records %q found: %v", g.endpoint, addrs)
+
 			case <-g.quit:
 				return
 			}
diff --git a/middleware/proxy/lookup.go b/middleware/proxy/lookup.go
index eda0d0a0c..1963e7dbd 100644
--- a/middleware/proxy/lookup.go
+++ b/middleware/proxy/lookup.go
@@ -4,6 +4,7 @@ package proxy
 
 import (
 	"context"
+	"fmt"
 	"sync/atomic"
 	"time"
 
@@ -14,9 +15,7 @@ import (
 )
 
 // NewLookup create a new proxy with the hosts in host and a Random policy.
-func NewLookup(hosts []string) Proxy {
-	return NewLookupWithOption(hosts, Options{})
-}
+func NewLookup(hosts []string) Proxy { return NewLookupWithOption(hosts, Options{}) }
 
 // NewLookupWithOption process creates a simple round robin forward with potentially forced proto for upstream.
 func NewLookupWithOption(hosts []string, opts Options) Proxy {
@@ -95,13 +94,15 @@ func (p Proxy) lookup(state request.Request) (*dns.Msg, error) {
 	}
 	for {
 		start := time.Now()
+		reply := new(dns.Msg)
+		var backendErr error
 
 		// Since Select() should give us "up" hosts, keep retrying
 		// hosts until timeout (or until we get a nil host).
 		for time.Since(start) < tryDuration {
 			host := upstream.Select()
 			if host == nil {
-				return nil, errUnreachable
+				return nil, fmt.Errorf("%s: %s", errUnreachable, "no upstream host")
 			}
 
 			// duplicated from proxy.go, but with a twist, we don't write the
@@ -109,7 +110,7 @@ func (p Proxy) lookup(state request.Request) (*dns.Msg, error) {
 
 			atomic.AddInt64(&host.Conns, 1)
 
-			reply, backendErr := upstream.Exchanger().Exchange(context.TODO(), host.Name, state)
+			reply, backendErr = upstream.Exchanger().Exchange(context.TODO(), host.Name, state)
 
 			atomic.AddInt64(&host.Conns, -1)
 
@@ -126,6 +127,6 @@ func (p Proxy) lookup(state request.Request) (*dns.Msg, error) {
 				atomic.AddInt32(&host.Fails, -1)
 			}(host, timeout)
 		}
-		return nil, errUnreachable
+		return nil, fmt.Errorf("%s: %s", errUnreachable, backendErr)
 	}
 }
diff --git a/middleware/proxy/proxy.go b/middleware/proxy/proxy.go
index cef58f658..2a3c8002d 100644
--- a/middleware/proxy/proxy.go
+++ b/middleware/proxy/proxy.go
@@ -3,6 +3,7 @@ package proxy
 
 import (
 	"errors"
+	"fmt"
 	"sync/atomic"
 	"time"
 
@@ -70,6 +71,8 @@ func (p Proxy) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (
 
 	for {
 		start := time.Now()
+		reply := new(dns.Msg)
+		var backendErr error
 
 		// Since Select() should give us "up" hosts, keep retrying
 		// hosts until timeout (or until we get a nil host).
@@ -79,7 +82,7 @@ func (p Proxy) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (
 
 				RequestDuration.WithLabelValues(state.Proto(), upstream.Exchanger().Protocol(), upstream.From()).Observe(float64(time.Since(start) / time.Millisecond))
 
-				return dns.RcodeServerFailure, errUnreachable
+				return dns.RcodeServerFailure, fmt.Errorf("%s: %s", errUnreachable, "no upstream host")
 			}
 
 			if span != nil {
@@ -90,7 +93,7 @@ func (p Proxy) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (
 			atomic.AddInt64(&host.Conns, 1)
 			queryEpoch := msg.Epoch()
 
-			reply, backendErr := upstream.Exchanger().Exchange(ctx, host.Name, state)
+			reply, backendErr = upstream.Exchanger().Exchange(ctx, host.Name, state)
 
 			respEpoch := msg.Epoch()
 			atomic.AddInt64(&host.Conns, -1)
@@ -99,8 +102,7 @@ func (p Proxy) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (
 				child.Finish()
 			}
 
-			taperr := toDnstap(ctx, host.Name, upstream.Exchanger(), state, reply,
-				queryEpoch, respEpoch)
+			taperr := toDnstap(ctx, host.Name, upstream.Exchanger(), state, reply, queryEpoch, respEpoch)
 
 			if backendErr == nil {
 				w.WriteMsg(reply)
@@ -123,7 +125,7 @@ func (p Proxy) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (
 
 		RequestDuration.WithLabelValues(state.Proto(), upstream.Exchanger().Protocol(), upstream.From()).Observe(float64(time.Since(start) / time.Millisecond))
 
-		return dns.RcodeServerFailure, errUnreachable
+		return dns.RcodeServerFailure, fmt.Errorf("%s: %s", errUnreachable, backendErr)
 	}
 }
 
diff --git a/middleware/proxy/setup.go b/middleware/proxy/setup.go
index 544633722..d55065734 100644
--- a/middleware/proxy/setup.go
+++ b/middleware/proxy/setup.go
@@ -30,7 +30,8 @@ func setup(c *caddy.Controller) error {
 
 	c.OnStartup(OnStartupMetrics)
 
-	for _, u := range upstreams {
+	for i := range upstreams {
+		u := upstreams[i]
 		c.OnStartup(func() error {
 			return u.Exchanger().OnStartup(P)
 		})