From bdf0287c2dea32f4e439b458c4ab04ffd1433cf8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20K=C4=99pie=C5=84?= Date: Tue, 6 Mar 2018 11:33:16 +0100 Subject: [PATCH 1/2] Fix a race between "rndc reconfig" and waiting for a ./DNSKEY fetch to complete 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. (cherry picked from commit 012ca0a27dc2058090d97027076cf09b1bb2474a) --- bin/tests/system/mkeys/setup.sh | 1 - bin/tests/system/mkeys/tests.sh | 6 +++--- 2 files changed, 3 insertions(+), 4 deletions(-) diff --git a/bin/tests/system/mkeys/setup.sh b/bin/tests/system/mkeys/setup.sh index 0a7a936aab..64d0e98761 100644 --- a/bin/tests/system/mkeys/setup.sh +++ b/bin/tests/system/mkeys/setup.sh @@ -17,7 +17,6 @@ test -r $RANDFILE || $GENRANDOM 400 $RANDFILE copy_setports ns1/named1.conf.in ns1/named.conf copy_setports ns2/named.conf.in ns2/named.conf copy_setports ns3/named.conf.in ns3/named.conf -copy_setports ns4/named.conf.in ns4/named.conf copy_setports ns5/named.conf.in ns5/named.conf cp ns5/named1.args ns5/named.args diff --git a/bin/tests/system/mkeys/tests.sh b/bin/tests/system/mkeys/tests.sh index 0f1ebad8ef..b524791265 100644 --- a/bin/tests/system/mkeys/tests.sh +++ b/bin/tests/system/mkeys/tests.sh @@ -685,7 +685,7 @@ rm -f ns5/managed-keys.bind* cp ns5/named2.args ns5/named.args nextpart ns5/named.run > /dev/null $PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} . ns5 -wait_for_log "Returned from key fetch in keyfetch_done()" ns5/named.run +wait_for_log "Returned from key fetch in keyfetch_done() for '.': failure" ns5/named.run # ns1 should still REFUSE queries from ns5, so resolving should be impossible $DIG $DIGOPTS +noauth example. @10.53.0.5 txt > dig.out.ns5.a.test$n || ret=1 grep "flags:.*ad.*QUERY" dig.out.ns5.a.test$n > /dev/null && ret=1 @@ -694,9 +694,9 @@ grep "status: SERVFAIL" dig.out.ns5.a.test$n > /dev/null || ret=1 # Allow queries from ns5 to ns1 copy_setports ns1/named3.conf.in ns1/named.conf rm -f ns1/root.db.signed.jnl -mkeys_reconfig_on 1 nextpart ns5/named.run > /dev/null -wait_for_log "Returned from key fetch in keyfetch_done()" ns5/named.run +mkeys_reconfig_on 1 +wait_for_log "Returned from key fetch in keyfetch_done() for '.': success" ns5/named.run # ns1 should not longer REFUSE queries from ns5, so managed keys should be # correctly refreshed and resolving should succeed $DIG $DIGOPTS +noauth example. @10.53.0.5 txt > dig.out.ns5.b.test$n || ret=1 From fe3404a595c98b390af8efc517d14ff68d782db6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20K=C4=99pie=C5=84?= Date: Thu, 8 Mar 2018 13:20:48 +0100 Subject: [PATCH 2/2] Add CHANGES entry 4911. [test] Improved the reliability of the 'mkeys' system test. [GL #128] (cherry picked from commit 32f875f9fc0fc44281fd42bcd4e4ef3f7459ef32) --- CHANGES | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/CHANGES b/CHANGES index e5a8d73fa9..ea5a51a61f 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,6 @@ +4911. [test] Improved the reliability of the 'mkeys' system test. + [GL #128] + 4910. [func] Update util/check-changes to work on release branches. [GL #113] @@ -8,7 +11,7 @@ system test. Also changed its name to allow-query. [GL #81] -4907. [test] Improved the reliabilty of the 'notify' system +4907. [test] Improved the reliability of the 'notify' system test. [GL #59] 4905. [bug] irs_resconf_load() ignored resolv.conf syntax errors