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
