Skip to content

BIND
BIND
Source
Select Git revision
...
Target
Select Git revision
 
Commits (4)
  • Michał Kępień's avatar
    Fix serial number used in zone verification checks · 46480a4b
    Michał Kępień authored 
    Due to the way the "mirror" system test is set up, it is impossible for
the "verify-unsigned" and "verify-untrusted" zones to contain any serial
number other than the original one present in ns2/verify.db.in.  Thus,
using presence of a different serial number in the SOA records of these
zones as an indicator of problems with mirror zone verification is
wrong.  Look for the original zone serial number instead as that is the
one that will be returned by ns3 if one of the aforementioned zones is
successfully verified.
    46480a4b
  • Michał Kępień's avatar
    Improve reliability of zone verification checks · 2cbf1028
    Michał Kępień authored 
    In the "mirror" system test, ns3 periodically sends trust anchor
telemetry queries to ns1 and ns2.  It may thus happen that for some
non-recursive queries for names inside mirror zones which are not yet
loaded, ns3 will be able to synthesize a negative answer from the cached
records it obtained from trust anchor telemetry responses.  In such
cases, NXDOMAIN responses will be sent with the root zone SOA in the
AUTHORITY section.  Since the root zone used in the "mirror" system test
has the same serial number as ns2/verify.db.in and zone verification
checks look for the specified serial numbers anywhere in the answer, the
test could be broken if different zone names were used.

The +noauth dig option could be used to address this weakness, but that
would prevent entire responses from being stored for later inspection,
which in turn would hamper troubleshooting test failures.  Instead, use
a different serial number for ns2/verify.db.in than for any other zone
used in the "mirror" system test and check the number of records in the
ANSWER section of each response.
    2cbf1028
  • Michał Kępień's avatar
    Prevent races when waiting for log messages · 9c611dd9
    Michał Kępień authored 
    The "mirror" system test checks whether log messages announcing a mirror
zone coming into effect are emitted properly.  However, the helper
functions responsible for waiting for zone transfers and zone loading to
complete do not wait for these exact log messages, but rather for other
ones preceding them, which introduces a possibility of false positives.

This problem cannot be addressed by just changing the log message to
look for because the test still needs to discern between transferring a
zone and loading a zone.

Add two new log messages at debug level 99 (which is what named
instances used in system tests are configured with) that are to be
emitted after the log messages announcing a mirror zone coming into
effect.  Tweak the aforementioned helper functions to only return once
the log messages they originally looked for are followed by the newly
added log messages.  This reliably prevents races when looking for
"mirror zone is now in use" log messages and also enables a workaround
previously put into place in the "mirror" system test to be reverted.
    9c611dd9
  • Michał Kępień's avatar
    Merge branch 'michal/improve-stability-of-mirror-zone-tests' into 'master' · 724663c1
    Michał Kępień authored 
    Improve stability of mirror zone system tests

See merge request isc-projects/bind9!1505
    724663c1
Hide whitespace changes
Inline Side-by-side
Showing with 44 additions and 19 deletions
bin/tests/system/mirror/ns1/root.db.in
View file @ 724663c1
......@@ -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.
......
bin/tests/system/mirror/ns2/initially-unavailable.db.in
View file @ 724663c1
......@@ -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.
bin/tests/system/mirror/tests.sh
View file @ 724663c1
......@@ -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
......
lib/dns/xfrin.c
View file @ 724663c1
......@@ -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);
}
......
lib/dns/zone.c
View file @ 724663c1
......@@ -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);
}
......