Merge pull request #1198 from NLnetLabs/bugfix/log-servfail-serve-expired

gthess · web-flow · commit 1512945c79e9 · 2024-12-03T14:02:03.000+01:00
Fix log-servfail with serve expired and no useful cache contents
diff --git a/services/mesh.c b/services/mesh.c
@@ -2203,8 +2203,13 @@ mesh_serve_expired_callback(void* arg)
 			qstate->serve_expired_data->get_cached_answer));
 		msg = (*qstate->serve_expired_data->get_cached_answer)(qstate,
 			lookup_qinfo, &is_expired);
-		if(!msg)
+		if(!msg || (FLAGS_GET_RCODE(msg->rep->flags) != LDNS_RCODE_NOERROR
+			&& FLAGS_GET_RCODE(msg->rep->flags) != LDNS_RCODE_NXDOMAIN
+			&& FLAGS_GET_RCODE(msg->rep->flags) != LDNS_RCODE_YXDOMAIN)) {
+			/* We don't care for cached failure answers at this
+			 * stage. */
 			return;
+		}
 		/* Reset these in case we pass a second time from here. */
 		encode_rep = msg->rep;
 		memset(&actinfo, 0, sizeof(actinfo));
diff --git a/testdata/iter_failreply.rpl b/testdata/iter_failreply.rpl
@@ -3,7 +3,6 @@ server:
 	target-fetch-policy: "0 0 0 0 0"
 	qname-minimisation: "no"
 	minimal-responses: no
-	log-servfail: yes
 
 stub-zone:
 	name: "."
diff --git a/testdata/iter_scrub_rr_length.rpl b/testdata/iter_scrub_rr_length.rpl
@@ -5,7 +5,6 @@ server:
 	minimal-responses: no
 	rrset-roundrobin: no
 	ede: yes
-	log-servfail: yes
 
 stub-zone:
 	name: "."
diff --git a/testdata/log_servfail.tdir/log_servfail.conf b/testdata/log_servfail.tdir/log_servfail.conf
@@ -0,0 +1,27 @@
+server:
+	verbosity: 0
+	use-syslog: no
+	directory: ""
+	pidfile: "unbound.pid"
+	chroot: ""
+	username: ""
+	do-not-query-localhost: no
+	use-caps-for-id: no
+	port: @SERVER_PORT@
+	interface: 127.0.0.1
+	outbound-msg-retry: 0
+
+        log-servfail: yes
+
+forward-zone:
+	name: "a.servfail"
+	forward-addr: 127.0.0.1@@SERVER_PORT@
+
+forward-zone:
+	name: "b.servfail"
+	forward-addr: 127.0.0.1@@SERVER_PORT@
+
+remote-control:
+	control-enable: yes
+	control-port: @CONTROL_PORT@
+	control-use-cert: no
diff --git a/testdata/log_servfail.tdir/log_servfail.dsc b/testdata/log_servfail.tdir/log_servfail.dsc
@@ -0,0 +1,16 @@
+BaseName: log_servfail
+Version: 1.0
+Description: Check the log_servfail option
+CreationDate: Fri 29 Nov 11:00:00 CEST 2024
+Maintainer:
+Category:
+Component:
+CmdDepends:
+Depends:
+Help:
+Pre: log_servfail.pre
+Post: log_servfail.post
+Test: log_servfail.test
+AuxFiles:
+Passed:
+Failure:
diff --git a/testdata/log_servfail.tdir/log_servfail.post b/testdata/log_servfail.tdir/log_servfail.post
@@ -0,0 +1,10 @@
+# #-- log_servfail.post --#
+# source the master var file when it's there
+[ -f ../.tpkg.var.master ] && source ../.tpkg.var.master
+# source the test var file when it's there
+[ -f .tpkg.var.test ] && source .tpkg.var.test
+#
+# do your teardown here
+. ../common.sh
+kill_from_pidfile "unbound.pid"
+cat unbound.log
diff --git a/testdata/log_servfail.tdir/log_servfail.pre b/testdata/log_servfail.tdir/log_servfail.pre
@@ -0,0 +1,21 @@
+# #-- log_servfail.pre--#
+PRE="../.."
+. ../common.sh
+
+get_random_port 2
+SERVER_PORT=$RND_PORT
+CONTROL_PORT=$(($RND_PORT + 1))
+echo "SERVER_PORT=$SERVER_PORT" >> .tpkg.var.test
+echo "CONTROL_PORT=$CONTROL_PORT" >> .tpkg.var.test
+
+# make config file
+sed \
+	-e 's/@SERVER_PORT\@/'$SERVER_PORT'/' \
+	-e 's/@CONTROL_PORT\@/'$CONTROL_PORT'/' \
+	< log_servfail.conf > ub.conf
+
+# start unbound in the background
+$PRE/unbound -d -c ub.conf > unbound.log 2>&1 &
+
+cat .tpkg.var.test
+wait_unbound_up unbound.log
diff --git a/testdata/log_servfail.tdir/log_servfail.test b/testdata/log_servfail.tdir/log_servfail.test
@@ -0,0 +1,47 @@
+# #-- cookie_file.test --#
+# source the master var file when it's there
+[ -f ../.tpkg.var.master ] && source ../.tpkg.var.master
+# use .tpkg.var.test for in test variable passing
+[ -f .tpkg.var.test ] && source .tpkg.var.test
+PRE="../.."
+. ../common.sh
+
+outfile=dig.out
+
+teststep "Check if log-servfail logs to output for iterator error"
+dig a.servfail @127.0.0.1 -p $SERVER_PORT > $outfile
+if ! grep "SERVFAIL" $outfile
+then
+	cat $outfile
+	echo "Did not get a SERVFAIL response"
+	exit 1
+fi
+if ! grep "SERVFAIL <a\.servfail\. "  unbound.log
+then
+        echo "No log-servfail in output"
+        exit 1
+fi
+
+teststep "Enable serve expired"
+$PRE/unbound-control -c ub.conf set_option serve-expired: yes
+if test $? -ne 0
+then
+	echo "unbound-control command exited with non-zero error code"
+	exit 1
+fi
+
+teststep "Check if log-servfail logs to output for iterator error (with serve-expired)"
+dig b.servfail @127.0.0.1 -p $SERVER_PORT > $outfile
+if ! grep "SERVFAIL" $outfile
+then
+	cat $outfile
+	echo "Did not get a SERVFAIL response"
+	exit 1
+fi
+if ! grep "SERVFAIL <b\.servfail\. "  unbound.log
+then
+        echo "No log-servfail in output"
+        exit 1
+fi
+
+exit 0
diff --git a/testdata/rpz_val_block.rpl b/testdata/rpz_val_block.rpl
@@ -6,7 +6,6 @@ server:
 	trust-anchor: "org. DS 1444 8 2 5224fb17d630a2e3efdc863a05a4032c5db415b5de3f32472ee9abed42e10146"
 	val-override-date: "20070916134226"
 	trust-anchor-signaling: no
-	log-servfail: yes
 	val-log-level: 2
 	ede: yes
 
diff --git a/testdata/serve_expired_0ttl_nodata.rpl b/testdata/serve_expired_0ttl_nodata.rpl
@@ -5,7 +5,6 @@ server:
 	minimal-responses: no
 	serve-expired: yes
 	serve-expired-client-timeout: 0
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/serve_expired_0ttl_nxdomain.rpl b/testdata/serve_expired_0ttl_nxdomain.rpl
@@ -5,7 +5,6 @@ server:
 	minimal-responses: no
 	serve-expired: yes
 	serve-expired-client-timeout: 0
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/serve_expired_0ttl_servfail.rpl b/testdata/serve_expired_0ttl_servfail.rpl
@@ -5,7 +5,6 @@ server:
 	minimal-responses: no
 	serve-expired: yes
 	serve-expired-client-timeout: 0
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/serve_expired_cached_servfail.rpl b/testdata/serve_expired_cached_servfail.rpl
@@ -6,7 +6,6 @@ server:
 	serve-expired: yes
 	serve-expired-client-timeout: 0
 	serve-expired-reply-ttl: 123
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/serve_expired_cached_servfail_refresh.rpl b/testdata/serve_expired_cached_servfail_refresh.rpl
@@ -6,7 +6,6 @@ server:
 	serve-expired: yes
 	serve-expired-client-timeout: 0
 	serve-expired-reply-ttl: 123
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/serve_expired_client_timeout_servfail.rpl b/testdata/serve_expired_client_timeout_servfail.rpl
@@ -6,7 +6,6 @@ server:
 	serve-expired: yes
 	serve-expired-client-timeout: 1
 	serve-expired-reply-ttl: 123
-	log-servfail: yes
 	ede: yes
 	ede-serve-expired: yes
 
diff --git a/testdata/val_failure_dnskey.rpl b/testdata/val_failure_dnskey.rpl
@@ -9,7 +9,6 @@ server:
 	fake-sha1: yes
 	trust-anchor-signaling: no
 	minimal-responses: no
-	log-servfail: yes
 	val-log-level: 2
 	ede: yes
 
diff --git a/testdata/val_scrub_rr_length.rpl b/testdata/val_scrub_rr_length.rpl
@@ -9,7 +9,6 @@ server:
 	minimal-responses: no
 	rrset-roundrobin: no
 	ede: yes
-	log-servfail: yes
 
 stub-zone:
 	name: "."
