Improve debugging for resolver

This patch improves debugging for the resolver;

- prefix debug messages with `[resolver]` for easier finding in the daemon logs
- use `A` / `AAAA` for query-types in the logs instead of their numeric code
- add debug messages if the external DNS did not return a result
- print sucessful results (t.b.d.)

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>

libnetwork/resolver.go

@@ -231,7 +231,7 @@ func (r *resolver) handleIPQuery(name string, query *dns.Msg, ipType int) (*dns.
 
 	if addr == nil && ipv6Miss {
 		// Send a reply without any Answer sections
-		logrus.Debugf("Lookup name %s present without IPv6 address", name)
+		logrus.Debugf("[resolver] lookup name %s present without IPv6 address", name)
 		resp := createRespMsg(query)
 		return resp, nil
 	}
@@ -239,7 +239,7 @@ func (r *resolver) handleIPQuery(name string, query *dns.Msg, ipType int) (*dns.
 		return nil, nil
 	}
 
-	logrus.Debugf("Lookup for %s: IP %v", name, addr)
+	logrus.Debugf("[resolver] lookup for %s: IP %v", name, addr)
 
 	resp := createRespMsg(query)
 	if len(addr) > 1 {
@@ -280,7 +280,7 @@ func (r *resolver) handlePTRQuery(ptr string, query *dns.Msg) (*dns.Msg, error)
 		return nil, nil
 	}
 
-	logrus.Debugf("Lookup for IP %s: name %s", parts[0], host)
+	logrus.Debugf("[resolver] lookup for IP %s: name %s", parts[0], host)
 	fqdn := dns.Fqdn(host)
 
 	resp := new(dns.Msg)
@@ -431,10 +431,12 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
 				}
 			}
 			if err != nil {
-				logrus.Warnf("Connect failed: %s", err)
+				logrus.Warnf("[resolver] connect failed: %s", err)
 				continue
 			}
-			logrus.Debugf("Query %s[%d] from %s, forwarding to %s:%s", name, query.Question[0].Qtype,
+
+			queryType := dns.TypeToString[query.Question[0].Qtype]
+			logrus.Debugf("[resolver] query %s (%s) from %s, forwarding to %s:%s", name, queryType,
 				extConn.LocalAddr().String(), proto, extDNS.IPStr)
 
 			// Timeout has to be set for every IO operation.
@@ -450,7 +452,7 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
 				old := r.tStamp
 				r.tStamp = time.Now()
 				if r.tStamp.Sub(old) > logInterval {
-					logrus.Errorf("More than %v concurrent queries from %s", maxConcurrent, extConn.LocalAddr().String())
+					logrus.Errorf("[resolver] more than %v concurrent queries from %s", maxConcurrent, extConn.LocalAddr().String())
 				}
 				continue
 			}
@@ -458,7 +460,7 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
 			err = co.WriteMsg(query)
 			if err != nil {
 				r.forwardQueryEnd()
-				logrus.Debugf("Send to DNS server failed, %s", err)
+				logrus.Debugf("[resolver] send to DNS server failed, %s", err)
 				continue
 			}
 
@@ -467,22 +469,32 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
 			// client can retry over TCP
 			if err != nil && err != dns.ErrTruncated {
 				r.forwardQueryEnd()
-				logrus.Debugf("Read from DNS server failed, %s", err)
+				logrus.Debugf("[resolver] read from DNS server failed, %s", err)
 				continue
 			}
 			r.forwardQueryEnd()
 			if resp != nil {
+				answers := 0
 				for _, rr := range resp.Answer {
 					h := rr.Header()
 					switch h.Rrtype {
 					case dns.TypeA:
+						answers++
 						ip := rr.(*dns.A).A
+						logrus.Debugf("[resolver] received A record %q for %q from %s:%s", ip, h.Name, proto, extDNS.IPStr)
 						r.backend.HandleQueryResp(h.Name, ip)
 					case dns.TypeAAAA:
+						answers++
 						ip := rr.(*dns.AAAA).AAAA
+						logrus.Debugf("[resolver] received AAAA record %q for %q from %s:%s", ip, h.Name, proto, extDNS.IPStr)
 						r.backend.HandleQueryResp(h.Name, ip)
 					}
 				}
+				if resp.Answer == nil || answers == 0 {
+					logrus.Debugf("[resolver] external DNS %s:%s did not return any %s records for %q", proto, extDNS.IPStr, queryType, name)
+				}
+			} else {
+				logrus.Debugf("[resolver] external DNS %s:%s returned empty response for %q", proto, extDNS.IPStr, name)
 			}
 			resp.Compress = true
 			break
@@ -493,7 +505,7 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
 	}
 
 	if err = w.WriteMsg(resp); err != nil {
-		logrus.Errorf("error writing resolver resp, %s", err)
+		logrus.Errorf("[resolver] error writing resolver resp, %s", err)
 	}
 }
 
@@ -514,7 +526,7 @@ func (r *resolver) forwardQueryEnd() {
 	defer r.queryLock.Unlock()
 
 	if r.count == 0 {
-		logrus.Error("Invalid concurrent query count")
+		logrus.Error("[resolver] invalid concurrent query count")
 	} else {
 		r.count--
 	}