Skip to content

Commit

Permalink
resolver: less debug
Browse files Browse the repository at this point in the history
Observed lots of debug messages from resolver (and associated high CPU
usage because of lots of logging) when debug logging is turned on. Here
is some data from a real system:

> $ journalctl -u docker --since="2019-10-21 21:00:00"  --until="2019-10-21 22:00:00"  | wc -l
> 188621
> $ journalctl -u docker --since="2019-10-21 21:00:00"  --until="2019-10-21 22:00:00"  | grep -E 'Name To resolve: |\[resolver\] ' | wc -l
> 186319

So, it was about 200000 lines logger for just one hour, and about 99%
of that are from resolver. While this might be the peculiarity of
a particular setup, the number of such messages still seem way too
excessive.

Remove the ones that are not errors.

Signed-off-by: Kir Kolyshkin <[email protected]>
  • Loading branch information
kolyshkin committed Oct 21, 2019
1 parent 79c19d0 commit 999e703
Show file tree
Hide file tree
Showing 2 changed files with 0 additions and 12 deletions.
11 changes: 0 additions & 11 deletions resolver.go
Original file line number Diff line number Diff line change
Expand Up @@ -255,8 +255,6 @@ func (r *resolver) handleIPQuery(name string, query *dns.Msg, ipType int) (*dns.
return nil, nil
}

logrus.Debugf("[resolver] lookup for %s: IP %v", name, addr)

resp := createRespMsg(query)
if len(addr) > 1 {
addr = shuffleAddr(addr)
Expand Down Expand Up @@ -296,7 +294,6 @@ func (r *resolver) handlePTRQuery(ptr string, query *dns.Msg) (*dns.Msg, error)
return nil, nil
}

logrus.Debugf("[resolver] lookup for IP %s: name %s", parts[0], host)
fqdn := dns.Fqdn(host)

resp := new(dns.Msg)
Expand Down Expand Up @@ -452,9 +449,6 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
logrus.Warnf("[resolver] connect failed: %s", err)
continue
}
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.
extConn.SetDeadline(time.Now().Add(extIOTimeout))
Expand Down Expand Up @@ -522,18 +516,13 @@ func (r *resolver) ServeDNS(w dns.ResponseWriter, query *dns.Msg) {
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)
}
resp.Compress = true
break
}
Expand Down
1 change: 0 additions & 1 deletion sandbox.go
Original file line number Diff line number Diff line change
Expand Up @@ -529,7 +529,6 @@ func (sb *sandbox) ResolveName(name string, ipType int) ([]net.IP, bool) {
// {a.b in network c.d},
// {a in network b.c.d},

logrus.Debugf("Name To resolve: %v", name)
name = strings.TrimSuffix(name, ".")
reqName := []string{name}
networkName := []string{""}
Expand Down

0 comments on commit 999e703

Please sign in to comment.