ComputerSurge/bind9
3
0
Fork 0
Code Pull Requests 1 Activity

improve forensic logs

Browse Source 
improve forensic logs by directing output to per sub-test named
files and reporting the sub-subtest number.
This commit is contained in:
Mark Andrews
2019-12-10 14:53:00 +11:00
committed by Ondřej Surý
parent 9bd6720f58
commit 05aa45c602
1 changed files with 124 additions and 121 deletions
Download Patch File Download Diff File Expand all files Collapse all files

245
bin/tests/system/xfer/tests.sh
View File

@@ -18,40 +18,41 @@ RNDCCMD="$RNDC -c $SYSTEMTESTTOP/common/rndc.conf -p ${CONTROLPORT} -s"
status=0
n=0
n=`expr $n + 1`
echo_i "testing basic zone transfer functionality (from primary)"
n=$((n+1))
echo_i "testing basic zone transfer functionality (from primary) ($n)"
tmp=0
$DIG $DIGOPTS example. \
@10.53.0.2 axfr > dig.out.ns2 || tmp=1
grep "^;" dig.out.ns2 | cat_i
@10.53.0.2 axfr > dig.out.ns2.test$n || tmp=1
grep "^;" dig.out.ns2.test$n | cat_i
digcomp dig1.good dig.out.ns2.test$n || tmp=1
digcomp dig1.good dig.out.ns2 || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
n=$((n+1))
echo_i "testing basic zone transfer functionality (from secondary) ($n)"
#
# Spin to allow the zone to tranfer.
#
for i in 1 2 3 4 5
do
tmp=0
$DIG $DIGOPTS example. \
@10.53.0.3 axfr > dig.out.ns3 || tmp=1
grep "^;" dig.out.ns3 > /dev/null || break
echo_i "plain zone re-transfer"
sleep 5
tmp=0
$DIG $DIGOPTS example. \
@10.53.0.3 axfr > dig.out.ns3.test$n || tmp=1
grep "^;" dig.out.ns3.test$n > /dev/null || break
echo_i "plain zone re-transfer"
sleep 5
done
grep "^;" dig.out.ns3 | cat_i
digcomp dig1.good dig.out.ns3 || tmp=1
grep "^;" dig.out.ns3.test$n | cat_i
digcomp dig1.good dig.out.ns3.test$n || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing TSIG signed zone transfers"
$DIG $DIGOPTS tsigzone. @10.53.0.2 axfr -y tsigzone.:1234abcd8765 > dig.out.ns2 || status=1
grep "^;" dig.out.ns2 | cat_i
n=$((n+1))
echo_i "testing TSIG signed zone transfers ($n)"
$DIG $DIGOPTS tsigzone. @10.53.0.2 axfr -y tsigzone.:1234abcd8765 > dig.out.ns2.test$n || status=1
grep "^;" dig.out.ns2.test$n | cat_i
#
# Spin to allow the zone to tranfer.
@@ -59,16 +60,16 @@ grep "^;" dig.out.ns2 | cat_i
for i in 1 2 3 4 5
do
tmp=0
$DIG $DIGOPTS tsigzone. @10.53.0.3 axfr -y tsigzone.:1234abcd8765 > dig.out.ns3 || tmp=1
grep "^;" dig.out.ns3 > /dev/null
$DIG $DIGOPTS tsigzone. @10.53.0.3 axfr -y tsigzone.:1234abcd8765 > dig.out.ns3.test$n || tmp=1
grep "^;" dig.out.ns3.test$n > /dev/null
if test $? -ne 0 ; then break; fi
echo_i "plain zone re-transfer"
sleep 5
done
if test $tmp -eq 1 ; then status=1; fi
grep "^;" dig.out.ns3 | cat_i
grep "^;" dig.out.ns3.test$n | cat_i
digcomp dig.out.ns2 dig.out.ns3 || status=1
digcomp dig.out.ns2.test$n dig.out.ns3.test$n || status=1
echo_i "reload servers for in preparation for ixfr-from-differences tests"
@@ -112,28 +113,29 @@ rndc_reload ns7 10.53.0.7
sleep 3
echo_i "testing zone is dumped after successful transfer"
n=$((n+1))
echo_i "testing zone is dumped after successful transfer ($n)"
$DIG $DIGOPTS +noall +answer +multi @10.53.0.2 \
slave. soa > dig.out.ns2 || tmp=1
grep "1397051952 ; serial" dig.out.ns2 > /dev/null 2>&1 || tmp=1
slave. soa > dig.out.ns2.test$n || tmp=1
grep "1397051952 ; serial" dig.out.ns2.test$n > /dev/null 2>&1 || tmp=1
grep "1397051952 ; serial" ns2/slave.db > /dev/null 2>&1 || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing ixfr-from-differences yes;"
n=$((n+1))
echo_i "testing ixfr-from-differences yes; ($n)"
tmp=0
for i in 0 1 2 3 4 5 6 7 8 9
do
a=0 b=0 c=0 d=0
echo_i "wait for reloads..."
$DIG $DIGOPTS @10.53.0.6 +noall +answer soa master > dig.out.soa1.ns6
grep "1397051953" dig.out.soa1.ns6 > /dev/null && a=1
$DIG $DIGOPTS @10.53.0.1 +noall +answer soa slave > dig.out.soa2.ns1
grep "1397051953" dig.out.soa2.ns1 > /dev/null && b=1
$DIG $DIGOPTS @10.53.0.2 +noall +answer soa example > dig.out.soa3.ns2
grep "1397051953" dig.out.soa3.ns2 > /dev/null && c=1
$DIG $DIGOPTS @10.53.0.6 +noall +answer soa master > dig.out.soa1.ns6.test$n
grep "1397051953" dig.out.soa1.ns6.test$n > /dev/null && a=1
$DIG $DIGOPTS @10.53.0.1 +noall +answer soa slave > dig.out.soa2.ns1.test$n
grep "1397051953" dig.out.soa2.ns1.test$n > /dev/null && b=1
$DIG $DIGOPTS @10.53.0.2 +noall +answer soa example > dig.out.soa3.ns2.test$n
grep "1397051953" dig.out.soa3.ns2.test$n > /dev/null && c=1
[ $a -eq 1 -a $b -eq 1 -a $c -eq 1 ] && break
sleep 2
done
@@ -142,12 +144,12 @@ for i in 0 1 2 3 4 5 6 7 8 9
do
a=0 b=0 c=0 d=0
echo_i "wait for transfers..."
$DIG $DIGOPTS @10.53.0.3 +noall +answer soa example > dig.out.soa1.ns3
grep "1397051953" dig.out.soa1.ns3 > /dev/null && a=1
$DIG $DIGOPTS @10.53.0.3 +noall +answer soa master > dig.out.soa2.ns3
grep "1397051953" dig.out.soa2.ns3 > /dev/null && b=1
$DIG $DIGOPTS @10.53.0.6 +noall +answer soa slave > dig.out.soa3.ns6
grep "1397051953" dig.out.soa3.ns6 > /dev/null && c=1
$DIG $DIGOPTS @10.53.0.3 +noall +answer soa example > dig.out.soa1.ns3.test$n
grep "1397051953" dig.out.soa1.ns3.test$n > /dev/null && a=1
$DIG $DIGOPTS @10.53.0.3 +noall +answer soa master > dig.out.soa2.ns3.test$n
grep "1397051953" dig.out.soa2.ns3.test$n > /dev/null && b=1
$DIG $DIGOPTS @10.53.0.6 +noall +answer soa slave > dig.out.soa3.ns6.test$n
grep "1397051953" dig.out.soa3.ns6.test$n > /dev/null && c=1
[ $a -eq 1 -a $b -eq 1 -a $c -eq 1 ] && break
# re-notify if necessary
@@ -158,62 +160,62 @@ do
done
$DIG $DIGOPTS example. \
@10.53.0.3 axfr > dig.out.ns3 || tmp=1
grep "^;" dig.out.ns3 | cat_i
@10.53.0.3 axfr > dig.out.ns3.test$n || tmp=1
grep "^;" dig.out.ns3.test$n | cat_i
digcomp dig2.good dig.out.ns3 || tmp=1
digcomp dig2.good dig.out.ns3.test$n || tmp=1
# ns3 has a journal iff it received an IXFR.
test -f ns3/example.bk || tmp=1
test -f ns3/example.bk.jnl || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing ixfr-from-differences master; (master zone)"
n=$((n+1))
echo_i "testing ixfr-from-differences master; (master zone) ($n)"
tmp=0
$DIG $DIGOPTS master. \
@10.53.0.6 axfr > dig.out.ns6 || tmp=1
grep "^;" dig.out.ns6 | cat_i
@10.53.0.6 axfr > dig.out.ns6.test$n || tmp=1
grep "^;" dig.out.ns6.test$n | cat_i
$DIG $DIGOPTS master. \
@10.53.0.3 axfr > dig.out.ns3 || tmp=1
grep "^;" dig.out.ns3 > /dev/null && cat_i dig.out.ns3
@10.53.0.3 axfr > dig.out.ns3.test$n || tmp=1
grep "^;" dig.out.ns3.test$n > /dev/null && cat_i dig.out.ns3.test$n
digcomp dig.out.ns6 dig.out.ns3 || tmp=1
digcomp dig.out.ns6.test$n dig.out.ns3.test$n || tmp=1
# ns3 has a journal iff it received an IXFR.
test -f ns3/master.bk || tmp=1
test -f ns3/master.bk.jnl || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing ixfr-from-differences master; (slave zone)"
n=$((n+1))
echo_i "testing ixfr-from-differences master; (slave zone) ($n)"
tmp=0
$DIG $DIGOPTS slave. \
@10.53.0.6 axfr > dig.out.ns6 || tmp=1
grep "^;" dig.out.ns6 | cat_i
@10.53.0.6 axfr > dig.out.ns6.test$n || tmp=1
grep "^;" dig.out.ns6.test$n | cat_i
$DIG $DIGOPTS slave. \
@10.53.0.1 axfr > dig.out.ns1 || tmp=1
grep "^;" dig.out.ns1 | cat_i
@10.53.0.1 axfr > dig.out.ns1.test$n || tmp=1
grep "^;" dig.out.ns1.test$n | cat_i
digcomp dig.out.ns6 dig.out.ns1 || tmp=1
digcomp dig.out.ns6.test$n dig.out.ns1.test$n || tmp=1
# ns6 has a journal iff it received an IXFR.
test -f ns6/slave.bk || tmp=1
test -f ns6/slave.bk.jnl && tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing ixfr-from-differences slave; (master zone)"
n=$((n+1))
echo_i "testing ixfr-from-differences slave; (master zone) ($n)"
tmp=0
# ns7 has a journal iff it generates an IXFR.
@@ -221,35 +223,36 @@ test -f ns7/master2.db || tmp=1
test -f ns7/master2.db.jnl && tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "testing ixfr-from-differences slave; (slave zone)"
n=$((n+1))
echo_i "testing ixfr-from-differences slave; (slave zone) ($n)"
tmp=0
$DIG $DIGOPTS slave. \
@10.53.0.1 axfr > dig.out.ns1 || tmp=1
grep "^;" dig.out.ns1 | cat_i
@10.53.0.1 axfr > dig.out.ns1.test$n || tmp=1
grep "^;" dig.out.ns1.test$n | cat_i
$DIG $DIGOPTS slave. \
@10.53.0.7 axfr > dig.out.ns7 || tmp=1
grep "^;" dig.out.ns1 | cat_i
@10.53.0.7 axfr > dig.out.ns7.test$n || tmp=1
grep "^;" dig.out.ns7.test$n | cat_i
digcomp dig.out.ns7 dig.out.ns1 || tmp=1
digcomp dig.out.ns7.test$n dig.out.ns1.test$n || tmp=1
# ns7 has a journal iff it generates an IXFR.
test -f ns7/slave.bk || tmp=1
test -f ns7/slave.bk.jnl || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
echo_i "check that a multi-message uncompressable zone transfers"
n=$((n+1))
echo_i "check that a multi-message uncompressable zone transfers ($n)"
$DIG axfr . -p ${PORT} @10.53.0.4 | grep SOA > axfr.out
if test `wc -l < axfr.out` != 2
then
echo_i "failed"
status=`expr $status + 1`
status=$((status+1))
fi
# now we test transfers with assorted TSIG glitches
@@ -280,20 +283,20 @@ rndc_reload ns4 10.53.0.4
for i in 0 1 2 3 4 5 6 7 8 9
do
$DIGCMD nil. SOA > dig.out.ns4
grep SOA dig.out.ns4 > /dev/null && break
$DIGCMD nil. SOA > dig.out.ns4.test$n
grep SOA dig.out.ns4.test$n > /dev/null && break
sleep 1
done
sed -n "$cur,\$p" < ns4/named.run | grep "Transfer status: success" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'initial AXFR' >/dev/null || {
echo_i "failed"
status=1
status=$((status+1))
}
echo_i "unsigned transfer"
@@ -307,13 +310,13 @@ sleep 2
sed -n "$cur,\$p" < ns4/named.run | grep "Transfer status: expected a TSIG or SIG(0)" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'unsigned AXFR' >/dev/null && {
echo_i "failed"
status=1
status=$((status+1))
}
echo_i "bad keydata"
@@ -327,13 +330,13 @@ sleep 2
sed -n "$cur,\$p" < ns4/named.run | grep "Transfer status: tsig verify failure" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'bad keydata AXFR' >/dev/null && {
echo_i "failed"
status=1
status=$((status+1))
}
echo_i "partially-signed transfer"
@@ -347,13 +350,13 @@ sleep 2
sed -n "$cur,\$p" < ns4/named.run | grep "Transfer status: expected a TSIG or SIG(0)" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'partially signed AXFR' >/dev/null && {
echo_i "failed"
status=1
status=$((status+1))
}
echo_i "unknown key"
@@ -367,13 +370,13 @@ sleep 2
sed -n "$cur,\$p" < ns4/named.run | grep "tsig key 'tsig_key': key name and algorithm do not match" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'unknown key AXFR' >/dev/null && {
echo_i "failed"
status=1
status=$((status+1))
}
echo_i "incorrect key"
@@ -387,16 +390,16 @@ sleep 2
sed -n "$cur,\$p" < ns4/named.run | grep "tsig key 'tsig_key': key name and algorithm do not match" > /dev/null || {
echo_i "failed: expected status was not logged"
status=1
status=$((status+1))
}
cur=`awk 'END {print NR}' ns4/named.run`
$DIGCMD nil. TXT | grep 'incorrect key AXFR' >/dev/null && {
echo_i "failed"
status=1
status=$((status+1))
}
n=`expr $n + 1`
n=$((n+1))
echo_i "check that we ask for and get a EDNS EXPIRE response ($n)"
# force a refresh query
$RNDCCMD 10.53.0.7 refresh edns-expire 2>&1 | sed 's/^/ns7 /' | cat_i
@@ -406,59 +409,59 @@ sleep 10
expire=`awk '/edns-expire\/IN: got EDNS EXPIRE of/ { x=$9 } END { print x }' ns7/named.run`
test ${expire:-0} -gt 0 -a ${expire:-0} -lt 1814400 || {
echo_i "failed (expire=${expire:-0})"
status=1
status=$((status+1))
}
n=`expr $n + 1`
n=$((n+1))
echo_i "test smaller transfer TCP message size ($n)"
$DIG $DIGOPTS example. @10.53.0.8 axfr \
-y key1.:1234abcd8765 > dig.out.msgsize || status=1
-y key1.:1234abcd8765 > dig.out.msgsize.test$n || status=1
$DOS2UNIX dig.out.msgsize >/dev/null 2>&1
$DOS2UNIX dig.out.msgsize.test$n >/dev/null 2>&1
bytes=`wc -c < dig.out.msgsize`
bytes=`wc -c < dig.out.msgsize.test$n`
if [ $bytes -ne 459357 ]; then
echo_i "failed axfr size check"
status=1
status=$((status+1))
fi
num_messages=`cat ns8/named.run | grep "sending TCP message of" | wc -l`
if [ $num_messages -le 300 ]; then
echo_i "failed transfer message count check"
status=1
status=$((status+1))
fi
n=`expr $n + 1`
n=$((n+1))
echo_i "test mapped zone with out of zone data ($n)"
tmp=0
$DIG -p ${PORT} txt mapped @10.53.0.3 > dig.out.1
grep "status: NOERROR," dig.out.1 > /dev/null || tmp=1
$DIG -p ${PORT} txt mapped @10.53.0.3 > dig.out.1.test$n
grep "status: NOERROR," dig.out.1.test$n > /dev/null || tmp=1
$PERL $SYSTEMTESTTOP/stop.pl xfer ns3
$PERL $SYSTEMTESTTOP/start.pl --noclean --restart --port ${PORT} xfer ns3
for try in 0 1 2 3 4 5 6 7 8 9; do
iret=0
$DIG -p ${PORT} txt mapped @10.53.0.3 > dig.out.2
grep "status: NOERROR," dig.out.2 > /dev/null || iret=1
$DIG -p ${PORT} txt mapped @10.53.0.3 > dig.out.2.test$n
grep "status: NOERROR," dig.out.2.test$n > /dev/null || iret=1
if [ "$iret" -eq 0 ]
then
$DIG -p ${PORT} axfr mapped @10.53.0.3 > dig.out.3
digcomp knowngood.mapped dig.out.3 || iret=1
$DIG -p ${PORT} axfr mapped @10.53.0.3 > dig.out.3.test$n
digcomp knowngood.mapped dig.out.3.test$n || iret=1
fi
[ "$iret" -eq 0 ] && break
sleep 1
done
[ "$iret" -eq 0 ] || tmp=1
[ "$tmp" -ne 0 ] && echo_i "failed"
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
n=$((n+1))
echo_i "test that a zone with too many records is rejected (AXFR) ($n)"
tmp=0
grep "'axfr-too-big/IN'.*: too many records" ns6/named.run >/dev/null || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
n=$((n+1))
echo_i "test that a zone with too many records is rejected (IXFR) ($n)"
tmp=0
grep "'ixfr-too-big./IN.*: too many records" ns6/named.run >/dev/null && tmp=1
@@ -475,18 +478,18 @@ do
done
grep "'ixfr-too-big/IN'.*: too many records" ns6/named.run >/dev/null || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "checking whether dig calculates AXFR statistics correctly"
n=$((n+1))
echo_i "checking whether dig calculates AXFR statistics correctly ($n)"
# Loop until the secondary server manages to transfer the "xfer-stats" zone so
# that we can both check dig output and immediately proceed with the next test.
# Use -b so that we can discern between incoming and outgoing transfers in ns3
# logs later on.
tmp=1
for i in 1 2 3 4 5 6 7 8 9 10; do
$DIG $DIGOPTS +noedns +stat -b 10.53.0.2 @10.53.0.3 xfer-stats. AXFR > dig.out.ns3.$n
if grep "; Transfer failed" dig.out.ns3.$n > /dev/null; then
$DIG $DIGOPTS +noedns +stat -b 10.53.0.2 @10.53.0.3 xfer-stats. AXFR > dig.out.ns3.test$n
if grep "; Transfer failed" dig.out.ns3.test$n > /dev/null; then
sleep 1
else
tmp=0
@@ -496,25 +499,25 @@ done
if [ $tmp -ne 0 ]; then
echo_i "timed out waiting for zone transfer"
else
get_dig_xfer_stats dig.out.ns3.$n > stats.dig
get_dig_xfer_stats dig.out.ns3.test$n > stats.dig
diff axfr-stats.good stats.dig || tmp=1
fi
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
# Note: in the next two tests, we use ns3 logs for checking both incoming and
# outgoing transfer statistics as ns3 is both a secondary server (for ns1) and a
# primary server (for dig queries from the previous test) for "xfer-stats".
n=`expr $n + 1`
echo_i "checking whether named calculates incoming AXFR statistics correctly"
n=$((n+1))
echo_i "checking whether named calculates incoming AXFR statistics correctly ($n)"
tmp=0
get_named_xfer_stats ns3/named.run 10.53.0.1 xfer-stats "Transfer completed" > stats.incoming
diff axfr-stats.good stats.incoming || tmp=1
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
n=`expr $n + 1`
echo_i "checking whether named calculates outgoing AXFR statistics correctly"
n=$((n+1))
echo_i "checking whether named calculates outgoing AXFR statistics correctly ($n)"
tmp=1
for i in 0 1 2 3 4 5 6 7 8 9; do
get_named_xfer_stats ns3/named.run 10.53.0.2 xfer-stats "AXFR ended" > stats.outgoing
@@ -525,7 +528,7 @@ for i in 0 1 2 3 4 5 6 7 8 9; do
sleep 1
done
if test $tmp != 0 ; then echo_i "failed"; fi
status=`expr $status + $tmp`
status=$((status+tmp))
echo_i "exit status: $status"
[ $status -eq 0 ] || exit 1