<html><body><div style="color:#000; background-color:#fff; font-family:times new roman, new york, times, serif;font-size:12pt"><div id="yiv6075104056"><div><div style="color:#000;background-color:#fff;font-family:times new roman, new york, times, serif;font-size:12pt;">Hello Bert,<br><br><div class="yiv6075104056yui_3_7_2_28_1371982853380_58" id="yiv6075104056yui_3_7_2_28_1371982853380_59" style="font-family:times new roman, new york, times, serif;font-size:12pt;"><div id="yiv6075104056yui_3_7_2_28_1371982853380_73" class="yiv6075104056yui_3_7_2_28_1371982853380_62" style="font-family:times new roman, new york, times, serif;font-size:12pt;"><div id="yiv6075104056yui_3_7_2_28_1371982853380_72" class="yiv6075104056y_msg_container">> > Any ideas why it takes so long?<br>> <br>> Rerun with --trace enabled and check what is happening. With some study, it should be clear what it is waiting for.<br><br>did that already before, but still did not
found anything helpful there. Below is a new trace.<br>btw, I am using 3.5.1 (package pdns-recursor-3.5.1-1.el6.x86_64).<br><br>Thanks,<br> Shamus<br><br>- /etc/init.d/pdns-recursor start<br>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<br>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.<br>Jun 23 12:30:12 server pdns_recursor[11064]: Operating in 64 bits mode<br>Jun 23 12:30:12 server pdns_recursor[11064]: Reading random entropy from '/dev/urandom'<br>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<br>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, ::<br>Jun 23 12:30:12 server pdns_recursor[11064]: NOT using IPv6 for
outgoing queries - set 'query-local-address6=::' to enable<br>Jun 23 12:30:12 server pdns_recursor[11064]: Redirecting queries for zone '.' to: 8.8.8.8:53<br>Jun 23 12:30:12 server pdns_recursor[11064]: Inserting rfc 1918 private space zones<br>Jun 23 12:30:12 server pdns_recursor[11064]: Not decreasing socket buffer size from 229376 to 200000<br>Jun 23 12:30:12 server pdns_recursor[11064]: Listening for UDP queries on 127.0.0.1:53<br>Jun 23 12:30:12 server pdns_recursor[11064]: Enabled TCP data-ready filter for (slight) DoS protection<br>Jun 23 12:30:12 server pdns_recursor[11064]: Listening for TCP queries on 127.0.0.1:53<br>Jun 23 12:30:12 server pdns_recursor[11064]: Calling daemonize, going to background<br>Jun 23 12:30:12 server pdns_recursor[11065]: Set effective group id to 497<br>Jun 23 12:30:12 server pdns_recursor[11065]: Set effective user id to 497<br>Jun 23 12:30:12 server pdns_recursor[11065]: Launching 2 threads<br>Jun 23 12:30:12 server
pdns_recursor[11065]: Done priming cache with root hints<br>Jun 23 12:30:12 server pdns_recursor[11065]: Done priming cache with root hints<br>Jun 23 12:30:12 server pdns_recursor[11065]: Enabled 'epoll' multiplexer<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: No cache hit for '.|NS', trying to find an appropriate NS record<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: No cache hit for '.|NS', trying to find an appropriate NS record<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Cache consultations done, have 1 NS to contact<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Cache consultations done, have 1 NS to contact<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Nameservers: -8.8.8.8:53(0.00ms)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Trying to resolve NS '-8.8.8.8:53' (1/1)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Domain has hardcoded nameserver(s)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Resolved
'.' NS -8.8.8.8:53 to: 8.8.8.8<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Nameservers: -8.8.8.8:53(0.00ms)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Trying to resolve NS '-8.8.8.8:53' (1/1)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Domain has hardcoded nameserver(s)<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Resolved '.' NS -8.8.8.8:53 to: 8.8.8.8<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Trying IP 8.8.8.8:53, asking '.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Trying IP 8.8.8.8:53, asking '.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Got 13 answers from -8.8.8.8:53 (8.8.8.8), rcode=0, aa=0, in 6ms<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|d.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|l.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .:
accept answer '.|NS|c.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|g.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|h.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|b.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: Got 13 answers from -8.8.8.8:53 (8.8.8.8), rcode=0, aa=0, in 6ms<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|d.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|l.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|c.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer
'.|NS|g.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|h.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|b.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|f.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|m.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|k.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|a.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|j.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer
'.|NS|i.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|e.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: determining status after receiving this packet<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'd.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'l.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'c.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'g.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'h.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'b.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to
'f.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'm.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'k.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'a.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'j.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'i.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'e.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: status=got results, this level of recursion done<br>Jun 23 12:30:12 server pdns_recursor[11065]: Refreshed . records<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|f.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server
pdns_recursor[11065]: .: accept answer '.|NS|m.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|k.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|a.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|j.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|i.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: accept answer '.|NS|e.root-servers.net.' from '.' nameservers? YES!<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: determining status after receiving this packet<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'd.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to
'l.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'c.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'g.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'h.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'b.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'f.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'm.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'k.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'a.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'j.root-servers.net.|NS'<br>Jun 23 12:30:12
server pdns_recursor[11065]: .: answer is in: resolved to 'i.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: answer is in: resolved to 'e.root-servers.net.|NS'<br>Jun 23 12:30:12 server pdns_recursor[11065]: .: status=got results, this level of recursion done<br>Jun 23 12:30:12 server pdns_recursor[11065]: Refreshed . records<br><br>- 1st lookup: dig +short www.google.com @localhost<br>Jun 23 12:34:10 server pdns_recursor[11065]: 0 [3] question for 'www.google.com.|A' from 127.0.0.1<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Looking for CNAME cache hit of 'www.google.com.|CNAME'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: No CNAME cache hit of 'www.google.com.|CNAME' found<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: No cache hit for 'www.google.com.|A', trying to find an appropriate NS record<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3]
www.google.com.: Cache consultations done, have 1 NS to contact<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Nameservers: -8.8.8.8:53(0.23ms)<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Trying to resolve NS '-8.8.8.8:53' (1/1)<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Domain has hardcoded nameserver(s)<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Resolved '.' NS -8.8.8.8:53 to: 8.8.8.8<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Trying IP 8.8.8.8:53, asking 'www.google.com.|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: Got 5 answers from -8.8.8.8:53 (8.8.8.8), rcode=0, aa=0, in 3ms<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: accept answer 'www.google.com.|A|173.194.112.242' from '.' nameservers? YES!<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: accept
answer 'www.google.com.|A|173.194.112.243' from '.' nameservers? YES!<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: accept answer 'www.google.com.|A|173.194.112.240' from '.' nameservers? YES!<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: accept answer 'www.google.com.|A|173.194.112.241' from '.' nameservers? YES!<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: accept answer 'www.google.com.|A|173.194.112.244' from '.' nameservers? YES!<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: determining status after receiving this packet<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: answer is in: resolved to '173.194.112.242|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: answer is in: resolved to '173.194.112.243|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: answer is in: resolved to
'173.194.112.240|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: answer is in: resolved to '173.194.112.241|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: answer is in: resolved to '173.194.112.244|A'<br>Jun 23 12:34:10 server pdns_recursor[11065]: [3] www.google.com.: status=got results, this level of recursion done<br>Jun 23 12:34:10 server pdns_recursor[11065]: 0 [3] answer to question 'www.google.com.|A': 5 answers, 0 additional, took 1 packets, 0 throttled, 0 timeouts, 0 tcp connections, rcode=0<br><br>- 2nd lookup: dig +short www.google.com @localhost<br>Jun 23 12:34:21 server pdns_recursor[11065]: 0 question answered from packet cache from 127.0.0.1<br><br id="yiv6075104056yui_3_7_2_28_1371982853380_103"></div> </div> </div> </div></div></div></div></body></html>