Add a --enable-querytrace configure switch for very verbose query tracelogging (#37520)

(cherry picked from commit 1783676a64)
(cherry picked from commit b83c20df65)

Conflicts:
	CHANGES
	config.h.in
	configure
	configure.in

CHANGES

@@ -1,3 +1,6 @@
+4072.	[func]		Add a --enable-querytrace configure switch for
+			very verbose query tracelogging. [RT #37520]
+
 4070.	[bug]		Fix a segfault in nslookup in a query such as
 			"nslookup isc.org AMS.SNS-PB.ISC.ORG -all".
 			[RT #38548]

bin/named/query.c

@@ -117,24 +117,30 @@
 #define NOQNAME(r)		(((r)->attributes & \
 				  DNS_RDATASETATTR_NOQNAME) != 0)
 
-#if 0
-#define CTRACE(l,m)	  do { \
-	if (client != NULL && client->query.qname != NULL) { \
-		char qbuf[DNS_NAME_FORMATSIZE]; \
-		dns_name_format(client->query.qname, qbuf, sizeof(qbuf)); \
-		isc_log_write(ns_g_lctx, \
-			      NS_LOGCATEGORY_CLIENT, NS_LOGMODULE_QUERY, \
-			      l, "client %p (%s): %s", client, qbuf, (m)); \
-	} else { \
-		isc_log_write(ns_g_lctx, \
-			      NS_LOGCATEGORY_CLIENT, NS_LOGMODULE_QUERY, \
-			      l, "client %p (<unknown-name>): %s", \
-			      client, (m)); \
-	} \
+#ifdef WANT_QUERYTRACE
+#define CTRACE(l,m)	  do {						\
+	if (client != NULL && client->query.qname != NULL) {		\
+		if (isc_log_wouldlog(ns_g_lctx, l)) {			\
+			char qbuf[DNS_NAME_FORMATSIZE];			\
+			dns_name_format(client->query.qname,		\
+					qbuf, sizeof(qbuf));		\
+			isc_log_write(ns_g_lctx,			\
+				      NS_LOGCATEGORY_CLIENT,		\
+				      NS_LOGMODULE_QUERY,		\
+				      l, "client %p (%s): %s",		\
+				      client, qbuf, (m));		\
+		}							\
+	 } else {							\
+		isc_log_write(ns_g_lctx,				\
+			      NS_LOGCATEGORY_CLIENT,			\
+			      NS_LOGMODULE_QUERY,			\
+			      l, "client %p (<unknown-name>): %s",	\
+			      client, (m));				\
+	}								\
 } while(0)
 #else
 #define CTRACE(l,m) ((void)m)
-#endif
+#endif /* WANT_QUERYTRACE */
 
 
 #define DNS_GETDB_NOEXACT 0x01U

config.h.in

@@ -470,6 +470,9 @@ int sigwait(const unsigned int *set, int *sig);
 /* Enable DNS Response Rate Limiting */
 #undef USE_RRL
 
+/* Define to enable very verbose query trace logging. */
+#undef WANT_QUERYTRACE
+
 /* define if idnkit support is to be included. */
 #undef WITH_IDN
 

configure

@@ -1006,6 +1006,7 @@ with_libiconv
 with_iconv
 with_idnlib
 with_atf
+enable_querytrace
 with_dlopen
 with_dlz_postgres
 with_dlz_mysql
@@ -1679,6 +1680,7 @@ Optional Features:
   --disable-rpz-nsdname	  disable rpz-nsdname rules [default=enabled]
   --enable-filter-aaaa    enable filtering of AAAA records over IPv4
 			  [default=no]
+  --enable-querytrace     enable very verbose query trace logging [default=no]
   --enable-full-report	  report values of all configure options
 
 Optional Packages:
@@ -19453,6 +19455,34 @@ fi
 done
 
 
+#
+# was --enable-querytrace specified?
+#
+# Check whether --enable-querytrace was given.
+if test "${enable_querytrace+set}" = set; then :
+  enableval=$enable_querytrace; want_querytrace="$enableval"
+else
+  want_querytrace="no"
+fi
+
+
+case "$want_querytrace" in
+yes)
+	{ $as_echo "$as_me:${as_lineno-$LINENO}: result: yes" >&5
+$as_echo "yes" >&6; }
+
+$as_echo "#define WANT_QUERYTRACE 1" >>confdefs.h
+
+	;;
+no)
+	{ $as_echo "$as_me:${as_lineno-$LINENO}: result: no" >&5
+$as_echo "no" >&6; }
+	;;
+*)
+	as_fn_error $? "\"--enable-querytrace requires yes or no\"" "$LINENO" 5
+	;;
+esac
+
 #
 # Substitutions
 #
@@ -23139,6 +23169,8 @@ test "$want_symtable" = "minimal" && \
     echo "    Use symbol table for backtrace, named only (--enable-symtable)"
 test "$want_symtable" = "yes" -o "$want_symtable" = "all" && \
     echo "    Use symbol table for backtrace, all binaries (--enable-symtable=all)"
+test "$want_querytrace" = "yes" && \
+    echo "    Very verbose query trace logging (--enable-querytrace)"
 test "$atf" = "no" || echo "    Automated Testing Framework (--with-atf)"
 
 # these lines are only printed if run with --enable-full-report
@@ -23186,6 +23218,8 @@ test "$enable_fixed" = "yes" || \
     echo "    Allow 'fixed' rrset-order (--enable-fixed-rrset)"
 test "$want_backtrace" = "yes" || \
     echo "    Print backtrace on crash (--enable-backtrace)"
+test "$want_querytrace" = "yes" || \
+    echo "    Very verbose query trace logging (--enable-querytrace)"
 test "$atf" = "no" && echo "    Automated Testing Framework (--with-atf)"
 test "X$USE_OPENSSL" = "X" && \
 	echo "    OpenSSL cryptography/DNSSEC (--with-openssl)"

configure.in

@@ -3517,6 +3517,26 @@ AC_SUBST(UNITTESTS)
 AC_CHECK_HEADERS(locale.h)
 AC_CHECK_FUNCS(setlocale)
 
+#
+# was --enable-querytrace specified?
+#
+AC_ARG_ENABLE(querytrace,
+	[  --enable-querytrace     enable very verbose query trace logging [[default=no]]],
+	want_querytrace="$enableval", want_querytrace="no")
+
+case "$want_querytrace" in
+yes)
+	AC_MSG_RESULT(yes)
+	AC_DEFINE(WANT_QUERYTRACE, 1, [Define to enable very verbose query trace logging.])
+	;;
+no)
+	AC_MSG_RESULT(no)
+	;;
+*)
+	AC_MSG_ERROR("--enable-querytrace requires yes or no")
+	;;
+esac
+
 #
 # Substitutions
 #
@@ -4068,6 +4088,8 @@ test "$want_symtable" = "minimal" && \
     echo "    Use symbol table for backtrace, named only (--enable-symtable)"
 test "$want_symtable" = "yes" -o "$want_symtable" = "all" && \
     echo "    Use symbol table for backtrace, all binaries (--enable-symtable=all)"
+test "$want_querytrace" = "yes" && \
+    echo "    Very verbose query trace logging (--enable-querytrace)"
 test "$atf" = "no" || echo "    Automated Testing Framework (--with-atf)"
 
 # these lines are only printed if run with --enable-full-report 
@@ -4115,6 +4137,8 @@ test "$enable_fixed" = "yes" || \
     echo "    Allow 'fixed' rrset-order (--enable-fixed-rrset)"
 test "$want_backtrace" = "yes" || \
     echo "    Print backtrace on crash (--enable-backtrace)"
+test "$want_querytrace" = "yes" || \
+    echo "    Very verbose query trace logging (--enable-querytrace)"
 test "$atf" = "no" && echo "    Automated Testing Framework (--with-atf)"
 test "X$USE_OPENSSL" = "X" && \
 	echo "    OpenSSL cryptography/DNSSEC (--with-openssl)"

lib/dns/resolver.c

@@ -64,8 +64,7 @@
 #include <dns/tsig.h>
 #include <dns/validator.h>
 
-#define DNS_RESOLVER_TRACE
-#ifdef DNS_RESOLVER_TRACE
+#ifdef WANT_QUERYTRACE
 #define RTRACE(m)       isc_log_write(dns_lctx, \
 				      DNS_LOGCATEGORY_RESOLVER, \
 				      DNS_LOGMODULE_RESOLVER, \
@@ -121,13 +120,16 @@
 				      query, query->fctx, \
 				      query->fctx->info, (m))
 #else
-#define RTRACE(m)
-#define RRTRACE(r, m)
-#define FCTXTRACE(m)
-#define FCTXTRACE2(m1, m2)
-#define FTRACE(m)
-#define QTRACE(m)
-#endif
+#define RTRACE(m) do { UNUSED(m); } while (0)
+#define RRTRACE(r, m) do { UNUSED(r); UNUSED(m); } while (0)
+#define FCTXTRACE(m) do { UNUSED(m); } while (0)
+#define FCTXTRACE2(m1, m2) do { UNUSED(m1); UNUSED(m2); } while (0)
+#define FCTXTRACE3(m1, res) do { UNUSED(m1); UNUSED(res); } while (0)
+#define FCTXTRACE4(m1, m2, res) \
+	do { UNUSED(m1); UNUSED(m2); UNUSED(res); } while (0)
+#define FTRACE(m) do { UNUSED(m); } while (0)
+#define QTRACE(m) do { UNUSED(m); } while (0)
+#endif /* WANT_QUERYTRACE */
 
 #define US_PER_SEC 1000000U
 /*
@@ -2947,6 +2949,9 @@ possibly_mark(fetchctx_t *fctx, dns_adbaddrinfo_t *addr)
 	    bogus)
 		aborted = ISC_TRUE;
 
+	if (!isc_log_wouldlog(dns_lctx, ISC_LOG_DEBUG(3)))
+		return;
+
 	if (aborted) {
 		addr->flags |= FCTX_ADDRINFO_MARK;
 		msg = "ignoring blackholed / bogus server: ";
@@ -2967,9 +2972,6 @@ possibly_mark(fetchctx_t *fctx, dns_adbaddrinfo_t *addr)
 	} else
 		return;
 
-	if (!isc_log_wouldlog(dns_lctx, ISC_LOG_DEBUG(3)))
-		return;
-
 	isc_netaddr_fromsockaddr(&na, sa);
 	isc_netaddr_format(&na, buf, sizeof(buf));
 	FCTXTRACE2(msg, buf);