nsd users - Dec 2015 - NSD doing 3 IXFR queries in rapid succession

Hello NSD users and developers,

I was just looking at some BIND logs on one of our servers. It feeds a
downstream NSD 4.1.7 slave. In the BIND logs, I often see this:

20-Dec-2015 11:50:45.011 xfer-out: client 10.64.0.12#47701/key
main.ripe.net (132.72.185.in-addr.arpa): transfer of
'132.72.185.in-addr.arpa/IN': IXFR ended
20-Dec-2015 11:50:45.078 xfer-out: client 10.64.0.12#47704/key
main.ripe.net (132.72.185.in-addr.arpa): transfer of
'132.72.185.in-addr.arpa/IN': IXFR ended
20-Dec-2015 11:50:45.146 xfer-out: client 10.64.0.12#47707/key
main.ripe.net (132.72.185.in-addr.arpa): transfer of
'132.72.185.in-addr.arpa/IN': IXFR ended

Notice that NSD appears to be doing 3 IXFR queries for the same zone in
rapid succession.

I captured some packets using tcpdump, and then put them through PacketQ
with the filter:

select src_addr,src_port,qname,qtype,rcode,aname,atype from dns

The results corresponding to the above log is:

["10.64.0.12",47701,"132.72.185.in-addr.arpa.",251,0,"",0],
["93.175.159.250",53,"132.72.185.in-addr.arpa.",251,0,"132.72.185.in-addr.arpa.",6],
["10.64.0.12",47704,"132.72.185.in-addr.arpa.",251,0,"",0],
["93.175.159.250",53,"132.72.185.in-addr.arpa.",251,0,"132.72.185.in-addr.arpa.",6],
["10.64.0.12",47707,"132.72.185.in-addr.arpa.",251,0,"",0],
["93.175.159.250",53,"132.72.185.in-addr.arpa.",251,0,"132.72.185.in-addr.arpa.",6]

The packet capture also shows shows the same thing: 3 IXFR queries in
rapid succession, with the same responses.

Does anyone have any idea why NSD is doing 3 queries per zone like this?

Regards,
Anand

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Hi Anand,

On 20/12/15 13:15, Anand Buddhdev wrote:
> Hello NSD users and developers,
> 
> I was just looking at some BIND logs on one of our servers. It 
> feeds a downstream NSD 4.1.7 slave. In the BIND logs, I often see 
> this:
> 
> 20-Dec-2015 11:50:45.011 xfer-out: client 10.64.0.12#47701/key 
> main.ripe.net (132.72.185.in-addr.arpa): transfer of 
> '132.72.185.in-addr.arpa/IN': IXFR ended 20-Dec-2015 11:50:45.078 
> xfer-out: client 10.64.0.12#47704/key main.ripe.net 
> (132.72.185.in-addr.arpa): transfer of 
> '132.72.185.in-addr.arpa/IN': IXFR ended 20-Dec-2015 11:50:45.146 
> xfer-out: client 10.64.0.12#47707/key main.ripe.net 
> (132.72.185.in-addr.arpa): transfer of 
> '132.72.185.in-addr.arpa/IN': IXFR ended
> 
> Notice that NSD appears to be doing 3 IXFR queries for the same 
> zone in rapid succession.
> 
> I captured some packets using tcpdump, and then put them through 
> PacketQ with the filter:
> 
> select src_addr,src_port,qname,qtype,rcode,aname,atype from dns
> 
> The results corresponding to the above log is:
> 
>
["10.64.0.12",47701,"132.72.185.in-addr.arpa.",251,0,"",0],
>
["93.175.159.250",53,"132.72.185.in-addr.arpa.",251,0,"132.72.185.in-a
ddr.arpa.",6],
>["10.64.0.12",47704,"132.72.185.in-addr.arpa.",251,0,"",0],
>
> 
["93.175.159.250",53,"132.72.185.in
> addr.arpa.",251,0,"132.72.185.inaddr.arpa.",6], 
>
["10.64.0.12",47707,"132.72.185.in-addr.arpa.",251,0,"",0],
>
["93.175.159.250",53,"132.72.185.in-addr.arpa.",251,0,"132.72.185.in-a
ddr.arpa.",6]
>
>
>
> 
The packet capture also shows shows the same thing: 3
IXFR
> queries in rapid succession, with the same responses.
> 
> Does anyone have any idea why NSD is doing 3 queries per zone like
>  this?
NSD wants to fetch an update for the zone.  The server does not
provide one.  NSD tries all masters several times to find the update.
 This is where this server sees multiple requests.

The reason for fetching it may be the SOA refresh timer or a NOTIFY.

Load balancers, and the server may be in the process of loading the
data, so the third query may return a different result.  Also, the
code, currently, just retries in the face of no result, which makes
for simpler code.

Best regards, Wouter
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQIcBAEBCAAGBQJWim8WAAoJEJ9vHC1+BF+NzyoP/A4ymsGGYke0nM2GTVUFQJ3V
vawp8SWBZlomi8kwQdUXwlVIrT9yprFjqyTCbOulnj0cTLjfMjQouviWfgr+DfjN
UHteOTjh9rqtJyISsDsK3whXpJRfByk9nJdWwOSkF0XuTMO6NyDbPc9YxOLcm8UB
WvHu8Q5K474qAldQsZ8HculwzETcmIF+cNH1oamXzDb/Y1BQnbfYdoMJDbgKAQOw
VU85Yko0RqYCaQ55P0N/1ffyBKU/8N/DkqLy7eCwwSzTddTz7Dw/vvuujtqJDaVb
Rv2ang+TOXmy6frIy7ttohoiMRsBuLG6SvifWXidkAPkksHPCrGCXfcsRhcW4xWs
5JIJcIcHHFWZ4r1E8nHAxtxDJ7r0DjdBwe61VRlZVgJ7d4X3twsyI8F35678lqsc
p3T0unlXWtGe5j6CDq8D1zApVCExh1dsn48PjbW9pFk8LJqIJEO2sYW2yJ9qjVMN
2zilC0r4UcamNtHm1BAU9Iiqzi89X5yZkDcZHAlNDhosCThRtZ2lUGfFrRdrTJyL
HNYmIqelHD3SMxIvLcFfiughTBRDqaQC6TPm4weZzwFYDpg/hZhsVDcHjzo3+N1f
0XUyUAVxDAbFFHZLmf4PVidpz4/5xDg6oyelqjnaegH1UZ+a/cY3mrXCVw7ToLga
qxcpmqbyYfcYUmndSgYA
=D3om
-----END PGP SIGNATURE-----