[nsd-users] sporadic: errors on zonetransfers

Wed Jun 10 13:17:32 UTC 2015

Hello,

since many weeks I notice sporadic error messages on zonetransfers.
As far as I can tell, anything work in general and also no user  
complain. But there is this error message :-(

Setup
1x nsd-1.4.2 as master serving exact one zone.
4x nsd-1.4.2 as slave serving dozens of zones with own data and just  
one zone as slave.

Here are the logs as the error occur.

@master ( 192.0.53.53 )
2015-04-29 09:26:15.265243500 [2015-04-29 09:26:15.265] nsd[13222]:  
info: new control connection from 127.0.0.1
2015-04-29 09:26:15.268803500 [2015-04-29 09:26:15.268] nsd[13222]:  
info: remote control connection authenticated
2015-04-29 09:26:15.308609500 [2015-04-29 09:26:15.308] nsd[13222]:  
info: control cmd:  reload
2015-04-29 09:26:15.308738500 [2015-04-29 09:26:15.308] nsd[13222]:  
info: remote control operation completed
2015-04-29 09:26:15.311365500 [2015-04-29 09:26:15.311] nsd[13259]:  
info: zone example.org. read with success
2015-04-29 09:26:15.311365500 [2015-04-29 09:26:15.311] nsd[13259]:  
info: rehash of zone example.org. with parameters 1 0 1 -
2015-04-29 09:26:15.312562500 [2015-04-29 09:26:15.311] nsd[683]:  
info: NSTATS 1430292375 1430290388 TYPE252=4
2015-04-29 09:26:15.312562500 [2015-04-29 09:26:15.312] nsd[683]:  
info: XSTATS 1430292375 1430290388 RR=0 RNXD=0 RFwdR=0 RDupR=0 RFail=0  
RFErr=0 RErr=0 RAXFR=4 RLame=0 ROpts=0 SSysQ=0 SAns=0 SF
wdQ=0 SDupQ=0 SErr=0 RQ=4 RIQ=0 RFwdQ=0 RDupQ=0 RTCP=4 SFwdR=0 SFail=0  
SFErr=0 SNaAns=0 SNXD=0 RUQ=0 RURQ=0 RUXFR=0 RUUpd=0

13222 ?        S      0:05  |   |   \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d
13259 ?        S      0:06  |   |       \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d
  9127 ?        S      0:00  |   |           \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d

nsd.conf:
       server:
           chroot: "/var/lib/nsd"
           debug-mode: yes
           statistics: 86400
           verbosity: 9
           ip-address: 192.0.53.53
           ip-address: $an_additional_ipv6_address
           nsid: "ascii_MASTER"
           database: ""

       key:
            name: "mykey"
            algorithm: hmac-sha256
            secret: "secret"
       zone:
            name: "example.org."
            zonefile: "/path/to/example.org.signed"
            notify: 192.0.53.101 mykey
            notify: 192.0.53.102 mykey
            notify: 192.0.153.101 mykey
            notify: 192.0.153.102 mykey
            provide-xfr: 192.0.53.101 mykey
            provide-xfr: 192.0.53.102 mykey
            provide-xfr: 192.0.153.101 mykey
            provide-xfr: 192.0.153.102 mykey

@slave1 (192.0.53.101)
2015-04-29 09:26:15.323078500 [2015-04-29 09:26:15.322] nsd[17497]:  
info: notify for example.org. from 192.0.53.53 serial 1430292374
--->>> BANG !!!
2015-04-29 09:26:15.325632500 [2015-04-29 09:26:15.325] nsd[9659]:  
error: xfrd: zone example.org. received error code NOT IMPL from  
192.0.53.53

2015-04-29 09:26:15.329649500 [2015-04-29 09:26:15.329] nsd[9659]:  
info: xfrd: zone example.org. written received XFR packet from  
192.0.53.53 with serial 1430292374 to disk
2015-04-29 09:26:15.330310500 [2015-04-29 09:26:15.330] nsd[9659]:  
info: xfrd: zone example.org. written received XFR packet from  
192.0.53.53 with serial 1430292374 to disk
2015-04-29 09:26:15.330687500 [2015-04-29 09:26:15.330] nsd[9659]:  
info: xfrd: zone example.org. written received XFR packet from  
192.0.53.53 with serial 1430292374 to disk
2015-04-29 09:26:15.330761500 [2015-04-29 09:26:15.330] nsd[9659]:  
info: xfrd: zone example.org. committed "received update to serial  
1430292374 at 2015-04-29T09:26:15 from 192.0.53.53 TSIG verified with  
key mykey"
2015-04-29 09:26:15.334419500 [2015-04-29 09:26:15.334] nsd[9705]:  
info: rehash of zone example.org. with parameters 1 0 1 -
2015-04-29 09:26:15.337018500 [2015-04-29 09:26:15.336] nsd[9705]:  
info: zone example.org. received update to serial 1430292374 at  
2015-04-29T09:26:15 from 192.0.53.53 TSIG verified with key mykey of  
41427 bytes in 0.001151 seconds
2015-04-29 09:26:15.337762500 [2015-04-29 09:26:15.337] nsd[17497]:  
info: NSTATS 1430292375 1430291110 A=12205 NS=462 CNAME=77 SOA=292  
PTR=1835 MX=4882 TXT=2892 AAAA=3793 SRV=434 TYPE38=10 NSEC=1 DNSKEY=7  
SPF=1392 TYPE255=139
2015-04-29 09:26:15.337774500 [2015-04-29 09:26:15.337] nsd[17497]:  
info: XSTATS 1430292375 1430291110 RR=0 RNXD=0 RFwdR=0 RDupR=0 RFail=0  
RFErr=0 RErr=0 RAXFR=0 RLame=0 ROpts=0 SSysQ=0 SAns=28408 SFwdQ=0  
SDupQ=0 SErr=0 RQ=28420 RIQ=0 RFwdQ=0 RDupQ=0 RTCP=13 SFwdR=0 SFail=0  
SFErr=0 SNaAns=253 SNXD=1302 RUQ=0 RURQ=0
RUXFR=0 RUUpd=0
2015-04-29 09:26:15.338774500 [2015-04-29 09:26:15.338] nsd[9659]:  
info: zone example.org. serial 1430290388 is updated to 1430292374.

     9659 ?        S      0:31  |   |   \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d
     9705 ?        S      1:28  |   |       \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d
    17745 ?        S      0:00  |   |           \_ /usr/sbin/nsd -c  
/var/lib/nsd/etc/nsd/nsd.conf -d

nsd.conf:
       server:
           chroot: "/var/lib/nsd"
           debug-mode: yes
           statistics: 86400
           verbosity: 9
           ip-address: 127.0.0.53
           ip-address: 192.0.53.101
           nsid: "ascii_SLAVE1"

key:
            name: "mykey"
            algorithm: hmac-sha256
            secret: "secret"

zone:
            name: "example.org."
            # Masterserver ist der 192.0.53.53
            allow-notify: 192.0.53.53 mykey
            request-xfr: 192.0.53.53 mykey
            outgoing-interface: 192.0.53.101

If there are any further question I may provide needed information.
I plan to update master and one slave to 1.4.3.rc1 next week to check  
if the phenomenon is still visible.

Andreas