From 7bd4fc1de421e0ba64ffca91c0d8889d1fb07f14 Mon Sep 17 00:00:00 2001 From: Sebastiaan van Stijn Date: Wed, 2 Aug 2017 17:57:15 +0200 Subject: [PATCH] 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 --- libnetwork/resolver.go | 32 ++++++++++++++++++++++---------- 1 file changed, 22 insertions(+), 10 deletions(-) diff --git a/libnetwork/resolver.go b/libnetwork/resolver.go index ff472d0019..12d89b9407 100644 --- a/libnetwork/resolver.go +++ b/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-- }