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>
This commit is contained in:
Sebastiaan van Stijn 2017-08-02 17:57:15 +02:00
parent e85aeedbc6
commit b9be3f5781
No known key found for this signature in database
GPG Key ID: 76698F39D527CE8C
1 changed files with 22 additions and 10 deletions

View File

@ -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--
}