race in autosign system test.

Job #889493 failed for 6ca026b3:

wait_for_log "add delay\.example\..*NSEC.a\.delay\.example\. NS SOA RRSIG NSEC DNSKEY" ns3/named.run returns before the zone is marked as secure. This can result in the subsequent lookups being returned without RRSIGs. Retry these lookups if they fail.

I:autosign:checking scheduled key activation (72)
I:autosign:waiting for changes to take effect
I:autosign:failed

echo_i "checking scheduled key activation ($n)"
ret=0
$SETTIME -K ns3 -A now+3s $zsk > settime.out.test$n.zsk || ret=1
$SETTIME -K ns3 -A now+3s $ksk > settime.out.test$n.ksk || ret=1
($RNDCCMD 10.53.0.3 loadkeys delay.example. 2>&1 | sed 's/^/ns2 /' | cat_i) || ret=1
echo_i "waiting for changes to take effect"
sleep 3
wait_for_log "add delay\.example\..*NSEC.a\.delay\.example\. NS SOA RRSIG NSEC DNSKEY" ns3/named.run
$DIG $DIGOPTS +noall +answer dnskey delay.example. @10.53.0.3 > dig.out.ns3.1.test$n || ret=1
# DNSKEY expected:
awk 'BEGIN {r=1} $4=="DNSKEY" {r=0} END {exit r}' dig.out.ns3.1.test$n || ret=1
# RRSIG expected:
awk 'BEGIN {r=1} $4=="RRSIG" {r=0} END {exit r}' dig.out.ns3.1.test$n || ret=1
$DIG $DIGOPTS +noall +answer a a.delay.example. @10.53.0.3 > dig.out.ns3.2.test$n || ret=1
# A expected:
awk 'BEGIN {r=1} $4=="A" {r=0} END {exit r}' dig.out.ns3.2.test$n || ret=1
# RRSIG expected:
awk 'BEGIN {r=1} $4=="RRSIG" {r=0} END {exit r}' dig.out.ns3.2.test$n || ret=1
n=`expr $n + 1`
if [ $ret != 0 ]; then echo_i "failed"; fi
status=`expr $status + $ret`

head autosign/dig.out.ns3.[12].test72
==> autosign/dig.out.ns3.1.test72 <==
delay.example.		300	IN	DNSKEY	256 3 7 AwEAAb0FjNazob/oUqj6yoPtX2zHZZBJ4lTMY6Dj5PFNIUnugIh3DtTf uyPRuby+6OAjTn24FNxOrlu/UcIpJllSI5U3hWEMRrowOL0UnkqB7GaC zxPcbTbyHvj51/fijdeFhK4mWzLDZPEbTYLNaxjOHsAI2Kyti3LelRzH VEw/wTU5
delay.example.		300	IN	DNSKEY	257 3 7 AwEAAbZ3JQjYj4J0bbHfC496OClZx8PVTSsXEGPj9BFnlWQ8Zb7rhQn8 H45RuUYh/gt0btmjPetD9ANKPj/S2vB62lkZo+X8FoU8h2tSLtkJ7Rsp XGCSyldNgzgtYSjTcU1SD0vpaVGNxSVShF8tSrQyO66xBpeQOl/hXQBq ncBxffBABsMdNLPKW3SYJGX6WqgasNh0/RjZbA5mWtYA+6v1nNXY8m9Z cJwkTN7X64tOrNbEizaphRqumbeRen9EmqZ58hvpklDMA8fZz99vwDnS flPVLoM/jlSPGyMIKJpH8EJW2kxSrsXRz/cXVhZfEZ5fAj7iCkfInktp B1C7Al4A6U8=

==> autosign/dig.out.ns3.2.test72 <==
a.delay.example.	300	IN	A	10.0.0.1

17-May-2020 23:47:49.971 received control channel command 'loadkeys delay.example.'
...
17-May-2020 23:47:52.976 add re-sign delay.example.             300     IN      RRSIG   DNSKEY 7 2 300 20200616234752 20200517224752 57189 delay.example. HnZUVSTqk2heuru5n2ju+SZYk64836po4FLbEhkC1Ox71mJCdSvLG5SH 16ZM03Nx2P4eu7NzYNNpj+Ndn04cHzT3Q5TczYDxu6PY7YpdaYrNT2ng TLHcvfSbzqdYISJPmyC1y39zufR/tg1y3BVgpcOXdT9tnH6Odihgn6mM 9vE=
...
17-May-2020 23:47:52.976 add re-sign delay.example.             300     IN      RRSIG   DNSKEY 7 2 300 20200616234752 20200517224752 19579 delay.example. k6VYi0hXM8wPowFry2TncPgoUAdH9tjqeMCLEmvW8MkUwsXer334fe+E tKU4K3/2WwujBwF1828EIR4ts03rtYCsDT2WQVbDaC1S3dy71CdErDDZ e3COggxN/opGiS+7Bp5w1SH2ctdCViV/jJkRp10Y+ByjPHVTqiBl13OW kaP/NZlUOKcWZyzVnBtF0hrUkDds1rKy8D7Uwm7/Qm1gyPIKSRJ7HM76 kfBdoWsyAwuU7CzoD8yEHxDHeAqtpblCcN71rjEy085DLcab0oB83knU 12BoQx/7rgAo3fJHv1IHZR4vQdVVJcAI87KfaKZvlhRXwOpTrAb5JGVt TPIHoQ==
...
17-May-2020 23:47:53.624 add re-sign a.delay.example.   300     IN      RRSIG   A 7 3 300 20200602150652 20200517224753 57189 delay.example. F5sae3NdEnj250wHmWQkdxwotLvM41EQCY7xwgFXX8L0x6Bucy0adAYH 9fJpGX9q07D1FTesi1Jz8i6r00U4PNLoR82qPSBY6CAQmpoTLKxi7Shq PL4eN6j9+Z1wrMhLFmZmJmOO92g6Sfe1Sa02VAc/0tU3NUacCYuzawZl gk0=
...
17-May-2020 23:47:54.024 add delay.example.             3600    IN      NSEC    a.delay.example. NS SOA RRSIG NSEC DNSKEY
...
17-May-2020 23:47:54.045 query client=0x7fcc6807fcd0 thread=0x7fcc9c821700 (delay.example/DNSKEY): query_find
...
17-May-2020 23:47:54.066 query client=0x7fcc9121dc40 thread=0x7fcc9a81d700 (a.delay.example/A): query_find