- Fix #369: dnstap showing extra responses; for client responses

right from the cache when replying with expired data or
  prefetching.

daemon/worker.c

@@ -1943,7 +1943,7 @@ send_reply_rc:
 	/*
 	 * sending src (client)/dst (local service) addresses over DNSTAP from send_reply code label (when we serviced local zone for ex.)
 	 */
-	if(worker->dtenv.log_client_response_messages) {
+	if(worker->dtenv.log_client_response_messages && rc !=0) {
 		log_addr(VERB_ALGO, "from local addr", (void*)repinfo->c->socket->addr, repinfo->c->socket->addrlen);
 		log_addr(VERB_ALGO, "response to client", &repinfo->client_addr, repinfo->client_addrlen);
 		dt_msg_send_client_response(&worker->dtenv, &repinfo->client_addr, (void*)repinfo->c->socket->addr, c->type, c->ssl, c->buffer);

doc/Changelog

@@ -8,6 +8,9 @@
 	- Fix #1035: Potential Bug while parsing port from the "stub-host"
 	  string; also affected forward-zones and remote-control host
 	  directives.
+	- Fix #369: dnstap showing extra responses; for client responses
+	  right from the cache when replying with expired data or
+	  prefetching.
 
 28 March 2024: Wouter
 	- Fix #1034: DoT forward-zone via unbound-control.

testdata/dnstap.tdir/dnstap.conf

@@ -12,6 +12,8 @@ server:
 	do-not-query-localhost: no
 	local-zone: "example.net." redirect
 	local-data: "example.net. IN A 10.20.30.41"
+        serve-expired: yes
+        serve-expired-reply-ttl: 30
 remote-control:
 	control-enable: yes
 	control-interface: 127.0.0.1

testdata/dnstap.tdir/dnstap.test

@@ -81,6 +81,46 @@ for x in q1 q2 q3 q4 5 q6 q7 q8 q9 q10; do
 	fi
 done
 
+echo "> query for a short ttl record"
+dig @127.0.0.1 -p $UNBOUND_PORT short.example.com.
+echo "> wait for log to happen on timer"
+sleep 3
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 1; fi
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 1; fi
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 1; fi
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 1; fi
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 1; fi
+if grep "short.example.com" tap.log >/dev/null; then :; else sleep 10; fi
+if grep "short.example.com" tap.log; then echo "yes it is in tap.log";
+else
+        echo "short.example.com. information not in tap.log"
+        echo "failed"
+        echo "> cat logfiles"
+        cat tap.log
+        cat tap.errlog
+        cat fwd.log
+        cat unbound.log
+        echo "Not OK"
+        exit 1
+fi
+echo "> query again for the now expired record"
+dig @127.0.0.1 -p $UNBOUND_PORT short.example.com.
+echo "> wait for log to happen on timer"
+sleep 3
+num_responses=`grep "short.example.com" tap.log | grep CLIENT_RESPONSE | wc -l`
+# Responses should be 2 for the 2 distinct dig commands.
+if test $num_responses -gt 2; then
+        echo "Duplicate client responses for short.example.com. in tap.log"
+        echo "failed"
+        echo "> cat logfiles"
+        cat tap.log
+        cat tap.errlog
+        cat fwd.log
+        cat unbound.log
+        echo "Not OK"
+        exit 1
+fi
+
 echo "> cat logfiles"
 cat tap.log
 cat tap.errlog

testdata/dnstap.tdir/dnstap.testns

@@ -12,6 +12,16 @@ SECTION ANSWER
 www	IN	A	10.20.30.40
 ENTRY_END
 
+ENTRY_BEGIN
+MATCH opcode qtype qname
+REPLY QR AA NOERROR
+ADJUST copy_id
+SECTION QUESTION
+short	IN	A
+SECTION ANSWER
+short	2 IN	A	10.20.30.40
+ENTRY_END
+
 ENTRY_BEGIN
 MATCH opcode qtype qname
 REPLY QR AA SERVFAIL