Log the rcode returned to for a query

Log to the querylog the rcode of a previous query using
the identifier 'response:' to diffenciate queries from
responses.

(cherry picked from commit 5fad79c92f)

bin/named/config.c

@@ -96,10 +96,12 @@ options {\n\
 #endif
 			    "\
 	prefetch 2 9;\n\
+#	querylog <boolean>;\n\
 	recursing-file \"named.recursing\";\n\
 	recursive-clients 1000;\n\
 	request-nsid false;\n\
 	resolver-query-timeout 10;\n\
+#	responselog <boolean>;\n\
 	rrset-order { order random; };\n\
 	secroots-file \"named.secroots\";\n\
 	send-cookie true;\n\

bin/named/control.c

@@ -251,6 +251,8 @@ named_control_docommand(isccc_sexpr_t *message, bool readonly,
 		result = named_server_refreshcommand(named_g_server, lex, text);
 	} else if (command_compare(command, NAMED_COMMAND_RELOAD)) {
 		result = named_server_reloadcommand(named_g_server, lex, text);
+	} else if (command_compare(command, NAMED_COMMAND_RESPONSELOG)) {
+		result = named_server_toggleresponselog(named_g_server, lex);
 	} else if (command_compare(command, NAMED_COMMAND_RETRANSFER)) {
 		result = named_server_retransfercommand(named_g_server, lex,
 							text);

bin/named/include/named/control.h

@@ -28,49 +28,50 @@
 
 #define NAMED_CONTROL_PORT 953
 
-#define NAMED_COMMAND_STOP	   "stop"
-#define NAMED_COMMAND_HALT	   "halt"
-#define NAMED_COMMAND_RELOAD	   "reload"
-#define NAMED_COMMAND_RECONFIG	   "reconfig"
-#define NAMED_COMMAND_REFRESH	   "refresh"
-#define NAMED_COMMAND_RETRANSFER   "retransfer"
-#define NAMED_COMMAND_DUMPSTATS	   "stats"
-#define NAMED_COMMAND_QUERYLOG	   "querylog"
+#define NAMED_COMMAND_ADDZONE	   "addzone"
+#define NAMED_COMMAND_DELZONE	   "delzone"
+#define NAMED_COMMAND_DNSSEC	   "dnssec"
+#define NAMED_COMMAND_DNSTAP	   "dnstap"
+#define NAMED_COMMAND_DNSTAPREOPEN "dnstap-reopen"
 #define NAMED_COMMAND_DUMPDB	   "dumpdb"
-#define NAMED_COMMAND_SECROOTS	   "secroots"
-#define NAMED_COMMAND_TRACE	   "trace"
-#define NAMED_COMMAND_NOTRACE	   "notrace"
+#define NAMED_COMMAND_DUMPSTATS	   "stats"
+#define NAMED_COMMAND_FETCHLIMIT   "fetchlimit"
 #define NAMED_COMMAND_FLUSH	   "flush"
 #define NAMED_COMMAND_FLUSHNAME	   "flushname"
 #define NAMED_COMMAND_FLUSHTREE	   "flushtree"
-#define NAMED_COMMAND_STATUS	   "status"
 #define NAMED_COMMAND_FREEZE	   "freeze"
-#define NAMED_COMMAND_UNFREEZE	   "unfreeze"
-#define NAMED_COMMAND_THAW	   "thaw"
-#define NAMED_COMMAND_RECURSING	   "recursing"
-#define NAMED_COMMAND_NULL	   "null"
-#define NAMED_COMMAND_NOTIFY	   "notify"
-#define NAMED_COMMAND_VALIDATION   "validation"
-#define NAMED_COMMAND_SCAN	   "scan"
-#define NAMED_COMMAND_SIGN	   "sign"
+#define NAMED_COMMAND_HALT	   "halt"
 #define NAMED_COMMAND_LOADKEYS	   "loadkeys"
-#define NAMED_COMMAND_ADDZONE	   "addzone"
-#define NAMED_COMMAND_MODZONE	   "modzone"
-#define NAMED_COMMAND_DELZONE	   "delzone"
-#define NAMED_COMMAND_SHOWZONE	   "showzone"
-#define NAMED_COMMAND_SKR	   "skr"
-#define NAMED_COMMAND_SYNC	   "sync"
-#define NAMED_COMMAND_SIGNING	   "signing"
-#define NAMED_COMMAND_DNSSEC	   "dnssec"
-#define NAMED_COMMAND_ZONESTATUS   "zonestatus"
-#define NAMED_COMMAND_NTA	   "nta"
-#define NAMED_COMMAND_TESTGEN	   "testgen"
 #define NAMED_COMMAND_MKEYS	   "managed-keys"
-#define NAMED_COMMAND_DNSTAPREOPEN "dnstap-reopen"
-#define NAMED_COMMAND_DNSTAP	   "dnstap"
-#define NAMED_COMMAND_TCPTIMEOUTS  "tcp-timeouts"
+#define NAMED_COMMAND_MODZONE	   "modzone"
+#define NAMED_COMMAND_NOTIFY	   "notify"
+#define NAMED_COMMAND_NOTRACE	   "notrace"
+#define NAMED_COMMAND_NTA	   "nta"
+#define NAMED_COMMAND_NULL	   "null"
+#define NAMED_COMMAND_QUERYLOG	   "querylog"
+#define NAMED_COMMAND_RECONFIG	   "reconfig"
+#define NAMED_COMMAND_RECURSING	   "recursing"
+#define NAMED_COMMAND_REFRESH	   "refresh"
+#define NAMED_COMMAND_RELOAD	   "reload"
+#define NAMED_COMMAND_RESPONSELOG  "responselog"
+#define NAMED_COMMAND_RETRANSFER   "retransfer"
+#define NAMED_COMMAND_SCAN	   "scan"
+#define NAMED_COMMAND_SECROOTS	   "secroots"
 #define NAMED_COMMAND_SERVESTALE   "serve-stale"
-#define NAMED_COMMAND_FETCHLIMIT   "fetchlimit"
+#define NAMED_COMMAND_SHOWZONE	   "showzone"
+#define NAMED_COMMAND_SIGN	   "sign"
+#define NAMED_COMMAND_SIGNING	   "signing"
+#define NAMED_COMMAND_SKR	   "skr"
+#define NAMED_COMMAND_STATUS	   "status"
+#define NAMED_COMMAND_STOP	   "stop"
+#define NAMED_COMMAND_SYNC	   "sync"
+#define NAMED_COMMAND_TCPTIMEOUTS  "tcp-timeouts"
+#define NAMED_COMMAND_TESTGEN	   "testgen"
+#define NAMED_COMMAND_THAW	   "thaw"
+#define NAMED_COMMAND_TRACE	   "trace"
+#define NAMED_COMMAND_UNFREEZE	   "unfreeze"
+#define NAMED_COMMAND_VALIDATION   "validation"
+#define NAMED_COMMAND_ZONESTATUS   "zonestatus"
 
 isc_result_t
 named_controls_create(named_server_t *server, named_controls_t **ctrlsp);

bin/named/include/named/server.h

@@ -190,6 +190,13 @@ named_server_togglequerylog(named_server_t *server, isc_lex_t *lex);
  * but can also be used as a toggle for backward comptibility.)
  */
 
+isc_result_t
+named_server_toggleresponselog(named_server_t *server, isc_lex_t *lex);
+/*%<
+ * Enable/disable logging of responses.  (Takes "yes" or "no" argument,
+ * but can also be used as a toggle for backward comptibility.)
+ */
+
 /*%
  * Save the current NTAs for all views to files.
  */

bin/named/server.c

@@ -9572,6 +9572,13 @@ load_configuration(const char *filename, named_server_t *server,
 				}
 			}
 		}
+		obj = NULL;
+		result = named_config_get(maps, "responselog", &obj);
+		if (result == ISC_R_SUCCESS) {
+			ns_server_setoption(server->sctx,
+					    NS_SERVER_LOGRESPONSES,
+					    cfg_obj_asboolean(obj));
+		}
 	}
 
 	obj = NULL;
@@ -11137,7 +11144,7 @@ named_server_refreshcommand(named_server_t *server, isc_lex_t *lex,
 isc_result_t
 named_server_togglequerylog(named_server_t *server, isc_lex_t *lex) {
 	bool prev, value;
-	char *ptr;
+	char *ptr = NULL;
 
 	/* Skip the command name. */
 	ptr = next_token(lex, NULL);
@@ -11174,6 +11181,46 @@ named_server_togglequerylog(named_server_t *server, isc_lex_t *lex) {
 	return (ISC_R_SUCCESS);
 }
 
+isc_result_t
+named_server_toggleresponselog(named_server_t *server, isc_lex_t *lex) {
+	bool prev, value;
+	char *ptr = NULL;
+
+	/* Skip the command name. */
+	ptr = next_token(lex, NULL);
+	if (ptr == NULL) {
+		return (ISC_R_UNEXPECTEDEND);
+	}
+
+	prev = ns_server_getoption(server->sctx, NS_SERVER_LOGRESPONSES);
+
+	ptr = next_token(lex, NULL);
+	if (ptr == NULL) {
+		value = !prev;
+	} else if (!strcasecmp(ptr, "on") || !strcasecmp(ptr, "yes") ||
+		   !strcasecmp(ptr, "enable") || !strcasecmp(ptr, "true"))
+	{
+		value = true;
+	} else if (!strcasecmp(ptr, "off") || !strcasecmp(ptr, "no") ||
+		   !strcasecmp(ptr, "disable") || !strcasecmp(ptr, "false"))
+	{
+		value = false;
+	} else {
+		return (DNS_R_SYNTAX);
+	}
+
+	if (value == prev) {
+		return (ISC_R_SUCCESS);
+	}
+
+	ns_server_setoption(server->sctx, NS_SERVER_LOGRESPONSES, value);
+
+	isc_log_write(named_g_lctx, NAMED_LOGCATEGORY_GENERAL,
+		      NAMED_LOGMODULE_SERVER, ISC_LOG_INFO,
+		      "response logging is now %s", value ? "on" : "off");
+	return (ISC_R_SUCCESS);
+}
+
 static isc_result_t
 listenlist_fromconfig(const cfg_obj_t *listenlist, const cfg_obj_t *config,
 		      cfg_aclconfctx_t *actx, isc_mem_t *mctx, uint16_t family,
@@ -12564,6 +12611,12 @@ named_server_status(named_server_t *server, isc_buffer_t **text) {
 			 : "OFF");
 	CHECK(putstr(text, line));
 
+	snprintf(line, sizeof(line), "response logging is %s\n",
+		 ns_server_getoption(server->sctx, NS_SERVER_LOGRESPONSES)
+			 ? "ON"
+			 : "OFF");
+	CHECK(putstr(text, line));
+
 	snprintf(line, sizeof(line), "recursive clients: %u/%u/%u\n",
 		 isc_quota_getused(&server->sctx->recursionquota),
 		 isc_quota_getsoft(&server->sctx->recursionquota),

bin/rndc/rndc.rst

@@ -449,6 +449,17 @@ Currently supported commands are:
 
 .. program:: rndc
 
+.. option:: responselog [on | off]
+
+   This command enables or disables response logging. For backward compatibility,
+   this command can also be used without an argument to toggle response logging
+   on and off.
+
+   Unlike query logging, response logging cannot be enabled by explicitly directing
+   the ``responses`` ``category`` to a ``channel`` in the ``logging`` section
+   of :iscman:`named.conf`, but it can still be enabled by specifying
+   ``responselog yes;`` in the ``options`` section of :iscman:`named.conf`.
+
 .. option:: retransfer [-force] zone [class [view]]
 
    This command retransfers the given secondary zone from the primary server.

doc/arm/logging-categories.inc.rst

@@ -56,7 +56,7 @@
     NSID options received from upstream servers.
 
 ``queries``
-    A location where queries should be logged.
+    The locations where queries should be logged.
 
     At startup, specifying the category ``queries`` also enables query logging unless the :any:`querylog` option has been specified.
 
@@ -80,6 +80,9 @@
 ``resolver``
     DNS resolution, such as the recursive lookups performed on behalf of clients by a caching name server.
 
+``responses``
+    The locations where query response summaries should be logged.
+
 ``rpz``
     Information about errors in response policy zone files, rewritten responses, and, at the highest ``debug`` levels, mere rewriting attempts.
 

doc/misc/options

@@ -263,6 +263,7 @@ options {
 	resolver-use-dns64 <boolean>;
 	response-padding { <address_match_element>; ... } block-size <integer>;
 	response-policy { zone <string> [ add-soa <boolean> ] [ log <boolean> ] [ max-policy-ttl <duration> ] [ min-update-interval <duration> ] [ policy ( cname | disabled | drop | given | no-op | nodata | nxdomain | passthru | tcp-only <quoted_string> ) ] [ recursive-only <boolean> ] [ nsip-enable <boolean> ] [ nsdname-enable <boolean> ] [ ede <string> ]; ... } [ add-soa <boolean> ] [ break-dnssec <boolean> ] [ max-policy-ttl <duration> ] [ min-update-interval <duration> ] [ min-ns-dots <integer> ] [ nsip-wait-recurse <boolean> ] [ nsdname-wait-recurse <boolean> ] [ qname-wait-recurse <boolean> ] [ recursive-only <boolean> ] [ nsip-enable <boolean> ] [ nsdname-enable <boolean> ] [ dnsrps-enable <boolean> ] [ dnsrps-options { <unspecified-text> } ];
+	responselog <boolean>;
 	reuseport <boolean>;
 	root-key-sentinel <boolean>;
 	rrset-order { [ class <string> ] [ type <string> ] [ name <quoted_string> ] <string> <string>; ... };

lib/isccfg/namedconf.c

@@ -1420,6 +1420,7 @@ static cfg_clausedef_t options_clauses[] = {
 	{ "recursive-clients", &cfg_type_uint32, 0 },
 	{ "reuseport", &cfg_type_boolean, 0 },
 	{ "reserved-sockets", &cfg_type_uint32, CFG_CLAUSEFLAG_ANCIENT },
+	{ "responselog", &cfg_type_boolean, 0 },
 	{ "secroots-file", &cfg_type_qstring, 0 },
 	{ "serial-queries", NULL, CFG_CLAUSEFLAG_ANCIENT },
 	{ "serial-query-rate", &cfg_type_uint32, 0 },

lib/ns/include/ns/log.h

@@ -30,6 +30,7 @@ extern isc_logmodule_t	 ns_modules[];
 #define NS_LOGCATEGORY_QUERY_ERRORS    (&ns_categories[5])
 #define NS_LOGCATEGORY_TAT	       (&ns_categories[6])
 #define NS_LOGCATEGORY_SERVE_STALE     (&ns_categories[7])
+#define NS_LOGCATEGORY_RESPONSES       (&ns_categories[8])
 
 /*
  * Backwards compatibility.

lib/ns/include/ns/server.h

@@ -49,6 +49,7 @@
 #define NS_SERVER_TRANSFERINSECS 0x00008000U /*%< -T transferinsecs */
 #define NS_SERVER_TRANSFERSLOWLY 0x00010000U /*%< -T transferslowly */
 #define NS_SERVER_TRANSFERSTUCK	 0x00020000U /*%< -T transferstuck */
+#define NS_SERVER_LOGRESPONSES	 0x00040000U /*%< log responses */
 
 /*%
  * Type for callback function to get hostname.

lib/ns/log.c

@@ -34,6 +34,7 @@ isc_logcategory_t ns_categories[] = { { "client", 0 },
 				      { "query-errors", 0 },
 				      { "trust-anchor-telemetry", 0 },
 				      { "serve-stale", 0 },
+				      { "responses", 0 },
 				      { NULL, 0 } };
 
 /*%

lib/ns/query.c

@@ -48,6 +48,7 @@
 #include <dns/nsec3.h>
 #include <dns/order.h>
 #include <dns/rbt.h>
+#include <dns/rcode.h>
 #include <dns/rdata.h>
 #include <dns/rdataclass.h>
 #include <dns/rdatalist.h>
@@ -547,6 +548,30 @@ inc_stats(ns_client_t *client, isc_statscounter_t counter) {
 	}
 }
 
+static inline void
+log_response(ns_client_t *client, dns_rcode_t rcode) {
+	char namebuf[DNS_NAME_FORMATSIZE];
+	char typebuf[DNS_RDATATYPE_FORMATSIZE];
+	char classbuf[DNS_RDATACLASS_FORMATSIZE];
+	char rcodebuf[20];
+	isc_buffer_t b;
+	int level = ISC_LOG_INFO;
+
+	if (!isc_log_wouldlog(ns_lctx, level))
+		return;
+
+	dns_name_format(client->query.origqname, namebuf, sizeof(namebuf));
+	dns_rdataclass_format(client->message->rdclass, classbuf,
+			      sizeof(classbuf));
+	dns_rdatatype_format(client->query.qtype, typebuf, sizeof(typebuf));
+	isc_buffer_init(&b, rcodebuf, sizeof(rcodebuf));
+	dns_rcode_totext(rcode, &b);
+
+	ns_client_log(client, NS_LOGCATEGORY_QUERIES, NS_LOGMODULE_QUERY, level,
+		      "response: %s %s %s %.*s", namebuf, classbuf, typebuf,
+		      (int)isc_buffer_usedlength(&b), rcodebuf);
+}
+
 static void
 query_send(ns_client_t *client) {
 	isc_statscounter_t counter;
@@ -576,6 +601,10 @@ query_send(ns_client_t *client) {
 		counter = ns_statscounter_failure;
 	}
 
+	if ((client->manager->sctx->options & NS_SERVER_LOGRESPONSES) != 0) {
+		log_response(client, client->message->rcode);
+	}
+
 	inc_stats(client, counter);
 	ns_client_send(client);
 
@@ -587,8 +616,10 @@ query_send(ns_client_t *client) {
 static void
 query_error(ns_client_t *client, isc_result_t result, int line) {
 	int loglevel = ISC_LOG_DEBUG(3);
+	dns_rcode_t rcode;
 
-	switch (dns_result_torcode(result)) {
+	rcode = dns_result_torcode(result);
+	switch (rcode) {
 	case dns_rcode_servfail:
 		loglevel = ISC_LOG_DEBUG(1);
 		inc_stats(client, ns_statscounter_servfail);
@@ -607,6 +638,12 @@ query_error(ns_client_t *client, isc_result_t result, int line) {
 
 	log_queryerror(client, result, line, loglevel);
 
+	if (client->query.origqname != NULL &&
+	    (client->manager->sctx->options & NS_SERVER_LOGRESPONSES) != 0)
+	{
+		log_response(client, rcode);
+	}
+
 	ns_client_error(client, result);
 
 	if (!client->nodetach) {

util/check-categories.sh

@@ -33,7 +33,7 @@ for i in $list1; do
     fi
   done
   if test $ok = no; then
-    echo "$i missing from documentation."
+    echo "$i missing from doc/arm/logging-categories.rst."
     status=1
   fi
 done
@@ -45,7 +45,7 @@ for i in $list2; do
     fi
   done
   if test $ok = no; then
-    echo "$i not in code."
+    echo "documented logging category '$i' not in code."
     status=1
   fi
 done