Commit 724663c1 authored by Michał Kępień's avatar Michał Kępień

Merge branch 'michal/improve-stability-of-mirror-zone-tests' into 'master'

Improve stability of mirror zone system tests

See merge request !1505
parents 3c47622f 9c611dd9
Pipeline #9957 passed with stages
in 58 seconds
......@@ -8,7 +8,7 @@
; information regarding copyright ownership.
$TTL 3600
@ SOA a.root-servers.nil. hostmaster 2000010100 3600 1200 604800 3600
@ SOA a.root-servers.nil. hostmaster 1 3600 1200 604800 3600
@ NS a.root-servers.nil.
a.root-servers.nil. A 10.53.0.1
example NS ns2.example.
......
......@@ -8,7 +8,7 @@
; information regarding copyright ownership.
$TTL 3600
@ SOA a.root-servers.nil. hostmaster 2000010100 3600 1200 604800 3600
@ SOA a.root-servers.nil. hostmaster 1 3600 1200 604800 3600
@ NS ns2
ns2 A 10.53.0.2
foo CNAME foo.example.
......@@ -17,10 +17,20 @@ RNDCCMD="$RNDC -c $SYSTEMTESTTOP/common/rndc.conf -p ${CONTROLPORT} -s"
# Wait until the transfer of the given zone to ns3 either completes successfully
# or is aborted by a verification failure or a REFUSED response from the master.
# Note that matching on any transfer status is deliberately avoided because some
# checks performed by this test cause transfer attempts to end with the "IXFR
# failed" status, which is followed by an AXFR retry and this test needs to
# check what the result of the latter transfer attempt is.
wait_for_transfer() {
zone=$1
for i in 1 2 3 4 5 6 7 8 9 10; do
nextpartpeek ns3/named.run | egrep "'$zone/IN'.*Transfer status: (success|verify failure|REFUSED)" > /dev/null && return
# Wait until a "freeing transfer context" message is logged
# after one of the transfer results we are looking for is
# logged. This is needed to prevent races when checking for
# "mirror zone is now in use" messages.
nextpartpeek ns3/named.run | \
awk "matched; /'$zone\/IN'.*Transfer status: (success|verify failure|REFUSED)/ {matched=1}" | \
grep "'$zone/IN'.*freeing transfer context" > /dev/null && return
sleep 1
done
echo_i "exceeded time limit waiting for proof of '$zone' being transferred to appear in ns3/named.run"
......@@ -34,7 +44,13 @@ wait_for_load() {
serial=$2
log=$3
for i in 1 2 3 4 5 6 7 8 9 10; do
nextpartpeek $log | egrep "$zone.*(loaded serial $serial|unable to load)" > /dev/null && return
# Wait until a "zone_postload: (...): done" message is logged
# after one of the loading-related messages we are looking for
# is logged. This is needed to prevent races when checking for
# "mirror zone is now in use" messages.
nextpartpeek $log | \
awk "matched; /$zone.*(loaded serial $serial|unable to load)/ {matched=1}" | \
grep "zone_postload: zone $zone/IN: done" > /dev/null && return
sleep 1
done
echo_i "exceeded time limit waiting for proof of '$zone' being loaded to appear in $log"
......@@ -61,7 +77,8 @@ echo_i "checking that an unsigned mirror zone is rejected ($n)"
ret=0
wait_for_transfer verify-unsigned
$DIG $DIGOPTS @10.53.0.3 +norec verify-unsigned SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null || ret=1
grep "${ORIGINAL_SERIAL}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "verify-unsigned.*Zone contains no DNSSEC keys" > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-unsigned.*mirror zone is now in use" > /dev/null && ret=1
if [ $ret != 0 ]; then echo_i "failed"; fi
......@@ -73,7 +90,8 @@ ret=0
nextpartreset ns3/named.run
wait_for_transfer verify-untrusted
$DIG $DIGOPTS @10.53.0.3 +norec verify-untrusted SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null || ret=1
grep "${ORIGINAL_SERIAL}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "verify-untrusted.*No trusted KSK DNSKEY found" > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-untrusted.*mirror zone is now in use" > /dev/null && ret=1
if [ $ret != 0 ]; then echo_i "failed"; fi
......@@ -85,6 +103,7 @@ ret=0
nextpartreset ns3/named.run
wait_for_transfer verify-axfr
$DIG $DIGOPTS @10.53.0.3 +norec verify-axfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null || ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "No correct RSASHA256 signature for verify-axfr SOA" > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-axfr.*mirror zone is now in use" > /dev/null && ret=1
......@@ -100,6 +119,7 @@ reload_zone verify-axfr ${UPDATED_SERIAL_GOOD}
$RNDCCMD 10.53.0.3 retransfer verify-axfr > /dev/null 2>&1
wait_for_transfer verify-axfr
$DIG $DIGOPTS @10.53.0.3 +norec verify-axfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null && ret=1
grep "${UPDATED_SERIAL_GOOD}.*; serial" dig.out.ns3.test$n > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-axfr.*mirror zone is now in use" > /dev/null || ret=1
if [ $ret != 0 ]; then echo_i "failed"; fi
......@@ -110,23 +130,14 @@ echo_i "checking that an IXFR of an incorrectly signed mirror zone is rejected (
nextpartreset ns3/named.run
ret=0
wait_for_transfer verify-ixfr
# Sanity check: the initial, properly signed version of the zone should have
# been announced as coming into effect.
nextpart ns3/named.run | grep "verify-ixfr.*mirror zone is now in use" > /dev/null || ret=1
# Make a copy of the original zone file for reuse in journal tests below.
cp ns2/verify-ixfr.db.signed ns3/verify-journal.db.mirror
# Wait 1 second so that the zone file timestamp changes and the subsequent
# invocation of "rndc reload" triggers a zone reload. This should also be way
# more than enough for the log message announcing the mirror zone coming into
# effect to appear in the log (see below).
# invocation of "rndc reload" triggers a zone reload.
sleep 1
# Sanity check: the initial, properly signed version of the zone should have
# been announced as coming into effect. Note that we cannot check that
# immediately after wait_for_transfer() as the latter might return before the
# log message we are looking for here appears; we also cannot call nextpart()
# after we update the zone on ns2 since there is a possibility of periodic
# refreshes triggering an IXFR of the "verify-ixfr" zone before the "rndc
# refresh" call below and that possibility needs to be handled as proper
# behavior. Thus, we need to look for the log message now.
nextpart ns3/named.run | grep "verify-ixfr.*mirror zone is now in use" > /dev/null || ret=1
# Update the "verify-ixfr" zone on ns2.
cat ns2/verify-ixfr.db.bad.signed > ns2/verify-ixfr.db.signed
reload_zone verify-ixfr ${UPDATED_SERIAL_BAD}
# Make a copy of the bad zone journal for reuse in journal tests below.
......@@ -141,6 +152,9 @@ if [ `nextpartpeek ns3/named.run | grep "verify-ixfr.*got incremental response"
fi
# Ensure the new, bad version of the zone was not accepted.
$DIG $DIGOPTS @10.53.0.3 +norec verify-ixfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
# A positive answer is expected as the original version of the "verify-ixfr"
# zone should have been successfully verified.
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null && ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "No correct RSASHA256 signature for verify-ixfr SOA" > /dev/null || ret=1
# Despite the verification failure for this IXFR, this mirror zone should still
......@@ -165,6 +179,7 @@ $RNDCCMD 10.53.0.3 refresh verify-ixfr > /dev/null 2>&1
wait_for_transfer verify-ixfr
# Ensure the new, good version of the zone was accepted.
$DIG $DIGOPTS @10.53.0.3 +norec verify-ixfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null && ret=1
grep "${UPDATED_SERIAL_GOOD}.*; serial" dig.out.ns3.test$n > /dev/null || ret=1
# The log message announcing the mirror zone coming into effect should not have
# been logged this time since the mirror zone in question is expected to
......@@ -179,6 +194,7 @@ ret=0
nextpartreset ns3/named.run
wait_for_load verify-load ${UPDATED_SERIAL_BAD} ns3/named.run
$DIG $DIGOPTS @10.53.0.3 +norec verify-load SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null || ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "No correct RSASHA256 signature for verify-load SOA" > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-load.*mirror zone is now in use" > /dev/null && ret=1
......@@ -194,6 +210,7 @@ nextpart ns3/named.run > /dev/null
$PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} mirror ns3
wait_for_load verify-load ${UPDATED_SERIAL_GOOD} ns3/named.run
$DIG $DIGOPTS @10.53.0.3 +norec verify-load SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null && ret=1
grep "${UPDATED_SERIAL_GOOD}.*; serial" dig.out.ns3.test$n > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-load.*mirror zone is now in use" > /dev/null || ret=1
if [ $ret != 0 ]; then echo_i "failed"; fi
......@@ -220,6 +237,7 @@ nextpart ns3/named.run > /dev/null
$PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} mirror ns3
wait_for_load verify-ixfr ${UPDATED_SERIAL_BAD} ns3/named.run
$DIG $DIGOPTS @10.53.0.3 +norec verify-ixfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null || ret=1
grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1
nextpartpeek ns3/named.run | grep "No correct RSASHA256 signature for verify-ixfr SOA" > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-ixfr.*mirror zone is now in use" > /dev/null && ret=1
......@@ -243,6 +261,7 @@ nextpart ns3/named.run > /dev/null
$PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} mirror ns3
wait_for_load verify-ixfr ${UPDATED_SERIAL_GOOD} ns3/named.run
$DIG $DIGOPTS @10.53.0.3 +norec verify-ixfr SOA > dig.out.ns3.test$n 2>&1 || ret=1
grep "ANSWER: 0" dig.out.ns3.test$n > /dev/null && ret=1
grep "${UPDATED_SERIAL_GOOD}.*; serial" dig.out.ns3.test$n > /dev/null || ret=1
nextpartpeek ns3/named.run | grep "verify-ixfr.*mirror zone is now in use" > /dev/null || ret=1
if [ $ret != 0 ]; then echo_i "failed"; fi
......
......@@ -1534,6 +1534,10 @@ maybe_free(dns_xfrin_ctx_t *xfr) {
dns_zone_log(xfr->zone, ISC_LOG_INFO,
"mirror zone is now in use");
}
xfrin_log(xfr, ISC_LOG_DEBUG(99), "freeing transfer context");
/*
* xfr->zone must not be detached before xfrin_log() is called.
*/
dns_zone_idetach(&xfr->zone);
}
......
......@@ -5069,6 +5069,8 @@ zone_postload(dns_zone_t *zone, dns_db_t *db, isc_time_t loadtime,
DNS_ZONE_CLRFLAG(zone->secure, DNS_ZONEFLG_LOADPENDING);
}
zone_debuglog(zone, "zone_postload", 99, "done");
return (result);
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment