From: Michał Kępień Date: Wed, 16 Jan 2019 14:31:48 +0000 (+0100) Subject: Log a message when a transferred mirror zone comes into effect X-Git-Tag: v9.13.6~51^2~3 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=1c97ace7dc9608c5b4e92c4f3eca5eae5305e831;p=thirdparty%2Fbind9.git Log a message when a transferred mirror zone comes into effect Log a message when a mirror zone is successfully transferred and verified, but only if no database for that zone was yet loaded at the time the transfer was initiated. This could have been implemented in a simpler manner, e.g. by modifying zone_replacedb(), but (due to the calling order of the functions involved in finalizing a zone transfer) that would cause the resulting logs to suggest that a mirror zone comes into effect before its transfer is finished, which would be confusing given the nature of mirror zones and the fact that no message is logged upon successful mirror zone verification. Once the dns_zone_replacedb() call in axfr_finalize() is made, it becomes impossible to determine whether the transferred zone had a database attached before the transfer was started. Thus, that check is instead performed when the transfer context is first created and the result of this check is passed around in a field of the transfer context structure. If it turns out to be desired, the relevant log message is then emitted just before the transfer context is freed. Taking this approach means that the log message added by this commit is not timed precisely, i.e. mirror zone data may be used before this message is logged. However, that can only be fixed by logging the message inside zone_replacedb(), which causes arguably more dire issues discussed above. dns_zone_isloaded() is not used to double-check that transferred zone data was correctly loaded since the 'shutdown_result' field of the zone transfer context will not be set to ISC_R_SUCCESS unless axfr_finalize() succeeds (and that in turn will not happen unless dns_zone_replacedb() succeeds). --- diff --git a/bin/tests/system/mirror/ns2/named.conf.in b/bin/tests/system/mirror/ns2/named.conf.in index 2979ea99805..1b616e52a8c 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 074e82a4514..e6702de1dfa 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. @@ -148,6 +163,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 effect 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` diff --git a/lib/dns/xfrin.c b/lib/dns/xfrin.c index f7e5cb3ab51..2ae5f941491 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)); }