Calling nextpart() after reconfiguring ns1 is not safe, because the
expected log message may appear in ns5/named.run before nextpart() is
run. With the TTL for ./DNSKEY set to 20 seconds, ns5 will refresh it
after 10 seconds, by which time wait_for_log() will already have failed.
This results in a false negative.
However, just calling nextpart() before reconfiguring ns1 would
introduce a different problem: if ns5 refreshed ./DNSKEY between these
two steps, the subsequent wait_for_log() call would return immediately
as it would come across the log message about a failure while refreshing
./DNSKEY instead of the expected success. This in turn would result in
a different false negative as the root key would still be uninitialized
by the time "rndc secroots" is called.
Prevent both kinds of false negatives by:
- calling nextpart() before reconfiguring ns1, in order to prevent the
first case described above,
- looking for a more specific log message, in order to prevent the
second case described above.
Also look for a more specific log message in the first part of the
relevant check, not to fix any problem, but just to emphasize that a
different fetch result is expected in that case.
With these tweaks in place, if a (failed) ./DNSKEY refresh is scheduled
between nextpart() and reconfiguring ns1, wait_for_log() will just wait
for two more seconds (one "hour"), at which point another refresh
attempt will be made that will succeed.