diff --git a/CHANGES b/CHANGES index a46594cb4f..c3be4bc5b1 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,6 @@ +5137. [func] named now logs messages whenever a mirror zone becomes + usable or unusable for resolution purposes. [GL #818] + 5136. [cleanup] Check in named-checkconf that allow-update and allow-update-forwarding are not set at the view/options level; fix documentation. [GL #512] diff --git a/bin/tests/system/mirror/ns2/named.conf.in b/bin/tests/system/mirror/ns2/named.conf.in index 2979ea9980..1b616e52a8 100644 --- a/bin/tests/system/mirror/ns2/named.conf.in +++ b/bin/tests/system/mirror/ns2/named.conf.in @@ -59,6 +59,7 @@ zone "verify-ixfr" { type master; file "verify-ixfr.db.signed"; ixfr-from-differences yes; + allow-transfer { 10.53.0.3; }; }; zone "verify-reconfig" { diff --git a/bin/tests/system/mirror/tests.sh b/bin/tests/system/mirror/tests.sh index 074e82a451..ce35f67dc0 100644 --- a/bin/tests/system/mirror/tests.sh +++ b/bin/tests/system/mirror/tests.sh @@ -62,7 +62,8 @@ 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 -nextpart ns3/named.run | grep "verify-unsigned.*Zone contains no DNSSEC keys" > /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 status=`expr $status + $ret` @@ -73,7 +74,8 @@ 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 -nextpart ns3/named.run | grep "verify-untrusted.*No trusted KSK DNSKEY found" > /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 status=`expr $status + $ret` @@ -84,7 +86,8 @@ 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 "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1 -nextpart ns3/named.run | grep "No correct RSASHA256 signature for verify-axfr SOA" > /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 if [ $ret != 0 ]; then echo_i "failed"; fi status=`expr $status + $ret` @@ -98,6 +101,7 @@ $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 "${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 status=`expr $status + $ret` @@ -106,12 +110,23 @@ 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 -nextpart ns3/named.run > /dev/null # 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. +# 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). 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. @@ -127,7 +142,10 @@ 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 grep "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1 -nextpart ns3/named.run | grep "No correct RSASHA256 signature for verify-ixfr SOA" > /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 +# be in use as its previous version should have been verified successfully. +nextpartpeek ns3/named.run | grep "verify-ixfr.*mirror zone is no longer in use" > /dev/null && ret=1 if [ $ret != 0 ]; then echo_i "failed"; fi status=`expr $status + $ret` @@ -148,6 +166,10 @@ 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 "${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 +# already be in use before this test case is checked. +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 status=`expr $status + $ret` @@ -158,7 +180,8 @@ 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 "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1 -nextpart ns3/named.run | grep "No correct RSASHA256 signature for verify-load SOA" > /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 if [ $ret != 0 ]; then echo_i "failed"; fi status=`expr $status + $ret` @@ -172,6 +195,7 @@ $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 "${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 status=`expr $status + $ret` @@ -181,12 +205,31 @@ ret=0 $PERL $SYSTEMTESTTOP/stop.pl --use-rndc --port ${CONTROLPORT} mirror ns3 cp ns3/verify-journal.db.mirror ns3/verify-ixfr.db.mirror cp ns3/verify-journal.db.bad.mirror.jnl ns3/verify-ixfr.db.mirror.jnl +# Temporarily disable transfers of the "verify-ixfr" zone on ns2. This is +# required to reliably test whether the message announcing the mirror zone +# coming into effect is not logged after a failed journal verification since +# otherwise a corrected version of the zone may be transferred after +# verification fails but before we look for the aforementioned log message. +# (NOTE: Keep the embedded newline in the sed function list below.) +sed '/^zone "verify-ixfr" {$/,/^};$/ { + s/10.53.0.3/10.53.0.254/ +}' ns2/named.conf > ns2/named.conf.modified +mv ns2/named.conf.modified ns2/named.conf +rndc_reconfig ns2 10.53.0.2 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 "${UPDATED_SERIAL_BAD}.*; serial" dig.out.ns3.test$n > /dev/null && ret=1 -nextpart ns3/named.run | grep "No correct RSASHA256 signature for verify-ixfr SOA" > /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 +# Restore transfers for the "verify-ixfr" zone on ns2. +# (NOTE: Keep the embedded newline in the sed function list below.) +sed '/^zone "verify-ixfr" {$/,/^};$/ { + s/10.53.0.254/10.53.0.3/ +}' ns2/named.conf > ns2/named.conf.modified +mv ns2/named.conf.modified ns2/named.conf +rndc_reconfig ns2 10.53.0.2 if [ $ret != 0 ]; then echo_i "failed"; fi status=`expr $status + $ret` @@ -201,6 +244,7 @@ $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 "${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 status=`expr $status + $ret` @@ -301,7 +345,9 @@ grep "flags:.* ad" dig.out.ns3.test$n.1 > /dev/null || ret=1 # Sanity check: the authoritative server should have been queried. nextpart ns2/named.run | grep "query 'foo.initially-unavailable/A/IN'" > /dev/null || ret=1 # Reconfigure ns2 so that the zone can be mirrored on ns3. -sed "s/10.53.0.254/10.53.0.3/;" ns2/named.conf > ns2/named.conf.modified +sed '/^zone "initially-unavailable" {$/,/^};$/ { + s/10.53.0.254/10.53.0.3/ +}' ns2/named.conf > ns2/named.conf.modified mv ns2/named.conf.modified ns2/named.conf rndc_reconfig ns2 10.53.0.2 # Flush the cache on ns3 and retransfer the mirror zone. @@ -324,7 +370,9 @@ echo_i "checking that resolution succeeds with expired mirror zone data ($n)" ret=0 # Reconfigure ns2 so that the zone from the previous test can no longer be # mirrored on ns3. -sed "s/10.53.0.3/10.53.0.254/;" ns2/named.conf > ns2/named.conf.modified +sed '/^zone "initially-unavailable" {$/,/^};$/ { + s/10.53.0.3/10.53.0.254/ +}' ns2/named.conf > ns2/named.conf.modified mv ns2/named.conf.modified ns2/named.conf rndc_reconfig ns2 10.53.0.2 # Stop ns3, update the timestamp of the zone file to one far in the past, then @@ -335,7 +383,9 @@ nextpart ns3/named.run > /dev/null $PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} mirror ns3 # Ensure named attempts to retransfer the zone due to its expiry. wait_for_transfer initially-unavailable -nextpart ns3/named.run | grep "initially-unavailable.*expired" > /dev/null || ret=1 +# Ensure the expected messages were logged. +nextpartpeek ns3/named.run | grep "initially-unavailable.*expired" > /dev/null || ret=1 +nextpartpeek ns3/named.run | grep "initially-unavailable.*mirror zone is no longer in use" > /dev/null || ret=1 # Query for a record in the expired zone. Resolution should still succeed. $DIG $DIGOPTS @10.53.0.3 foo.initially-unavailable. A > dig.out.ns3.test$n 2>&1 || ret=1 # Check response code and flags in the answer. diff --git a/lib/dns/xfrin.c b/lib/dns/xfrin.c index f7e5cb3ab5..2ae5f94149 100644 --- a/lib/dns/xfrin.c +++ b/lib/dns/xfrin.c @@ -133,6 +133,13 @@ struct dns_xfrin_ctx { dns_tcpmsg_t tcpmsg; bool tcpmsg_valid; + /*% + * Whether the zone originally had a database attached at the time this + * transfer context was created. Used by maybe_free() when making + * logging decisions. + */ + bool zone_had_db; + dns_db_t *db; dns_dbversion_t *ver; dns_diff_t diff; /*%< Pending database changes */ @@ -657,6 +664,10 @@ dns_xfrin_create(dns_zone_t *zone, dns_rdatatype_t xfrtype, dns_zone_getclass(zone), xfrtype, masteraddr, sourceaddr, dscp, tsigkey, &xfr)); + if (db != NULL) { + xfr->zone_had_db = true; + } + CHECK(xfrin_start(xfr)); xfr->done = done; @@ -821,6 +832,7 @@ xfrin_create(isc_mem_t *mctx, /* tcpmsg */ xfr->tcpmsg_valid = false; + xfr->zone_had_db = false; xfr->db = NULL; if (db != NULL) dns_db_attach(db, &xfr->db); @@ -1513,8 +1525,17 @@ maybe_free(dns_xfrin_ctx_t *xfr) { if (xfr->db != NULL) dns_db_detach(&xfr->db); - if (xfr->zone != NULL) + if (xfr->zone != NULL) { + if (!xfr->zone_had_db && + xfr->shuttingdown && + xfr->shutdown_result == ISC_R_SUCCESS && + dns_zone_gettype(xfr->zone) == dns_zone_mirror) + { + dns_zone_log(xfr->zone, ISC_LOG_INFO, + "mirror zone is now in use"); + } dns_zone_idetach(&xfr->zone); + } isc_mem_putanddetach(&xfr->mctx, xfr, sizeof(*xfr)); } diff --git a/lib/dns/zone.c b/lib/dns/zone.c index 5a22e77998..954245c999 100644 --- a/lib/dns/zone.c +++ b/lib/dns/zone.c @@ -4440,6 +4440,7 @@ zone_postload(dns_zone_t *zone, dns_db_t *db, isc_time_t loadtime, bool needdump = false; bool hasinclude = DNS_ZONE_FLAG(zone, DNS_ZONEFLG_HASINCLUDE); bool nomaster = false; + bool had_db = false; unsigned int options; dns_include_t *inc; @@ -4804,6 +4805,7 @@ zone_postload(dns_zone_t *zone, dns_db_t *db, isc_time_t loadtime, ZONEDB_LOCK(&zone->dblock, isc_rwlocktype_write); if (zone->db != NULL) { + had_db = true; result = zone_replacedb(zone, db, false); ZONEDB_UNLOCK(&zone->dblock, isc_rwlocktype_write); if (result != ISC_R_SUCCESS) @@ -4915,6 +4917,11 @@ zone_postload(dns_zone_t *zone, dns_db_t *db, isc_time_t loadtime, dns_db_issecure(db) ? " (DNSSEC signed)" : ""); } + if (!had_db && zone->type == dns_zone_mirror) { + dns_zone_logc(zone, DNS_LOGCATEGORY_ZONELOAD, ISC_LOG_INFO, + "mirror zone is now in use"); + } + zone->loadtime = loadtime; goto done; @@ -10838,6 +10845,12 @@ zone_unload(dns_zone_t *zone) { ZONEDB_UNLOCK(&zone->dblock, isc_rwlocktype_write); DNS_ZONE_CLRFLAG(zone, DNS_ZONEFLG_LOADED); DNS_ZONE_CLRFLAG(zone, DNS_ZONEFLG_NEEDDUMP); + + if (zone->type == dns_zone_mirror) { + dns_zone_log(zone, ISC_LOG_INFO, + "mirror zone is no longer in use; " + "reverting to normal recursion"); + } } void