[nsd-users] update failed

Wed Aug 17 08:36:50 UTC 2022

Hello!

We upgraded one of our servers from 4.3.5 to 4.6, but had some problems with XFRs (not yet debugged in detail) and hence went back to 4.3.5.

Since that, one of the served zones periodically reports "update failed" without any details, but seems to recover itself (more logs below)
Aug 17 06:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083711025 is updated to 1083711033
Aug 17 06:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example: soa serial 1083711027 update failed, restarting transfer (notified zone)

We already use verbosity: 2, any chance to get more info why the update failed?

Further, I do not understand how it can happen that "serial 1083711025 is updated to 1083711033" but then it complains that an update to an intermediate "serial 1083711027 update failed".

Please give us some info how we can debug this issue or if we shall ignore the problem.

Thanks
Klaus

(update failed with 20 lines before and after)
Aug 17 04:27:16 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone example to file example.zone
Aug 17 04:27:16 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708815 at 2022-08-17T04:27:16 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:16 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from X.X.X.20 serial 1083708815
Aug 17 04:27:16 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from XXXX:XXXX:9::5 serial 1083708815
Aug 17 04:27:21 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from X.X.X.4 serial 1083708817
Aug 17 04:27:21 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from XXXX:XXXX:8::5 serial 1083708817
Aug 17 04:27:21 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708817 at 2022-08-17T04:27:21 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:21 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from X.X.X.20 serial 1083708817
Aug 17 04:27:21 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from XXXX:XXXX:9::5 serial 1083708817
Aug 17 04:27:26 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from X.X.X.4 serial 1083708818
Aug 17 04:27:26 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from XXXX:XXXX:8::5 serial 1083708818
Aug 17 04:27:26 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708818 at 2022-08-17T04:27:26 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:26 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from X.X.X.20 serial 1083708818
Aug 17 04:27:26 tld-all-vnn1.rcode0.net nsd[1528612]: notify for example. from XXXX:XXXX:9::5 serial 1083708818
Aug 17 04:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--e1a4c to file xn--e1a4c.zone
Aug 17 04:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--qxa6a to file xn--qxa6a.zone
Aug 17 04:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708815 at 2022-08-17T04:27:16 from X.X.X.4 TSIG verified with key foobar of 4292 bytes in 8.2e-05 seconds
Aug 17 04:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708817 at 2022-08-17T04:27:21 from X.X.X.4 TSIG verified with key foobar of 8527 bytes in 0.00011 seconds
Aug 17 04:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708818 at 2022-08-17T04:27:26 from X.X.X.4 TSIG verified with key foobar of 4282 bytes in 5e-05 seconds
Aug 17 04:27:30 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083708814 is updated to 1083708818
Aug 17 04:27:30 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example: soa serial 1083708817 update failed, restarting transfer (notified zone)
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[1529116]: notify for example. from X.X.X.4 serial 1083708820
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[1529116]: notify for example. from XXXX:XXXX:8::5 serial 1083708820
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708820 at 2022-08-17T04:27:31 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[1529116]: notify for example. from X.X.X.20 serial 1083708820
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[1529116]: notify for example. from XXXX:XXXX:9::5 serial 1083708820
Aug 17 04:27:31 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708820 at 2022-08-17T04:27:31 from X.X.X.4 TSIG verified with key foobar of 8552 bytes in 0.000105 seconds
Aug 17 04:27:32 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083708818 is updated to 1083708820
Aug 17 04:27:36 tld-all-vnn1.rcode0.net nsd[1529118]: notify for example. from X.X.X.4 serial 1083708821
Aug 17 04:27:36 tld-all-vnn1.rcode0.net nsd[1529118]: notify for example. from XXXX:XXXX:8::5 serial 1083708821
Aug 17 04:27:36 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708821 at 2022-08-17T04:27:36 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:36 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708821 at 2022-08-17T04:27:36 from X.X.X.4 TSIG verified with key foobar of 4372 bytes in 9.3e-05 seconds
Aug 17 04:27:37 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083708820 is updated to 1083708821
Aug 17 04:27:38 tld-all-vnn1.rcode0.net nsd[1529125]: notify for example. from X.X.X.20 serial 1083708821
Aug 17 04:27:38 tld-all-vnn1.rcode0.net nsd[1529125]: notify for example. from XXXX:XXXX:9::5 serial 1083708821
Aug 17 04:27:44 tld-all-vnn1.rcode0.net nsd[1529125]: notify for example. from X.X.X.4 serial 1083708825
Aug 17 04:27:44 tld-all-vnn1.rcode0.net nsd[1529125]: notify for example. from XXXX:XXXX:8::5 serial 1083708825
Aug 17 04:27:44 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083708825 at 2022-08-17T04:27:44 from X.X.X.4 TSIG verified with key foobar"
Aug 17 04:27:45 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083708825 at 2022-08-17T04:27:44 from X.X.X.4 TSIG verified with key foobar of 13919 bytes in 9.5e-05 seconds
Aug 17 04:27:45 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083708821 is updated to 1083708825
Aug 17 04:27:45 tld-all-vnn1.rcode0.net nsd[1529403]: notify for example. from X.X.X.20 serial 1083708825
--
Aug 17 05:27:15 tld-all-vnn1.rcode0.net nsd[1621157]: notify for example. from XXXX:XXXX:8::5 serial 1083709896
Aug 17 05:27:15 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709896 at 2022-08-17T05:27:15 from X.X.X.4 TSIG verified with key foobar"
Aug 17 05:27:15 tld-all-vnn1.rcode0.net nsd[1621157]: notify for example. from X.X.X.20 serial 1083709896
Aug 17 05:27:15 tld-all-vnn1.rcode0.net nsd[1621157]: notify for example. from XXXX:XXXX:9::5 serial 1083709896
Aug 17 05:27:15 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709896 at 2022-08-17T05:27:15 from X.X.X.4 TSIG verified with key foobar of 4351 bytes in 8.2e-05 seconds
Aug 17 05:27:16 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083709895 is updated to 1083709896
Aug 17 05:27:16 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone example to file example.zone
Aug 17 05:27:20 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from X.X.X.20 serial 1083709898
Aug 17 05:27:20 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709898 at 2022-08-17T05:27:20 from X.X.X.20 TSIG verified with key foobar"
Aug 17 05:27:20 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from X.X.X.4 serial 1083709898
Aug 17 05:27:20 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from XXXX:XXXX:8::5 serial 1083709898
Aug 17 05:27:20 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from XXXX:XXXX:9::5 serial 1083709898
Aug 17 05:27:26 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from X.X.X.20 serial 1083709899
Aug 17 05:27:26 tld-all-vnn1.rcode0.net nsd[1621460]: notify for example. from XXXX:XXXX:9::5 serial 1083709899
Aug 17 05:27:26 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709899 at 2022-08-17T05:27:26 from X.X.X.20 TSIG verified with key foobar"
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--e1a4c to file xn--e1a4c.zone
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--qxa6a to file xn--qxa6a.zone
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709898 at 2022-08-17T05:27:20 from X.X.X.20 TSIG verified with key foobar of 8527 bytes in 5.1e-05 seconds
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709899 at 2022-08-17T05:27:26 from X.X.X.20 TSIG verified with key foobar of 4289 bytes in 5.3e-05 seconds
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083709896 is updated to 1083709899
Aug 17 05:27:29 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example: soa serial 1083709898 update failed, restarting transfer (notified zone)
Aug 17 05:27:30 tld-all-vnn1.rcode0.net nsd[1621524]: notify for example. from X.X.X.4 serial 1083709899
Aug 17 05:27:30 tld-all-vnn1.rcode0.net nsd[1621524]: notify for example. from XXXX:XXXX:8::5 serial 1083709899
Aug 17 05:27:31 tld-all-vnn1.rcode0.net nsd[1621524]: notify for example. from X.X.X.20 serial 1083709901
Aug 17 05:27:31 tld-all-vnn1.rcode0.net nsd[1621524]: notify for example. from XXXX:XXXX:9::5 serial 1083709901
Aug 17 05:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709901 at 2022-08-17T05:27:31 from X.X.X.20 TSIG verified with key foobar"
Aug 17 05:27:31 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709901 at 2022-08-17T05:27:31 from X.X.X.20 TSIG verified with key foobar of 8575 bytes in 6.3e-05 seconds
Aug 17 05:27:32 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083709899 is updated to 1083709901
Aug 17 05:27:34 tld-all-vnn1.rcode0.net nsd[1621672]: notify for example. from X.X.X.4 serial 1083709901
Aug 17 05:27:35 tld-all-vnn1.rcode0.net nsd[1621672]: notify for example. from XXXX:XXXX:8::5 serial 1083709901
Aug 17 05:27:36 tld-all-vnn1.rcode0.net nsd[1621672]: notify for example. from X.X.X.20 serial 1083709904
Aug 17 05:27:36 tld-all-vnn1.rcode0.net nsd[1621672]: notify for example. from XXXX:XXXX:9::5 serial 1083709904
Aug 17 05:27:36 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709904 at 2022-08-17T05:27:36 from X.X.X.20 TSIG verified with key foobar"
Aug 17 05:27:36 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709904 at 2022-08-17T05:27:36 from X.X.X.20 TSIG verified with key foobar of 12800 bytes in 0.000107 seconds
Aug 17 05:27:37 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083709901 is updated to 1083709904
Aug 17 05:27:40 tld-all-vnn1.rcode0.net nsd[1621799]: notify for example. from X.X.X.4 serial 1083709904
Aug 17 05:27:40 tld-all-vnn1.rcode0.net nsd[1621799]: notify for example. from XXXX:XXXX:8::5 serial 1083709904
Aug 17 05:27:41 tld-all-vnn1.rcode0.net nsd[1621799]: notify for example. from X.X.X.20 serial 1083709907
Aug 17 05:27:41 tld-all-vnn1.rcode0.net nsd[1621799]: notify for example. from XXXX:XXXX:9::5 serial 1083709907
Aug 17 05:27:41 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083709907 at 2022-08-17T05:27:41 from X.X.X.20 TSIG verified with key foobar"
Aug 17 05:27:41 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083709907 at 2022-08-17T05:27:41 from X.X.X.20 TSIG verified with key foobar of 12698 bytes in 0.000102 seconds
--
Aug 17 06:27:17 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:8::5 serial 1083711026
Aug 17 06:27:17 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711026 at 2022-08-17T06:27:17 from X.X.X.4 TSIG verified with key foobar"
Aug 17 06:27:20 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from X.X.X.20 serial 1083711026
Aug 17 06:27:20 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:9::5 serial 1083711026
Aug 17 06:27:22 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from X.X.X.4 serial 1083711027
Aug 17 06:27:22 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711027 at 2022-08-17T06:27:22 from X.X.X.4 TSIG verified with key foobar"
Aug 17 06:27:22 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:8::5 serial 1083711027
Aug 17 06:27:23 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from X.X.X.20 serial 1083711027
Aug 17 06:27:23 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:9::5 serial 1083711027
Aug 17 06:27:27 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from X.X.X.4 serial 1083711033
Aug 17 06:27:27 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:8::5 serial 1083711033
Aug 17 06:27:27 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711033 at 2022-08-17T06:27:27 from X.X.X.4 TSIG verified with key foobar"
Aug 17 06:27:28 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from X.X.X.20 serial 1083711033
Aug 17 06:27:28 tld-all-vnn1.rcode0.net nsd[1714255]: notify for example. from XXXX:XXXX:9::5 serial 1083711033
Aug 17 06:27:30 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--e1a4c to file xn--e1a4c.zone
Aug 17 06:27:30 tld-all-vnn1.rcode0.net nsd[4148891]: writing zone xn--qxa6a to file xn--qxa6a.zone
Aug 17 06:27:30 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711026 at 2022-08-17T06:27:17 from X.X.X.4 TSIG verified with key foobar of 4244 bytes in 0.000369 seconds
Aug 17 06:27:30 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711027 at 2022-08-17T06:27:22 from X.X.X.4 TSIG verified with key foobar of 4357 bytes in 9.7e-05 seconds
Aug 17 06:27:30 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711033 at 2022-08-17T06:27:27 from X.X.X.4 TSIG verified with key foobar of 25585 bytes in 0.000481 seconds
Aug 17 06:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083711025 is updated to 1083711033
Aug 17 06:27:31 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example: soa serial 1083711027 update failed, restarting transfer (notified zone)
Aug 17 06:27:32 tld-all-vnn1.rcode0.net nsd[1715072]: notify for example. from X.X.X.4 serial 1083711035
Aug 17 06:27:32 tld-all-vnn1.rcode0.net nsd[1715072]: notify for example. from XXXX:XXXX:8::5 serial 1083711035
Aug 17 06:27:32 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711035 at 2022-08-17T06:27:32 from X.X.X.4 TSIG verified with key foobar"
Aug 17 06:27:33 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711035 at 2022-08-17T06:27:32 from X.X.X.4 TSIG verified with key foobar of 8176 bytes in 0.000106 seconds
Aug 17 06:27:33 tld-all-vnn1.rcode0.net nsd[1715072]: notify for example. from X.X.X.20 serial 1083711035
Aug 17 06:27:33 tld-all-vnn1.rcode0.net nsd[1715072]: notify for example. from XXXX:XXXX:9::5 serial 1083711035
Aug 17 06:27:33 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083711033 is updated to 1083711035
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[1715075]: notify for example. from X.X.X.4 serial 1083711036
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[1715075]: notify for example. from XXXX:XXXX:8::5 serial 1083711036
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711036 at 2022-08-17T06:27:43 from X.X.X.4 TSIG verified with key foobar"
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711036 at 2022-08-17T06:27:43 from X.X.X.4 TSIG verified with key foobar of 4313 bytes in 7.1e-05 seconds
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[1715075]: notify for example. from X.X.X.20 serial 1083711036
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083711035 is updated to 1083711036
Aug 17 06:27:43 tld-all-vnn1.rcode0.net nsd[1715097]: notify for example. from XXXX:XXXX:9::5 serial 1083711036
Aug 17 06:27:46 tld-all-vnn1.rcode0.net nsd[1715097]: notify for example. from X.X.X.20 serial 1083711038
Aug 17 06:27:46 tld-all-vnn1.rcode0.net nsd[1715097]: notify for example. from XXXX:XXXX:9::5 serial 1083711038
Aug 17 06:27:46 tld-all-vnn1.rcode0.net nsd[4148890]: xfrd: zone example committed "received update to serial 1083711038 at 2022-08-17T06:27:46 from X.X.X.20 TSIG verified with key foobar"
Aug 17 06:27:46 tld-all-vnn1.rcode0.net nsd[4148891]: zone example. received update to serial 1083711038 at 2022-08-17T06:27:46 from X.X.X.20 TSIG verified with key foobar of 5032 bytes in 8e-05 seconds
Aug 17 06:27:47 tld-all-vnn1.rcode0.net nsd[4148890]: zone example serial 1083711036 is updated to 1083711038
Aug 17 06:27:48 tld-all-vnn1.rcode0.net nsd[1715101]: notify for example. from X.X.X.4 serial 1083711038

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.nlnetlabs.nl/pipermail/nsd-users/attachments/20220817/e0578d51/attachment-0001.htm>