[Pdns-users] Slow query and SERVERFAIL from local pdns_recursor

Christian Degenkolb christian+pdns at degenkolb.net
Tue Sep 8 07:22:31 UTC 2020


(send again, first answer was not send cc to the ML)

Hi,

sorry for not sending any configs. pdns_recursor runs more or less with 
the vanilla config with the following changes:

forward-zones-recurse=zen.spamhaus.org=1.1.1.1;1.0.0.1 (thats why I 
wanted to use the local recursor, as mentioned the server is located in 
the hetzner IP Range which apparently is blocked for the spamhaus DNSBL)
loglevel=6
log-common-errors=yes
quiet=no
root-nx-trust=no (found this as a solution for the SERVERFAIL but did 
not work)

and
# rec_control set-carbon-server 37.252.122.50 rho-test (for the grafs)


A trace for the same resolves from my last mail:

  $ time dig +trace pubs.vmware.com @127.0.0.1
; <<>> DiG 9.11.5-P4-5.1+deb10u2-Debian <<>> +trace pubs.vmware.com 
@127.0.0.1
;; global options: +cmd
.                       86118   IN      NS      d.root-servers.net.
.                       86118   IN      NS      c.root-servers.net.
.                       86118   IN      NS      l.root-servers.net.
.                       86118   IN      NS      b.root-servers.net.
.                       86118   IN      NS      f.root-servers.net.
.                       86118   IN      NS      m.root-servers.net.
.                       86118   IN      NS      e.root-servers.net.
.                       86118   IN      NS      a.root-servers.net.
.                       86118   IN      NS      i.root-servers.net.
.                       86118   IN      NS      k.root-servers.net.
.                       86118   IN      NS      g.root-servers.net.
.                       86118   IN      NS      h.root-servers.net.
.                       86118   IN      NS      j.root-servers.net.
.                       86118   IN      RRSIG   NS 8 0 518400 
20200921050000 20200908040000 46594 . 
wgnBz8tKA9hjwIxmMQgTVwnZaiUpAB9a1+oC5T/syHzqNj1e5qhApLQN 
NLok43hu5Ykt8RFe/IiDZuYxIdyyzItwk
4QN8xNgsQsfhVfBbZ26bWRz 
fskquwnFn6Gmvq2qI6o42tsBxXUw09X4sNlNYI2zHB3sKaaMu0AbN9WI 
Pe14jpX/PwaP3m78+XqMy9CiKmuDon6g3BuyecPhCZL5Pa8ZPC7nrKfV 
pfyNSiPoBODsJE96UHGlOCJTFcbu/6Ia4ek3AGOJf+WC84HPrxLT
riyk XHfbPl7EjTbFSPgT8D7jGBfVCTQU3JSfynv29VFAHWZu1gm5VJWNQGaw u5gatA==
;; Received 540 bytes from 127.0.0.1#53(127.0.0.1) in 0 ms

com.                    172800  IN      NS      a.gtld-servers.net.
com.                    172800  IN      NS      b.gtld-servers.net.
com.                    172800  IN      NS      c.gtld-servers.net.
com.                    172800  IN      NS      d.gtld-servers.net.
com.                    172800  IN      NS      e.gtld-servers.net.
com.                    172800  IN      NS      f.gtld-servers.net.
com.                    172800  IN      NS      g.gtld-servers.net.
com.                    172800  IN      NS      h.gtld-servers.net.
com.                    172800  IN      NS      i.gtld-servers.net.
com.                    172800  IN      NS      j.gtld-servers.net.
com.                    172800  IN      NS      k.gtld-servers.net.
com.                    172800  IN      NS      l.gtld-servers.net.
com.                    172800  IN      NS      m.gtld-servers.net.
com.                    86400   IN      DS      30909 8 2 
E2D3C916F6DEEAC73294E8268FB5885044A833FC5459588F4A9184CF C41A5766
com.                    86400   IN      RRSIG   DS 8 1 86400 
20200921050000 20200908040000 46594 . 
zz85z6R/YUHxyW+ywA6zrgiYILjPo0i248M3wU+2XCRCneBH6yknQfjM 
LIcbo3vADVUlkJd0l4W2TLd7NPgC255hr2
+ALojzzHa07jyFmE203Kdw 
ma7XL0C55TdFrCEMhARkZf4EncfJH9JH+fdWRWdMr0EQZd1A+FzMYemO 
o7/L/8ZYq4FOt0vz+zheAJNDveGii+QpXAoDyw4xt3HMUVM+40Z/VgD1 
tk9Y3K9e2wwRNISeHdlq21JFVA2SY/gDgPCzBtM1r9Yz7oFZ2ld5W
AD0 P84GPEUMgUceAGofwxlV9+dSawhunskb+yVrpdjpizLageyJRWEu/F9A zDXxew==
;; Received 1175 bytes from 198.97.190.53#53(h.root-servers.net) in 5 ms

vmware.com.             172800  IN      NS      dns1.p05.nsone.net.
vmware.com.             172800  IN      NS      dns2.p05.nsone.net.
vmware.com.             172800  IN      NS      dns3.p05.nsone.net.
vmware.com.             172800  IN      NS      dns4.p05.nsone.net.
vmware.com.             172800  IN      NS      ns01.vmwdns.com.
vmware.com.             172800  IN      NS      ns02.vmwdns.com.
vmware.com.             172800  IN      NS      ns03.vmwdns.com.
vmware.com.             172800  IN      NS      ns04.vmwdns.com.
vmware.com.             86400   IN      DS      48553 13 2 
AA2C697F3990472642AF01509A18224828E403CA8608EC75D5C83002 CE21847E
vmware.com.             86400   IN      RRSIG   DS 8 2 86400 
20200915062203 20200908051203 24966 com. 
FA2xsJKvT2LLn5UEy7hAE7PaYmds7FBkQB0SGhm8riwJRKnxbHAY0tvv 
I1T/k0EzXJ4wy1J5qzNLMjhzFgPxEQB
6BwBfJm8qo8Cnzxm4YC5Ko1/9 
pDWooVBHoFfMmJgu14Dk+u1AcHobxH9pPs7az16cLK/3YeaFW3dCrIVQ 
NK2fZc0d/pc7CY0Zl1LjYQdTq+MsZiL2kbepEHD6A/4J6g==
;; Received 523 bytes from 2001:503:eea3::30#53(g.gtld-servers.net) in 6 
ms

pubs.vmware.com.        30      IN      CNAME   
pubs.vmware.com.ds.edgekey.net.
pubs.vmware.com.        30      IN      RRSIG   CNAME 13 3 30 
20200909071011 20200907071011 12752 vmware.com. 
yTxj4OFvCx3flxtOFAFdkwAOpOAVNibgseFi5U5ekzYbdATw98xZqrDT 
tYs/n46iHFiLN4ql4Y3MS6U
16Qr6DQ==
;; Received 194 bytes from 45.54.11.1#53(ns01.vmwdns.com) in 11 ms

real0m32.149s
user0m0.012s
sys0m0.012s

But this looks normal to me. I don't know why the trace only shows 5, 6 
and 11 ms but takes up to 32 seconds to finish.

Regarding your questions for the ipv6 connectivity. How can I test this?

I did a

$ dig ipv6.google.com @127.0.0.1

; <<>> DiG 9.11.5-P4-5.1+deb10u2-Debian <<>> ipv6.google.com @127.0.0.1
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 9226
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4096
;; QUESTION SECTION:
;ipv6.google.com.INA

;; ANSWER SECTION:
ipv6.google.com.86400   INCNAME   ipv6.l.google.com.

;; AUTHORITY SECTION:
l.google.com.   60INSOAns1.google.com. dns-admin.google.com. 330353109 
900 900 1800 60

;; Query time: 3087 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Tue Sep 08 09:12:50 CEST 2020
;; MSG SIZE  rcvd: 115

and

$ ping6 ipv6.google.com
PING ipv6.google.com(fra16s13-in-x0e.1e100.net 
(2a00:1450:4001:819::200e)) 56 data bytes
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=1 ttl=118 time=5.11 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=2 ttl=118 time=5.08 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=3 ttl=118 time=5.12 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=4 ttl=118 time=5.13 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=5 ttl=118 time=5.09 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=6 ttl=118 time=5.08 ms
64 bytes from fra16s13-in-x0e.1e100.net (2a00:1450:4001:819::200e): 
icmp_seq=7 ttl=118 time=5.08 ms
^C
--- ipv6.google.com ping statistics ---
7 packets transmitted, 7 received, 0% packet loss, time 24ms
rtt min/avg/max/mdev = 5.075/5.096/5.133/0.043 ms

and it looks good.

regards
Chris


Am 2020-09-04 15:05, schrieb Otto Moerbeek:
> On Wed, Sep 02, 2020 at 09:44:37AM +0200, Christian Degenkolb via
> Pdns-users wrote:
> 
>> Hi,
>> 
>> I hope somebody on the ML can help me figure out what I'm doing wrong.
>> I have a local pdns_recursor (version 4.1.11-1+deb10u1 from debian 10)
>> runing and added it at the top of my /etc/resolve.conf as 127.0.0.1.
>> 
>> However I see some strange SERVERFAIL resolves happening and all in 
>> all a
>> slow DNS system.
>> 
>> For example see the following two consecutive resolves and a direct 
>> request
>> to the NS.
>> The first one takes nearly 3 seconds vs 11 ms from the same system if 
>> I
>> query the NS directly.
>> 
>> $ dig pubs.vmware.com @127.0.0.1
>> 
>> ; <<>> DiG 9.11.5-P4-5.1+deb10u2-Debian <<>> pubs.vmware.com 
>> @127.0.0.1
>> ;; global options: +cmd
>> ;; Got answer:
>> ;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 4929
>> ;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1
>> 
>> ;; OPT PSEUDOSECTION:
>> ; EDNS: version: 0, flags:; udp: 4096
>> ;; QUESTION SECTION:
>> ;pubs.vmware.com.INA
>> 
>> ;; ANSWER SECTION:
>> pubs.vmware.com.30INCNAME   pubs.vmware.com.ds.edgekey.net.
>> pubs.vmware.com.ds.edgekey.net. 10 IN   CNAME   
>> e751.dscx.akamaiedge.net.
>> 
>> ;; Query time: 3009 msec
>> ;; SERVER: 127.0.0.1#53(127.0.0.1)
>> ;; WHEN: Wed Sep 02 09:19:04 CEST 2020
>> ;; MSG SIZE  rcvd: 123
>> 
>> $ dig pubs.vmware.com @127.0.0.1
>> 
>> ; <<>> DiG 9.11.5-P4-5.1+deb10u2-Debian <<>> pubs.vmware.com 
>> @127.0.0.1
>> ;; global options: +cmd
>> ;; Got answer:
>> ;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1345
>> ;; flags: qr rd ra; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 1
>> 
>> ;; OPT PSEUDOSECTION:
>> ; EDNS: version: 0, flags:; udp: 4096
>> ;; QUESTION SECTION:
>> ;pubs.vmware.com.INA
>> 
>> ;; ANSWER SECTION:
>> pubs.vmware.com.18INCNAME   pubs.vmware.com.ds.edgekey.net.
>> pubs.vmware.com.ds.edgekey.net. 4 INCNAME   e751.dscx.akamaiedge.net.
>> e751.dscx.akamaiedge.net. 16INA104.111.214.47
>> 
>> ;; Query time: 0 msec
>> ;; SERVER: 127.0.0.1#53(127.0.0.1)
>> ;; WHEN: Wed Sep 02 09:19:08 CEST 2020
>> ;; MSG SIZE  rcvd: 139
>> 
>> $ dig pubs.vmware.com @ns03.vmwdns.com
>> 
>> ; <<>> DiG 9.11.5-P4-5.1+deb10u2-Debian <<>> pubs.vmware.com
>> @ns03.vmwdns.com
>> ;; global options: +cmd
>> ;; Got answer:
>> ;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 5509
>> ;; flags: qr aa rd; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
>> ;; WARNING: recursion requested but not available
>> 
>> ;; OPT PSEUDOSECTION:
>> ; EDNS: version: 0, flags:; udp: 4096
>> ;; QUESTION SECTION:
>> ;pubs.vmware.com.INA
>> 
>> ;; ANSWER SECTION:
>> pubs.vmware.com.30INCNAME   pubs.vmware.com.ds.edgekey.net.
>> 
>> ;; Query time: 11 msec
>> ;; SERVER: 45.54.11.129#53(45.54.11.129)
>> ;; WHEN: Wed Sep 02 09:34:42 CEST 2020
>> ;; MSG SIZE  rcvd: 88
>> 
>> Also I have a number SERVFAIL in /var/log/syslog (pdns_recurser is 
>> currently
>> running with loglevel=6).
>> For example:
>> 
>> Sep  2 08:45:35 rho pdns_recursor[19311]: Sending SERVFAIL to 
>> 127.0.0.1
>> during resolve of 'pubs.vmware.com' because: Too much time waiting for
>> pubs.vmware.com.ds.edgekey.net|A, timeouts: 5,
>> throttles: 1, queries: 6, 7991msec
>> 
>> # grep 'Too much time waiting for' /var/log/syslog | wc -l
>> 184
>> 
>> As per 
>> https://blog.powerdns.com/2014/12/11/powerdns-graphing-as-a-service/
>> I send the metrics to 
>> https://metronome1.powerdns.com/?server=pdns.rho-test.recursor&beginTime=-172800
>> 
>> Does anybody have an idea whats wrong? This seems way to slow for DNS 
>> and
>> the SERVFAIL schouldn't happen this often.
>> The server in question is running in a DC of the german Hoster 
>> hetzner.de.
>> Besides the strange DNS I don't have any problems with the reliability 
>> of
>> the network connection.
>> 
>> thanks
>> Chris
>> 
>> _______________________________________________
>> Pdns-users mailing list
>> Pdns-users at mailman.powerdns.com
>> https://mailman.powerdns.com/mailman/listinfo/pdns-users
> 
> You did not share any config or traces, so it's hard to tell. A wild
> guess: It might be you enabled IPV6 but your IPV6 connectivity is bad.
> 
> 	-Otto


More information about the Pdns-users mailing list