RRSIG which is not valid yet causes repeated queries to authoritative servers
This behavior can be seen in test sets/resolver/world_cz_rhybar.rpl
version deckard@0b25a1c0.
The snippet causing the problem is:
val-override-date: 20170201163631
rhybar.cz. 18000 IN RRSIG DS 10 2 18000 20170214061134 20170201163953 58211 cz. CGwqHhSb6b8JsjztqPeRDKBC/Sp4O0Igc4r53T+SheWdMwgNwvbXiFD6 krt0FGf1QU/JCkH5L5oYHFeaPXljftB2d0JbzLnA+iaI9Jy1aRmUqvTN /PiDVPYI/SRFvCfk2FLMK5LzMfjPjooiSNv9b1zZKJd8cykq8/jgijXy 5Xk=
I.e. inception time of the RRSIG < current time.
The log looks like this:
[system] interactive mode
> [ 0][plan] plan 'rhybar.cz.' type 'A'
[47197][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[47197][resl] => using root hints
[17823][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[17823][resl] => querying: '2001:dc3::35' score: 10 zone cut: '.' m12n: 'RhyBaR.Cz.' type: 'A' proto: 'udp'
[17823][iter] <= using glue for 'b.ns.nic.cz.': '194.0.13.1'
[17823][iter] <= using glue for 'b.ns.nic.cz.': '2001:678:10::1'
[17823][iter] <= using glue for 'a.ns.nic.cz.': '194.0.12.1'
[17823][iter] <= using glue for 'a.ns.nic.cz.': '2001:678:f::1'
[17823][iter] <= using glue for 'd.ns.nic.cz.': '193.29.206.1'
[17823][iter] <= using glue for 'd.ns.nic.cz.': '2001:678:1::1'
[17823][iter] <= using glue for 'c.ns.nic.cz.': '194.0.14.1'
[17823][iter] <= using glue for 'c.ns.nic.cz.': '2001:678:11::1'
[17823][iter] <= referral response, follow
[17823][resl] <= server: '2001:dc3::35' rtt: 120 ms
[20634][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[20634][resl] => querying: '2001:678:1::1' score: 10 zone cut: 'cz.' m12n: 'rhybaR.CZ.' type: 'A' proto: 'udp'
[20634][iter] <= rcode: NOERROR
[20634][ pc ] => answer cached for TTL=600
[20634][resl] <= server: '2001:678:1::1' rtt: 8 ms
[ 0][resl] finished: 4, queries: 1, mempool: 32800 B
[ 0][plan] plan 'rhybar.cz.' type 'A'
[59360][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[59360][resl] => using root hints
[32239][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[32239][plan] plan '.' type 'DNSKEY'
[36271][iter] '.' type 'DNSKEY' id was assigned, parent id 32239
[36271][resl] => querying: '2001:dc3::35' score: 120 zone cut: '.' m12n: '.' type: 'DNSKEY' proto: 'udp'
[36271][iter] <= rcode: NOERROR
[36271][vldr] <= parent: updating DNSKEY
[36271][vldr] <= answer valid, OK
[36271][resl] <= server: '2001:dc3::35' rtt: 1 ms
[13287][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[13287][resl] => querying: '2001:dc3::35' score: 65 zone cut: '.' m12n: 'rHybAr.Cz.' type: 'A' proto: 'udp'
[13287][iter] <= using glue for 'b.ns.nic.cz.': '194.0.13.1'
[13287][iter] <= using glue for 'b.ns.nic.cz.': '2001:678:10::1'
[13287][iter] <= using glue for 'a.ns.nic.cz.': '194.0.12.1'
[13287][iter] <= using glue for 'a.ns.nic.cz.': '2001:678:f::1'
[13287][iter] <= using glue for 'd.ns.nic.cz.': '193.29.206.1'
[13287][iter] <= using glue for 'd.ns.nic.cz.': '2001:678:1::1'
[13287][iter] <= using glue for 'c.ns.nic.cz.': '194.0.14.1'
[13287][iter] <= using glue for 'c.ns.nic.cz.': '2001:678:11::1'
[13287][iter] <= referral response, follow
[13287][vldr] <= DS: OK
[13287][vldr] <= answer valid, OK
[13287][resl] <= server: '2001:dc3::35' rtt: 4 ms
[ 3864][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[ 3864][plan] plan 'cz.' type 'DNSKEY'
[33358][iter] 'cz.' type 'DNSKEY' id was assigned, parent id 3864
[33358][resl] => querying: '2001:678:11::1' score: 10 zone cut: 'cz.' m12n: 'Cz.' type: 'DNSKEY' proto: 'udp'
[33358][iter] <= rcode: NOERROR
[33358][vldr] <= parent: updating DNSKEY
[33358][vldr] <= answer valid, OK
[33358][resl] <= server: '2001:678:11::1' rtt: 1 ms
[ 2393][iter] 'rhybar.cz.' type 'A' id was assigned, parent id 0
[ 2393][resl] => querying: '2001:678:10::1' score: 10 zone cut: 'cz.' m12n: 'rHyBAR.cz.' type: 'A' proto: 'udp'
[ 2393][iter] <= rcode: NOERROR
[ 2393][vldr] >< cut changed, needs revalidation
[ 2393][resl] <= server: '2001:678:10::1' rtt: 2 ms
[ 2393][plan] plan 'rhybar.cz.' type 'DS'
[50926][iter] 'rhybar.cz.' type 'DS' id was assigned, parent id 2393
[50926][resl] => querying: '2001:678:f::1' score: 10 zone cut: 'cz.' m12n: 'RhybAR.CZ.' type: 'DS' proto: 'udp'
[50926][iter] <= rcode: NOERROR
[50926][vldr] >< no RRSIGs found
[50926][plan] plan 'rhybar.cz.' type 'RRSIG'
[50926][resl] <= server: '2001:678:f::1' rtt: 1 ms
[55962][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[55962][resl] => querying: '2001:678:1::1' score: 11 zone cut: 'cz.' m12n: 'rHyBAr.CZ.' type: 'RRSIG' proto: 'udp'
[55962][iter] <= rcode: SERVFAIL
[55962][resl] <= server: '2001:678:1::1' rtt: 0 ms
[29630][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[29630][resl] => querying: '193.29.206.1' score: 10 zone cut: 'cz.' m12n: 'RHYBAR.CZ.' type: 'RRSIG' proto: 'udp'
[29630][iter] <= rcode: SERVFAIL
[29630][resl] <= server: '193.29.206.1' rtt: 0 ms
[64954][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[64954][resl] => querying: '2001:678:11::1' score: 11 zone cut: 'cz.' m12n: 'rHYBAR.Cz.' type: 'RRSIG' proto: 'udp'
[64954][iter] <= rcode: SERVFAIL
[64954][resl] <= server: '2001:678:11::1' rtt: 0 ms
[56185][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[56185][resl] => querying: '194.0.14.1' score: 10 zone cut: 'cz.' m12n: 'rhYbAR.CZ.' type: 'RRSIG' proto: 'udp'
[56185][iter] <= rcode: SERVFAIL
[56185][resl] => server: '194.0.14.1' flagged as 'bad'
[61332][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[61332][resl] => querying: '2001:678:11::1' score: 111 zone cut: 'cz.' m12n: 'rHYBar.cZ.' type: 'RRSIG' proto: 'udp'
[61332][iter] <= rcode: SERVFAIL
[61332][resl] <= server: '2001:678:11::1' rtt: 0 ms
[34917][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[34917][resl] => querying: '2001:678:10::1' score: 11 zone cut: 'cz.' m12n: 'RHYBAR.cZ.' type: 'RRSIG' proto: 'udp'
[34917][iter] <= rcode: SERVFAIL
[34917][resl] <= server: '2001:678:10::1' rtt: 0 ms
[58600][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[58600][resl] => querying: '2001:678:11::1' score: 161 zone cut: 'cz.' m12n: 'RHYbaR.Cz.' type: 'RRSIG' proto: 'udp'
[58600][iter] <= rcode: SERVFAIL
[58600][resl] <= server: '2001:678:11::1' rtt: 0 ms
[ 9072][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 9072][resl] => querying: '194.0.13.1' score: 10 zone cut: 'cz.' m12n: 'RHyBAR.Cz.' type: 'RRSIG' proto: 'udp'
[ 9072][iter] <= rcode: SERVFAIL
[ 9072][resl] => server: '194.0.13.1' flagged as 'bad'
[19862][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[19862][resl] => querying: '2001:678:f::1' score: 11 zone cut: 'cz.' m12n: 'RhyBAr.CZ.' type: 'RRSIG' proto: 'udp'
[19862][iter] <= rcode: SERVFAIL
[19862][resl] <= server: '2001:678:f::1' rtt: 0 ms
[61142][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[61142][resl] => querying: '2001:678:11::1' score: 186 zone cut: 'cz.' m12n: 'RhYbaR.CZ.' type: 'RRSIG' proto: 'udp'
[61142][iter] <= rcode: SERVFAIL
[61142][resl] <= server: '2001:678:11::1' rtt: 1 ms
[ 7135][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 7135][resl] => querying: '194.0.12.1' score: 10 zone cut: 'cz.' m12n: 'RHYBAR.cZ.' type: 'RRSIG' proto: 'udp'
[ 7135][iter] <= rcode: SERVFAIL
[ 7135][resl] <= server: '194.0.12.1' rtt: 2 ms
[63972][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[63972][resl] => querying: '2001:678:1::1' score: 111 zone cut: 'cz.' m12n: 'RHyBAR.CZ.' type: 'RRSIG' proto: 'udp'
[63972][iter] <= rcode: SERVFAIL
[63972][resl] => server: '2001:678:1::1' flagged as 'bad'
[ 3009][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 3009][resl] => querying: '2001:678:11::1' score: 198 zone cut: 'cz.' m12n: 'rhybAR.Cz.' type: 'RRSIG' proto: 'udp'
[ 3009][iter] <= rcode: SERVFAIL
[ 3009][resl] <= server: '2001:678:11::1' rtt: 1 ms
[54605][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[54605][resl] => querying: '193.29.206.1' score: 111 zone cut: 'cz.' m12n: 'rhYBar.cZ.' type: 'RRSIG' proto: 'udp'
[54605][iter] <= rcode: SERVFAIL
[54605][resl] <= server: '193.29.206.1' rtt: 0 ms
[30581][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[30581][resl] => querying: '2001:678:10::1' score: 111 zone cut: 'cz.' m12n: 'RHYBAr.Cz.' type: 'RRSIG' proto: 'udp'
[30581][iter] <= rcode: SERVFAIL
[30581][resl] <= server: '2001:678:10::1' rtt: 0 ms
[65398][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[65398][resl] => querying: '2001:678:10::1' score: 161 zone cut: 'cz.' m12n: 'rhyBAR.CZ.' type: 'RRSIG' proto: 'udp'
[65398][iter] <= rcode: SERVFAIL
[65398][resl] => server: '2001:678:10::1' flagged as 'bad'
[49369][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[49369][resl] => querying: '2001:678:f::1' score: 111 zone cut: 'cz.' m12n: 'RHybAr.Cz.' type: 'RRSIG' proto: 'udp'
[49369][iter] <= rcode: SERVFAIL
[49369][resl] <= server: '2001:678:f::1' rtt: 0 ms
[31469][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[31469][resl] => querying: '194.0.12.1' score: 111 zone cut: 'cz.' m12n: 'RhybAr.Cz.' type: 'RRSIG' proto: 'udp'
[31469][iter] <= rcode: SERVFAIL
[31469][resl] <= server: '194.0.12.1' rtt: 0 ms
[39202][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[39202][resl] => querying: '193.29.206.1' score: 161 zone cut: 'cz.' m12n: 'rHYbar.Cz.' type: 'RRSIG' proto: 'udp'
[39202][iter] <= rcode: SERVFAIL
[39202][resl] <= server: '193.29.206.1' rtt: 0 ms
[ 797][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 797][resl] => querying: '2001:678:f::1' score: 161 zone cut: 'cz.' m12n: 'RhYbar.CZ.' type: 'RRSIG' proto: 'udp'
[ 797][iter] <= rcode: SERVFAIL
[ 797][resl] => server: '2001:678:f::1' flagged as 'bad'
[18355][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[18355][resl] => querying: '194.0.12.1' score: 161 zone cut: 'cz.' m12n: 'RHYBar.Cz.' type: 'RRSIG' proto: 'udp'
[18355][iter] <= rcode: SERVFAIL
[18355][resl] <= server: '194.0.12.1' rtt: 0 ms
[57235][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[57235][resl] => querying: '193.29.206.1' score: 186 zone cut: 'cz.' m12n: 'rHYbAR.Cz.' type: 'RRSIG' proto: 'udp'
[57235][iter] <= rcode: SERVFAIL
[57235][resl] <= server: '193.29.206.1' rtt: 0 ms
[21285][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[21285][resl] => querying: '194.0.12.1' score: 186 zone cut: 'cz.' m12n: 'rHYbar.Cz.' type: 'RRSIG' proto: 'udp'
[21285][iter] <= rcode: SERVFAIL
[21285][resl] <= server: '194.0.12.1' rtt: 0 ms
[57096][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[57096][resl] => querying: '193.29.206.1' score: 198 zone cut: 'cz.' m12n: 'rHYbaR.cZ.' type: 'RRSIG' proto: 'udp'
[57096][iter] <= rcode: SERVFAIL
[57096][resl] => server: '193.29.206.1' flagged as 'bad'
[41167][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[41167][resl] => querying: '194.0.12.1' score: 198 zone cut: 'cz.' m12n: 'rhYBaR.cZ.' type: 'RRSIG' proto: 'udp'
[41167][iter] <= rcode: SERVFAIL
[41167][resl] <= server: '194.0.12.1' rtt: 0 ms
[25510][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[25510][resl] => querying: '2001:678:11::1' score: 204 zone cut: 'cz.' m12n: 'RHYbaR.CZ.' type: 'RRSIG' proto: 'udp'
[25510][iter] <= rcode: SERVFAIL
[25510][resl] <= server: '2001:678:11::1' rtt: 0 ms
[ 2294][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 2294][resl] => querying: '194.0.12.1' score: 204 zone cut: 'cz.' m12n: 'RHYbar.cZ.' type: 'RRSIG' proto: 'udp'
[ 2294][iter] <= rcode: SERVFAIL
[ 2294][resl] <= server: '194.0.12.1' rtt: 0 ms
[14118][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[14118][resl] => querying: '2001:678:11::1' score: 207 zone cut: 'cz.' m12n: 'RhybaR.cz.' type: 'RRSIG' proto: 'udp'
[14118][iter] <= rcode: SERVFAIL
[14118][resl] => server: '2001:678:11::1' flagged as 'bad'
[61824][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[61824][resl] => querying: '194.0.12.1' score: 207 zone cut: 'cz.' m12n: 'RHybar.CZ.' type: 'RRSIG' proto: 'udp'
[61824][iter] <= rcode: SERVFAIL
[61824][resl] <= server: '194.0.12.1' rtt: 0 ms
[44971][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[44971][resl] => querying: '194.0.12.1' score: 209 zone cut: 'cz.' m12n: 'rhYBAr.CZ.' type: 'RRSIG' proto: 'udp'
[44971][iter] <= rcode: SERVFAIL
[44971][resl] <= server: '194.0.12.1' rtt: 0 ms
[44587][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[44587][resl] => querying: '194.0.12.1' score: 210 zone cut: 'cz.' m12n: 'rHybaR.Cz.' type: 'RRSIG' proto: 'udp'
[44587][iter] <= rcode: SERVFAIL
[44587][resl] <= server: '194.0.12.1' rtt: 0 ms
[58970][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[58970][resl] => querying: '194.0.12.1' score: 210 zone cut: 'cz.' m12n: 'rHYbAR.cZ.' type: 'RRSIG' proto: 'udp'
[58970][iter] <= rcode: SERVFAIL
[58970][resl] => server: '194.0.12.1' flagged as 'bad'
[54018][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[54018][resl] => no valid NS left
[50926][resl] => resuming yielded answer
[50926][vldr] >< no RRSIGs found
[50926][plan] plan 'rhybar.cz.' type 'RRSIG'
[22397][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[22397][resl] => querying: '2001:678:1::1' score: 2850 zone cut: 'cz.' m12n: 'RhyBar.cz.' type: 'RRSIG' proto: 'udp'
[22397][iter] <= rcode: SERVFAIL
[22397][resl] <= server: '2001:678:1::1' rtt: 0 ms
[14742][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[14742][resl] => querying: '2001:678:1::1' score: 1530 zone cut: 'cz.' m12n: 'rhYBar.CZ.' type: 'RRSIG' proto: 'udp'
[14742][iter] <= rcode: SERVFAIL
[14742][resl] <= server: '2001:678:1::1' rtt: 0 ms
[ 7717][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 7717][resl] => querying: '2001:678:1::1' score: 870 zone cut: 'cz.' m12n: 'RHYbaR.Cz.' type: 'RRSIG' proto: 'udp'
[ 7717][iter] <= rcode: SERVFAIL
[ 7717][resl] <= server: '2001:678:1::1' rtt: 0 ms
[33888][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[33888][resl] => querying: '2001:678:1::1' score: 540 zone cut: 'cz.' m12n: 'RhYbAR.Cz.' type: 'RRSIG' proto: 'udp'
[33888][iter] <= rcode: SERVFAIL
[33888][resl] => server: '2001:678:1::1' flagged as 'bad'
[29686][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[29686][resl] => querying: '193.29.206.1' score: 2850 zone cut: 'cz.' m12n: 'rHyBaR.Cz.' type: 'RRSIG' proto: 'udp'
[29686][iter] <= rcode: SERVFAIL
[29686][resl] <= server: '193.29.206.1' rtt: 0 ms
[ 1054][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 1054][resl] => querying: '193.29.206.1' score: 1530 zone cut: 'cz.' m12n: 'rHYbar.CZ.' type: 'RRSIG' proto: 'udp'
[ 1054][iter] <= rcode: SERVFAIL
[ 1054][resl] <= server: '193.29.206.1' rtt: 0 ms
[46440][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[46440][resl] => querying: '193.29.206.1' score: 870 zone cut: 'cz.' m12n: 'rhYbAR.cZ.' type: 'RRSIG' proto: 'udp'
[46440][iter] <= rcode: SERVFAIL
[46440][resl] <= server: '193.29.206.1' rtt: 1 ms
[13696][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[13696][resl] => querying: '193.29.206.1' score: 540 zone cut: 'cz.' m12n: 'rhYBaR.cz.' type: 'RRSIG' proto: 'udp'
[13696][iter] <= rcode: SERVFAIL
[13696][resl] => server: '193.29.206.1' flagged as 'bad'
[35270][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[35270][resl] => querying: '2001:678:11::1' score: 2850 zone cut: 'cz.' m12n: 'RhybAr.Cz.' type: 'RRSIG' proto: 'udp'
[35270][iter] <= rcode: SERVFAIL
[35270][resl] <= server: '2001:678:11::1' rtt: 2 ms
[55121][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[55121][resl] => querying: '2001:678:11::1' score: 1530 zone cut: 'cz.' m12n: 'RhyBar.cZ.' type: 'RRSIG' proto: 'udp'
[55121][iter] <= rcode: SERVFAIL
[55121][resl] <= server: '2001:678:11::1' rtt: 1 ms
[64339][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[64339][resl] => querying: '2001:678:11::1' score: 870 zone cut: 'cz.' m12n: 'rhYBaR.cz.' type: 'RRSIG' proto: 'udp'
[64339][iter] <= rcode: SERVFAIL
[64339][resl] <= server: '2001:678:11::1' rtt: 1 ms
[ 1399][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 1399][resl] => querying: '2001:678:11::1' score: 540 zone cut: 'cz.' m12n: 'RHyBaR.CZ.' type: 'RRSIG' proto: 'udp'
[ 1399][iter] <= rcode: SERVFAIL
[ 1399][resl] => server: '2001:678:11::1' flagged as 'bad'
[58393][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[58393][resl] => querying: '194.0.14.1' score: 2850 zone cut: 'cz.' m12n: 'RHYBaR.CZ.' type: 'RRSIG' proto: 'udp'
[58393][iter] <= rcode: SERVFAIL
[58393][resl] <= server: '194.0.14.1' rtt: 0 ms
[ 2155][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 2155][resl] => querying: '194.0.14.1' score: 1530 zone cut: 'cz.' m12n: 'RHYBaR.cz.' type: 'RRSIG' proto: 'udp'
[ 2155][iter] <= rcode: SERVFAIL
[ 2155][resl] <= server: '194.0.14.1' rtt: 0 ms
[ 9269][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 9269][resl] => querying: '194.0.14.1' score: 870 zone cut: 'cz.' m12n: 'rhYBar.CZ.' type: 'RRSIG' proto: 'udp'
[ 9269][iter] <= rcode: SERVFAIL
[ 9269][resl] <= server: '194.0.14.1' rtt: 0 ms
[58896][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[58896][resl] => querying: '194.0.14.1' score: 540 zone cut: 'cz.' m12n: 'rhyBAR.cz.' type: 'RRSIG' proto: 'udp'
[58896][iter] <= rcode: SERVFAIL
[58896][resl] => server: '194.0.14.1' flagged as 'bad'
[17007][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[17007][resl] => querying: '2001:678:10::1' score: 2850 zone cut: 'cz.' m12n: 'rhyBAr.cz.' type: 'RRSIG' proto: 'udp'
[17007][iter] <= rcode: SERVFAIL
[17007][resl] <= server: '2001:678:10::1' rtt: 1 ms
[32824][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[32824][resl] => querying: '2001:678:10::1' score: 1530 zone cut: 'cz.' m12n: 'rhYbar.cZ.' type: 'RRSIG' proto: 'udp'
[32824][iter] <= rcode: SERVFAIL
[32824][resl] <= server: '2001:678:10::1' rtt: 1 ms
[ 9351][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[ 9351][resl] => querying: '2001:678:10::1' score: 870 zone cut: 'cz.' m12n: 'RHYBar.CZ.' type: 'RRSIG' proto: 'udp'
[ 9351][iter] <= rcode: SERVFAIL
[ 9351][resl] <= server: '2001:678:10::1' rtt: 1 ms
[40368][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[40368][resl] => querying: '2001:678:10::1' score: 540 zone cut: 'cz.' m12n: 'RhYBAr.cZ.' type: 'RRSIG' proto: 'udp'
[40368][iter] <= rcode: SERVFAIL
[40368][resl] => server: '2001:678:10::1' flagged as 'bad'
[63445][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[63445][resl] => querying: '194.0.13.1' score: 2850 zone cut: 'cz.' m12n: 'rhYBAR.cz.' type: 'RRSIG' proto: 'udp'
[63445][iter] <= rcode: SERVFAIL
[63445][resl] <= server: '194.0.13.1' rtt: 0 ms
[46542][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[46542][resl] => querying: '194.0.13.1' score: 1530 zone cut: 'cz.' m12n: 'rhYBAR.CZ.' type: 'RRSIG' proto: 'udp'
[46542][iter] <= rcode: SERVFAIL
[46542][resl] <= server: '194.0.13.1' rtt: 0 ms
[37841][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[37841][resl] => querying: '194.0.13.1' score: 870 zone cut: 'cz.' m12n: 'RHyBAr.cZ.' type: 'RRSIG' proto: 'udp'
[37841][iter] <= rcode: SERVFAIL
[37841][resl] <= server: '194.0.13.1' rtt: 0 ms
[52508][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[52508][resl] => querying: '194.0.13.1' score: 540 zone cut: 'cz.' m12n: 'RHYBAr.cz.' type: 'RRSIG' proto: 'udp'
[52508][iter] <= rcode: SERVFAIL
[52508][resl] => server: '194.0.13.1' flagged as 'bad'
[52048][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[52048][resl] => querying: '2001:678:f::1' score: 2850 zone cut: 'cz.' m12n: 'rHyBAr.cz.' type: 'RRSIG' proto: 'udp'
[52048][iter] <= rcode: SERVFAIL
[52048][resl] <= server: '2001:678:f::1' rtt: 1 ms
[46719][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[46719][resl] => querying: '2001:678:f::1' score: 1530 zone cut: 'cz.' m12n: 'rHybAR.cZ.' type: 'RRSIG' proto: 'udp'
[46719][iter] <= rcode: SERVFAIL
[46719][resl] <= server: '2001:678:f::1' rtt: 1 ms
[48235][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[48235][resl] => querying: '2001:678:f::1' score: 870 zone cut: 'cz.' m12n: 'RhYbAR.CZ.' type: 'RRSIG' proto: 'udp'
[48235][iter] <= rcode: SERVFAIL
[48235][resl] <= server: '2001:678:f::1' rtt: 1 ms
[12078][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[12078][resl] => querying: '2001:678:f::1' score: 540 zone cut: 'cz.' m12n: 'rhYBar.cz.' type: 'RRSIG' proto: 'udp'
[12078][iter] <= rcode: SERVFAIL
[12078][resl] => server: '2001:678:f::1' flagged as 'bad'
[35022][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[35022][resl] => querying: '194.0.12.1' score: 2850 zone cut: 'cz.' m12n: 'rhyBAR.cz.' type: 'RRSIG' proto: 'udp'
[35022][iter] <= rcode: SERVFAIL
[35022][resl] <= server: '194.0.12.1' rtt: 0 ms
[62994][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[62994][resl] => querying: '194.0.12.1' score: 1530 zone cut: 'cz.' m12n: 'RhybaR.cz.' type: 'RRSIG' proto: 'udp'
[62994][iter] <= rcode: SERVFAIL
[62994][resl] <= server: '194.0.12.1' rtt: 0 ms
[20803][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[20803][resl] => querying: '194.0.12.1' score: 870 zone cut: 'cz.' m12n: 'rhYbAR.cz.' type: 'RRSIG' proto: 'udp'
[20803][iter] <= rcode: SERVFAIL
[20803][resl] <= server: '194.0.12.1' rtt: 1 ms
[15772][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[15772][resl] => querying: '194.0.12.1' score: 540 zone cut: 'cz.' m12n: 'rHYBAR.cz.' type: 'RRSIG' proto: 'udp'
[15772][iter] <= rcode: SERVFAIL
[15772][resl] => server: '194.0.12.1' flagged as 'bad'
[10068][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 50926
[10068][resl] => no valid NS left
[33517][iter] 'rhybar.cz.' type 'DS' id was assigned, parent id 2393
[33517][resl] => querying: '2001:678:1::1' score: 2850 zone cut: 'cz.' m12n: 'RhyBAr.Cz.' type: 'DS' proto: 'udp'
[33517][resl] <= server: '2001:678:1::1' rtt: 3 ms
[ 2393][plan] plan 'rhybar.cz.' type 'DS'
[35505][iter] 'rhybar.cz.' type 'DS' id was assigned, parent id 2393
[35505][resl] => querying: '2001:678:1::1' score: 1430 zone cut: 'cz.' m12n: 'rhyBar.Cz.' type: 'DS' proto: 'udp'
[35505][iter] <= rcode: NOERROR
[35505][vldr] >< no RRSIGs found
[35505][plan] plan 'rhybar.cz.' type 'RRSIG'
[35505][resl] <= server: '2001:678:1::1' rtt: 3 ms
[35330][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[35330][resl] => querying: '2001:678:1::1' score: 720 zone cut: 'cz.' m12n: 'RhyBAR.cZ.' type: 'RRSIG' proto: 'udp'
[35330][iter] <= rcode: SERVFAIL
[35330][resl] <= server: '2001:678:1::1' rtt: 1 ms
[24098][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[24098][resl] => querying: '2001:678:1::1' score: 465 zone cut: 'cz.' m12n: 'RHybAR.CZ.' type: 'RRSIG' proto: 'udp'
[24098][iter] <= rcode: SERVFAIL
[24098][resl] <= server: '2001:678:1::1' rtt: 1 ms
[35423][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[35423][resl] => querying: '2001:678:1::1' score: 338 zone cut: 'cz.' m12n: 'rhybar.CZ.' type: 'RRSIG' proto: 'udp'
[35423][iter] <= rcode: SERVFAIL
[35423][resl] <= server: '2001:678:1::1' rtt: 1 ms
[11771][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[11771][resl] => querying: '2001:678:1::1' score: 274 zone cut: 'cz.' m12n: 'rhyBaR.cZ.' type: 'RRSIG' proto: 'udp'
[11771][iter] <= rcode: SERVFAIL
[11771][resl] => server: '2001:678:1::1' flagged as 'bad'
[15810][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[15810][resl] => querying: '193.29.206.1' score: 2850 zone cut: 'cz.' m12n: 'rhYbAr.cz.' type: 'RRSIG' proto: 'udp'
[15810][iter] <= rcode: SERVFAIL
[15810][resl] <= server: '193.29.206.1' rtt: 1 ms
[49853][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[49853][resl] => querying: '193.29.206.1' score: 1530 zone cut: 'cz.' m12n: 'rhybaR.cz.' type: 'RRSIG' proto: 'udp'
[49853][iter] <= rcode: SERVFAIL
[49853][resl] <= server: '193.29.206.1' rtt: 1 ms
[24189][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[24189][resl] => querying: '193.29.206.1' score: 870 zone cut: 'cz.' m12n: 'RHYBAR.cZ.' type: 'RRSIG' proto: 'udp'
[24189][iter] <= rcode: SERVFAIL
[24189][resl] <= server: '193.29.206.1' rtt: 1 ms
[57228][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[57228][resl] => querying: '193.29.206.1' score: 540 zone cut: 'cz.' m12n: 'rhyBAr.cZ.' type: 'RRSIG' proto: 'udp'
[57228][iter] <= rcode: SERVFAIL
[57228][resl] => server: '193.29.206.1' flagged as 'bad'
[23175][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[23175][resl] => querying: '2001:678:11::1' score: 2850 zone cut: 'cz.' m12n: 'rhybaR.Cz.' type: 'RRSIG' proto: 'udp'
[23175][iter] <= rcode: SERVFAIL
[23175][resl] <= server: '2001:678:11::1' rtt: 1 ms
[61373][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[61373][resl] => querying: '2001:678:11::1' score: 1530 zone cut: 'cz.' m12n: 'rhybAr.cZ.' type: 'RRSIG' proto: 'udp'
[61373][iter] <= rcode: SERVFAIL
[61373][resl] <= server: '2001:678:11::1' rtt: 1 ms
[21023][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[21023][resl] => querying: '2001:678:11::1' score: 870 zone cut: 'cz.' m12n: 'RHybar.cz.' type: 'RRSIG' proto: 'udp'
[21023][iter] <= rcode: SERVFAIL
[21023][resl] <= server: '2001:678:11::1' rtt: 1 ms
[31568][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[31568][resl] => querying: '2001:678:11::1' score: 540 zone cut: 'cz.' m12n: 'rhyBAr.Cz.' type: 'RRSIG' proto: 'udp'
[31568][iter] <= rcode: SERVFAIL
[31568][resl] => server: '2001:678:11::1' flagged as 'bad'
[28128][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[28128][resl] => querying: '194.0.14.1' score: 2850 zone cut: 'cz.' m12n: 'RHYBAR.CZ.' type: 'RRSIG' proto: 'udp'
[28128][iter] <= rcode: SERVFAIL
[28128][resl] <= server: '194.0.14.1' rtt: 1 ms
[ 4056][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[ 4056][resl] => querying: '194.0.14.1' score: 1530 zone cut: 'cz.' m12n: 'rHYbaR.Cz.' type: 'RRSIG' proto: 'udp'
[ 4056][iter] <= rcode: SERVFAIL
[ 4056][resl] <= server: '194.0.14.1' rtt: 1 ms
[16486][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[16486][resl] => querying: '194.0.14.1' score: 870 zone cut: 'cz.' m12n: 'RHybAr.Cz.' type: 'RRSIG' proto: 'udp'
[16486][iter] <= rcode: SERVFAIL
[16486][resl] <= server: '194.0.14.1' rtt: 1 ms
[21693][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[21693][resl] => querying: '194.0.14.1' score: 540 zone cut: 'cz.' m12n: 'RHyBAR.cZ.' type: 'RRSIG' proto: 'udp'
[21693][iter] <= rcode: SERVFAIL
[21693][resl] => server: '194.0.14.1' flagged as 'bad'
[ 295][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[ 295][resl] => querying: '2001:678:10::1' score: 2850 zone cut: 'cz.' m12n: 'rhyBAr.Cz.' type: 'RRSIG' proto: 'udp'
[ 295][iter] <= rcode: SERVFAIL
[ 295][resl] <= server: '2001:678:10::1' rtt: 1 ms
[ 3172][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[ 3172][resl] => querying: '2001:678:10::1' score: 1530 zone cut: 'cz.' m12n: 'RHYBar.Cz.' type: 'RRSIG' proto: 'udp'
[ 3172][iter] <= rcode: SERVFAIL
[ 3172][resl] <= server: '2001:678:10::1' rtt: 1 ms
[37768][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[37768][resl] => querying: '2001:678:10::1' score: 870 zone cut: 'cz.' m12n: 'rhYbar.cz.' type: 'RRSIG' proto: 'udp'
[37768][iter] <= rcode: SERVFAIL
[37768][resl] <= server: '2001:678:10::1' rtt: 1 ms
[50310][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[50310][resl] => querying: '2001:678:10::1' score: 540 zone cut: 'cz.' m12n: 'rhYbAr.cZ.' type: 'RRSIG' proto: 'udp'
[50310][iter] <= rcode: SERVFAIL
[50310][resl] => server: '2001:678:10::1' flagged as 'bad'
[62561][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[62561][resl] => querying: '194.0.13.1' score: 2850 zone cut: 'cz.' m12n: 'rhYbAr.cz.' type: 'RRSIG' proto: 'udp'
[62561][iter] <= rcode: SERVFAIL
[62561][resl] <= server: '194.0.13.1' rtt: 2 ms
[24185][iter] 'rhybar.cz.' type 'RRSIG' id was assigned, parent id 35505
[ 0][resl] finished: 8, queries: 5, mempool: 65600 B
Please note line
=> querying: '2001:678:11::1' score: 186 zone cut: 'cz.' m12n: 'RhYbaR.CZ.' type: 'RRSIG' proto: 'udp'
which repeats several times for each authoritative server.
Affected kresd version: 1.2.1, c664f007