[Pdns-users] Intermittent SERVFAIL Response

Scott Hollenbeck sah at musclecarresearch.com
Tue Aug 18 16:41:56 UTC 2015


> -----Original Message-----
> From: bert hubert [mailto:bert.hubert at powerdns.com]
> Sent: Tuesday, August 18, 2015 10:35 AM
> To: Scott Hollenbeck
> Cc: pdns-users at mailman.powerdns.com
> Subject: Re: [Pdns-users] Intermittent SERVFAIL Response
> 
> On Tue, Aug 18, 2015 at 10:33:15AM -0400, Scott Hollenbeck wrote:
> > I'm running PowerDNS Recursor 3.7.3 on a pair of Ubuntu 14.04.3 LTS
> servers.
> > I'm getting intermittent SERVFAIL responses on both servers to
> queries for a
> > particular name. Could someone please help me understand what might
> be
> > causing these failures? Here are examples of the SERVFAIL responses
> I'm
> > seeing on one of the servers:
> 
> Hi Scott,
> 
> Can you repeat with trace-regex turned on for this domain? Also, asking
> ANY
> queries confuses things, could you try 'A' queries?

Done. Here's the query:

$ dig @localhost concoursmustang.com a

; <<>> DiG 9.9.5-3ubuntu0.4-Ubuntu <<>> @localhost concoursmustang.com a
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 40253
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;concoursmustang.com.           IN      A

;; Query time: 3254 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Tue Aug 18 12:19:58 EDT 2015
;; MSG SIZE  rcvd: 37

...and here's what I pulled from syslog:

Aug 18 12:19:55 musclecarresearch pdns_recursor[8817]: 1 [375/1] question
for 'concoursmustang.com.|A' from 127.0.0.1
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Looking for CNAME cache hit of
'concoursmustang.com.|CNAME'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: No CNAME cache hit of 'concoursmustang.com.|CNAME'
found
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: No cache hit for 'concoursmustang.com.|A', trying to
find an appropriate NS record
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Checking if we have NS in cache for
'concoursmustang.com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: no valid/useful NS in cache for 'concoursmustang.com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Checking if we have NS in cache for 'com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'a.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'b.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'c.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'd.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'e.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'f.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'g.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'h.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'i.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'j.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'k.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'l.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: NS (with ip, or non-glue) in cache for 'com.' ->
'm.gtld-servers.net.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: within bailiwick: 0, not in cache / did not look at
cache
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: We have NS in cache for 'com.' (flawedNSSet=0)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Cache consultations done, have 13 NS to contact
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Nameservers: j.gtld-servers.net.(0.00ms),
a.gtld-servers.net.(0.00ms), l.gtld-servers.net.(0.00ms),
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.:              g.gtld-servers.net.(0.00ms),
m.gtld-servers.net.(0.00ms), i.gtld-servers.net.(0.00ms),
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.:              f.gtld-servers.net.(0.00ms),
c.gtld-servers.net.(0.00ms), d.gtld-servers.net.(0.00ms),
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.:              h.gtld-servers.net.(0.00ms),
k.gtld-servers.net.(0.00ms), b.gtld-servers.net.(0.00ms),
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.:              e.gtld-servers.net.(0.00ms)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying to resolve NS 'j.gtld-servers.net.' (1/13)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
j.gtld-servers.net.: Looking for CNAME cache hit of
'j.gtld-servers.net.|CNAME'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
j.gtld-servers.net.: No CNAME cache hit of 'j.gtld-servers.net.|CNAME' found
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
j.gtld-servers.net.: Found cache hit for A: 192.48.79.30[ttl=79835]
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Resolved 'com.' NS j.gtld-servers.net. to:
192.48.79.30
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying IP 192.48.79.30:53, asking
'concoursmustang.com.|A'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Got 4 answers from j.gtld-servers.net. (192.48.79.30),
rcode=0 (No Error), aa=0, in 243ms
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: accept answer
'concoursmustang.com.|NS|ns2.hostmonster.com.' from 'com.' nameservers? YES!
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: accept answer
'concoursmustang.com.|NS|ns1.hostmonster.com.' from 'com.' nameservers? YES!
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: accept answer 'ns2.hostmonster.com.|A|69.89.16.8' from
'com.' nameservers? YES!
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: accept answer 'ns1.hostmonster.com.|A|74.220.195.131'
from 'com.' nameservers? YES!
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: determining status after receiving this packet
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: got NS record 'concoursmustang.com.' ->
'ns2.hostmonster.com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: got NS record 'concoursmustang.com.' ->
'ns1.hostmonster.com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: status=did not resolve, got 2 NS, looping to them
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Nameservers: ns2.hostmonster.com.(0.00ms),
ns1.hostmonster.com.(0.00ms)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying to resolve NS 'ns2.hostmonster.com.' (1/2)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns2.hostmonster.com.: Looking for CNAME cache hit of
'ns2.hostmonster.com.|CNAME'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns2.hostmonster.com.: No CNAME cache hit of 'ns2.hostmonster.com.|CNAME'
found
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns2.hostmonster.com.: Found cache hit for A: 69.89.16.8[ttl=8001]
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Resolved 'concoursmustang.com.' NS
ns2.hostmonster.com. to: 69.89.16.8
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying IP 69.89.16.8:53, asking
'concoursmustang.com.|A'
***Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: timeout resolving after 1501.87msec
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying to resolve NS 'ns1.hostmonster.com.' (2/2)
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns1.hostmonster.com.: Looking for CNAME cache hit of
'ns1.hostmonster.com.|CNAME'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns1.hostmonster.com.: No CNAME cache hit of 'ns1.hostmonster.com.|CNAME'
found
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
ns1.hostmonster.com.: Found cache hit for A: 74.220.195.131[ttl=86398]
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Resolved 'concoursmustang.com.' NS
ns1.hostmonster.com. to: 74.220.195.131
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Trying IP 74.220.195.131:53, asking
'concoursmustang.com.|A'
***Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: timeout resolving after 1501.85msec
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: Failed to resolve via any of the 2 offered NS at level
'concoursmustang.com.'
Aug 18 12:19:58 musclecarresearch pdns_recursor[8817]: [375]
concoursmustang.com.: failed (res=-1)

So the queries to the two name servers are timing out (lines marked "***").
Thanks for the clue, Bert. This gives me something to investigate further.

Scott





More information about the Pdns-users mailing list