[Pdns-users] 1 sec delay before DNS-answer at pdns-recursor

[Michael Loftis]

On Sunday, June 23, 2013, Shamus Smith wrote:

> Thanks for your answer. The full dig output was in the first posting.
> I have not modified nsswitch.conf and /etc/hosts contains only this:
>

No, only the +short is in any of your responses, when I say full output I
mean without +short - there's a hint of timing information in the full dig
output.  We have teh time it took for the entire command to execute but we
don't have the actual RTT of the DNS query.  It'll indicate the query time,
as well as whom it sent the query too IE what @localhost was resolved to
prior to dig starting it's own query - which I think it uses gethostent or
one of the other get* calls.


>
>
> 127.0.0.1   localhost localhost.localdomain localhost4
> localhost4.localdomain4
> ::1         localhost localhost.localdomain localhost6
> localhost6.localdomain6
>
> And you were right! When using "dig www.google.com @127.0.0.1" it takes
> just
> 0.021 seconds. But I still do not have a clue why, do you?
>

My *guess* or hunch is that your internal OS stack gethostent, getaddrinfo,
etc, is failing/falling over somehow or in some form.  It shouldn't be
talking to anything in resolv.conf but if it is  then the later response
about correctly having the RD bit set or not because of the configuration
could explain the different behavior with dnsmasq.  Normally it should be
consulting your local files first, finding an answer, and immediately
returning.  But if there's something funny going on it might not be.  Other
issues can occur if you have LDAP user databases/etc, or even if you've got
some heavy swapping/paging going on it'll take a while to start up any
command that isn't already fully in cache/RAM.  All that is why I asked for
the timing information from dig, which it runs *after* any of that could
get into the way.


>
> When using another recursor (Dnsmasq) there is no time difference when
> using
> @localhost or @127.0.0.1.
>
> Thanks,
> Shamus
>
I don't think anything other than /etc/hosts should get involved but your
stall pretty clearly appears to be happening during the resolution of the
@localhost and not the round trip to the world and through the pdns
recursor.



>
> What about giving the full dig output too?  My bet is you're actually
> experiencing some sort of huge delay starting up dig or resolving
> "localhost", use @127.0.0.1 instead and see if the time goes away.
> Does your /etc/hosts contain 'localhost'?  Have you modified your
> nsswitch.conf? (Assuming standard *nix like system)
>
> On Sun, Jun 23, 2013 at 3:58 AM, Shamus Smith <smithshamus at yahoo.de>
> wrote:
> > Hello Bert,
> >
> >> > Any ideas why it takes so long?
> >>
> >> Rerun with --trace enabled and check what is happening. With some study,
> >> it should be clear what it is waiting for.
> >
> > did that already before, but still did not found anything helpful there.
> > Below is a new trace.
> > btw, I am using 3.5.1 (package pdns-recursor-3.5.1-1.el6.x86_64).
> >
> > Thanks,
> >  Shamus
> >
> > - /etc/init.d/pdns-recursor start
> > Jun 23 12:30:12 server pdns_recursor[11064]: PowerDNS recursor 3.5.1 (C)
> > 2001-2013 PowerDNS.COM BV (May  3 2013, 20:04:33, gcc 4.4.7 20120313 (Red
> > Hat 4.4.7-3)) starting up
> > Jun 23 12:30:12 server pdns_recursor[11064]: PowerDNS comes with
> ABSOLUTELY
> > NO WARRANTY. This is free software, and you are welcome to redistribute
> it
> > according to the terms of the GPL version 2.
> > Jun 23 12:30:12 server pdns_recursor[11064]: Operating in 64 bits mode
> > Jun 23 12:30:12 server pdns_recursor[11064]: Reading random entropy from
> > '/dev/urandom'
> > Jun 23 12:30:12 server pdns_recursor[11064]: Only allowing queries from:
> > 127.0.0.0/8, 10.0.0.0/8, 100.64.0.0/10, 169.254.0.0/16, 192.168.0.0/16,
> > 172.16.0.0/12, ::1/128, fe80::/10
> > Jun 23 12:30:12 server pdns_recursor[11064]: Will not send queries to:
> > 127.0.0.0/8, 10.0.0.0/8, 100.64.0.0/10, 169.254.0.0/16, 192.168.0.0/16,
> > 172.16.0.0/12, ::1/128, fe80::/10, 0.0.0.0, ::
> > Jun 23 12:30:12 server pdns_recursor[11064]: NOT using IPv6 for outgoing
> > queries - set 'query-local-address6=::' to enable
> > Jun 23 12:30:12 server pdns_recursor[11064]: Redirecting queries for zone
> > '.' to: 8.8.8.8:53
> > Jun 23 12:30:12 server pdns_recursor[11064]: Inserting rfc 1918 private
> > space zones
> > Jun 23 12:30:12 server pdns_recursor[11064]: Not decreasing socket buffer
> > size from 229376 to 200000
> > Jun 23 12:30:12 server pdns_recursor[11064]: Listening for UDP queries on
> > 127.0.0.1:53
> > Jun 23 12:30:12 server pdns_recursor[11064]: Enabled TCP data-ready
> filter
> > for (slight) DoS protection
> > Jun 23 12:30:12 server pdns_recursor[11064]: Listening for TCP queries on
> > 127.0.0.1:53
> > Jun 23 12:30:12 server pdns_recursor[11064]: Calling daemonize, going to
> > background
> > Jun 23 12:30:12 server pdns_recursor[11065]: Set effective group id to
> 497
> > Jun 23 12:30:12 server pdns_recursor[11065]: Set effective user id to 497
> > Jun 23 12:30:12 server pdns_recursor[11065]: Launching 2 threads
> > Jun 23 12:30:12 server pdns_recursor[11065]: Done priming cache with root
> > hints
> > Jun 23 12:30:12 server pdns_recursor[11065]: Done priming cache with root
> > hints
> > Jun 23 12:30:12 server pdns_recursor[11065]: Enabled 'epoll' multiplexer
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: No cache hit for '.|NS',
> > trying to find an appropriate NS record
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: No cache hit for '.|NS',
> > trying to find an appropriate NS record
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: Cache consultations done,
> > have 1 NS to contact
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: Cache consultations done,
> > have 1 NS to contact
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: Nameservers:
> > -8.8.8.8:53(0.00ms)
> > Jun 23 12:30:12 server pdns_recursor[11065]: .: Trying to resolve NS
> > '-8.8.8.8:53' (1/1)
> > Jun 23 12:30:12 server pdns_recurs
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.powerdns.com/pipermail/pdns-users/attachments/20130623/8bb96d56/attachment-0001.html>