diff --git a/CHANGES b/CHANGES
index 47f40b53ee..6e122d2d1d 100644
--- a/CHANGES
+++ b/CHANGES
@@ -1,3 +1,7 @@
+3937.	[func]		Added some debug logging to better indicate the
+			conditions causing SERVFAILs when resolving.
+			[RT #35538]
+
 3936.	[func]		Added authoritative support for the EDNS Client
 			Subnet (ECS) option.
 
diff --git a/bin/named/query.c b/bin/named/query.c
index a79a930fd3..7239ce8bca 100644
--- a/bin/named/query.c
+++ b/bin/named/query.c
@@ -125,21 +125,25 @@
 				  DNS_RDATASETATTR_NOQNAME) != 0)
 
 #if 0
-#define CTRACE(m)       isc_log_write(ns_g_lctx, \
-				      NS_LOGCATEGORY_CLIENT, \
-				      NS_LOGMODULE_QUERY, \
-				      ISC_LOG_DEBUG(3), \
-				      "client %p: %s", client, (m))
-#define QTRACE(m)       isc_log_write(ns_g_lctx, \
-				      NS_LOGCATEGORY_GENERAL, \
-				      NS_LOGMODULE_QUERY, \
-				      ISC_LOG_DEBUG(3), \
-				      "query %p: %s", query, (m))
+#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)); \
+	} \
+} while(0)
 #else
-#define CTRACE(m) ((void)m)
-#define QTRACE(m) ((void)m)
+#define CTRACE(l,m) ((void)m)
 #endif
 
+
 #define DNS_GETDB_NOEXACT 0x01U
 #define DNS_GETDB_NOLOG 0x02U
 #define DNS_GETDB_PARTIAL 0x04U
@@ -312,13 +316,13 @@ static inline void
 query_putrdataset(ns_client_t *client, dns_rdataset_t **rdatasetp) {
 	dns_rdataset_t *rdataset = *rdatasetp;
 
-	CTRACE("query_putrdataset");
+	CTRACE(ISC_LOG_DEBUG(3), "query_putrdataset");
 	if (rdataset != NULL) {
 		if (dns_rdataset_isassociated(rdataset))
 			dns_rdataset_disassociate(rdataset);
 		dns_message_puttemprdataset(client->message, rdatasetp);
 	}
-	CTRACE("query_putrdataset: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_putrdataset: done");
 }
 
 static inline void
@@ -425,7 +429,7 @@ query_newnamebuf(ns_client_t *client) {
 	isc_buffer_t *dbuf;
 	isc_result_t result;
 
-	CTRACE("query_newnamebuf");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newnamebuf");
 	/*%
 	 * Allocate a name buffer.
 	 */
@@ -433,12 +437,13 @@ query_newnamebuf(ns_client_t *client) {
 	dbuf = NULL;
 	result = isc_buffer_allocate(client->mctx, &dbuf, 1024);
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_newnamebuf: isc_buffer_allocate failed: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_newnamebuf: isc_buffer_allocate failed: done");
 		return (result);
 	}
 	ISC_LIST_APPEND(client->query.namebufs, dbuf, link);
 
-	CTRACE("query_newnamebuf: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newnamebuf: done");
 	return (ISC_R_SUCCESS);
 }
 
@@ -448,7 +453,7 @@ query_getnamebuf(ns_client_t *client) {
 	isc_result_t result;
 	isc_region_t r;
 
-	CTRACE("query_getnamebuf");
+	CTRACE(ISC_LOG_DEBUG(3), "query_getnamebuf");
 	/*%
 	 * Return a name buffer with space for a maximal name, allocating
 	 * a new one if necessary.
@@ -457,7 +462,8 @@ query_getnamebuf(ns_client_t *client) {
 	if (ISC_LIST_EMPTY(client->query.namebufs)) {
 		result = query_newnamebuf(client);
 		if (result != ISC_R_SUCCESS) {
-		    CTRACE("query_getnamebuf: query_newnamebuf failed: done");
+		    CTRACE(ISC_LOG_DEBUG(3),
+			   "query_getnamebuf: query_newnamebuf failed: done");
 			return (NULL);
 		}
 	}
@@ -468,7 +474,8 @@ query_getnamebuf(ns_client_t *client) {
 	if (r.length < 255) {
 		result = query_newnamebuf(client);
 		if (result != ISC_R_SUCCESS) {
-		    CTRACE("query_getnamebuf: query_newnamebuf failed: done");
+		    CTRACE(ISC_LOG_DEBUG(3),
+			   "query_getnamebuf: query_newnamebuf failed: done");
 			return (NULL);
 
 		}
@@ -476,7 +483,7 @@ query_getnamebuf(ns_client_t *client) {
 		isc_buffer_availableregion(dbuf, &r);
 		INSIST(r.length >= 255);
 	}
-	CTRACE("query_getnamebuf: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_getnamebuf: done");
 	return (dbuf);
 }
 
@@ -484,7 +491,7 @@ static inline void
 query_keepname(ns_client_t *client, dns_name_t *name, isc_buffer_t *dbuf) {
 	isc_region_t r;
 
-	CTRACE("query_keepname");
+	CTRACE(ISC_LOG_DEBUG(3), "query_keepname");
 	/*%
 	 * 'name' is using space in 'dbuf', but 'dbuf' has not yet been
 	 * adjusted to take account of that.  We do the adjustment.
@@ -508,14 +515,14 @@ query_releasename(ns_client_t *client, dns_name_t **namep) {
 	 * rights on the buffer.
 	 */
 
-	CTRACE("query_releasename");
+	CTRACE(ISC_LOG_DEBUG(3), "query_releasename");
 	if (dns_name_hasbuffer(name)) {
 		INSIST((client->query.attributes & NS_QUERYATTR_NAMEBUFUSED)
 		       != 0);
 		client->query.attributes &= ~NS_QUERYATTR_NAMEBUFUSED;
 	}
 	dns_message_puttempname(client->message, namep);
-	CTRACE("query_releasename: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_releasename: done");
 }
 
 static inline dns_name_t *
@@ -528,11 +535,12 @@ query_newname(ns_client_t *client, isc_buffer_t *dbuf,
 
 	REQUIRE((client->query.attributes & NS_QUERYATTR_NAMEBUFUSED) == 0);
 
-	CTRACE("query_newname");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newname");
 	name = NULL;
 	result = dns_message_gettempname(client->message, &name);
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_newname: dns_message_gettempname failed: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_newname: dns_message_gettempname failed: done");
 		return (NULL);
 	}
 	isc_buffer_availableregion(dbuf, &r);
@@ -541,7 +549,7 @@ query_newname(ns_client_t *client, isc_buffer_t *dbuf,
 	dns_name_setbuffer(name, nbuf);
 	client->query.attributes |= NS_QUERYATTR_NAMEBUFUSED;
 
-	CTRACE("query_newname: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newname: done");
 	return (name);
 }
 
@@ -550,17 +558,18 @@ query_newrdataset(ns_client_t *client) {
 	dns_rdataset_t *rdataset;
 	isc_result_t result;
 
-	CTRACE("query_newrdataset");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newrdataset");
 	rdataset = NULL;
 	result = dns_message_gettemprdataset(client->message, &rdataset);
 	if (result != ISC_R_SUCCESS) {
-	  CTRACE("query_newrdataset: "
+	  CTRACE(ISC_LOG_DEBUG(3),
+		 "query_newrdataset: "
 		 "dns_message_gettemprdataset failed: done");
 		return (NULL);
 	}
 	dns_rdataset_init(rdataset);
 
-	CTRACE("query_newrdataset: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_newrdataset: done");
 	return (rdataset);
 }
 
@@ -727,8 +736,10 @@ query_validatezonedb(ns_client_t *client, dns_name_t *name,
 	 * Get the current version of this database.
 	 */
 	dbversion = query_findversion(client, db);
-	if (dbversion == NULL)
+	if (dbversion == NULL) {
+		CTRACE(ISC_LOG_ERROR, "unable to get db version");
 		return (DNS_R_SERVFAIL);
+	}
 
 	if ((options & DNS_GETDB_IGNOREACL) != 0)
 		goto approved;
@@ -1191,7 +1202,7 @@ query_isduplicate(ns_client_t *client, dns_name_t *name,
 	dns_name_t *mname = NULL;
 	isc_result_t result;
 
-	CTRACE("query_isduplicate");
+	CTRACE(ISC_LOG_DEBUG(3), "query_isduplicate");
 
 	for (section = DNS_SECTION_ANSWER;
 	     section <= DNS_SECTION_ADDITIONAL;
@@ -1202,7 +1213,8 @@ query_isduplicate(ns_client_t *client, dns_name_t *name,
 			/*
 			 * We've already got this RRset in the response.
 			 */
-			CTRACE("query_isduplicate: true: done");
+			CTRACE(ISC_LOG_DEBUG(3),
+			       "query_isduplicate: true: done");
 			return (ISC_TRUE);
 		} else if (result == DNS_R_NXRRSET) {
 			/*
@@ -1218,7 +1230,7 @@ query_isduplicate(ns_client_t *client, dns_name_t *name,
 	if (mnamep != NULL)
 		*mnamep = mname;
 
-	CTRACE("query_isduplicate: false: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_isduplicate: false: done");
 	return (ISC_FALSE);
 }
 
@@ -1245,7 +1257,7 @@ query_addadditional(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	if (!WANTDNSSEC(client) && dns_rdatatype_isdnssec(qtype))
 		return (ISC_R_SUCCESS);
 
-	CTRACE("query_addadditional");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional");
 
 	/*
 	 * Initialization.
@@ -1301,7 +1313,7 @@ query_addadditional(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	if (result != ISC_R_SUCCESS)
 		goto try_cache;
 
-	CTRACE("query_addadditional: db_find");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional: db_find");
 
 	/*
 	 * Since we are looking for authoritative data, we do not set
@@ -1573,7 +1585,7 @@ query_addadditional(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	}
 
  addname:
-	CTRACE("query_addadditional: addname");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional: addname");
 	/*
 	 * If we haven't added anything, then we're done.
 	 */
@@ -1613,7 +1625,7 @@ query_addadditional(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	}
 
  cleanup:
-	CTRACE("query_addadditional: cleanup");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional: cleanup");
 	query_putrdataset(client, &rdataset);
 	if (sigrdataset != NULL)
 		query_putrdataset(client, &sigrdataset);
@@ -1626,7 +1638,7 @@ query_addadditional(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	if (zone != NULL)
 		dns_zone_detach(&zone);
 
-	CTRACE("query_addadditional: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional: done");
 	return (eresult);
 }
 
@@ -1744,7 +1756,7 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	dns_clientinfomethods_init(&cm, ns_client_sourceip);
 	dns_clientinfo_init(&ci, client, NULL);
 
-	CTRACE("query_addadditional2");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2");
 
 	/*
 	 * We treat type A additional section processing as if it
@@ -1776,14 +1788,16 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	if (result != ISC_R_SUCCESS)
 		goto findauthdb;
 	if (zone == NULL) {
-		CTRACE("query_addadditional2: auth zone not found");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addadditional2: auth zone not found");
 		goto try_cache;
 	}
 
 	/* Is the cached DB up-to-date? */
 	result = query_iscachevalid(zone, cdb, NULL, cversion);
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_addadditional2: old auth additional cache");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addadditional2: old auth additional cache");
 		query_discardcache(client, rdataset_base, additionaltype,
 				   type, &zone, &cdb, &cversion, &cnode,
 				   &cfname);
@@ -1796,7 +1810,8 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 		 * ACL, since the result (not using this zone) would be same
 		 * regardless of the result.
 		 */
-		CTRACE("query_addadditional2: negative auth additional cache");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addadditional2: negative auth additional cache");
 		dns_db_closeversion(cdb, &cversion, ISC_FALSE);
 		dns_db_detach(&cdb);
 		dns_zone_detach(&zone);
@@ -1813,7 +1828,8 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	}
 
 	/* We've got an active cache. */
-	CTRACE("query_addadditional2: auth additional cache");
+	CTRACE(ISC_LOG_DEBUG(3),
+	       "query_addadditional2: auth additional cache");
 	dns_db_closeversion(cdb, &cversion, ISC_FALSE);
 	db = cdb;
 	node = cnode;
@@ -1837,7 +1853,7 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 		goto try_cache;
 	}
 
-	CTRACE("query_addadditional2: db_find");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2: db_find");
 
 	/*
 	 * Since we are looking for authoritative data, we do not set
@@ -1922,7 +1938,8 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 
 	result = query_iscachevalid(zone, cdb, client->query.gluedb, cversion);
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_addadditional2: old glue additional cache");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addadditional2: old glue additional cache");
 		query_discardcache(client, rdataset_base, additionaltype,
 				   type, &zone, &cdb, &cversion, &cnode,
 				   &cfname);
@@ -1931,14 +1948,15 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 
 	if (cnode == NULL) {
 		/* We have a negative cache. */
-		CTRACE("query_addadditional2: negative glue additional cache");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addadditional2: negative glue additional cache");
 		dns_db_closeversion(cdb, &cversion, ISC_FALSE);
 		dns_db_detach(&cdb);
 		goto cleanup;
 	}
 
 	/* Cache hit. */
-	CTRACE("query_addadditional2: glue additional cache");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2: glue additional cache");
 	dns_db_closeversion(cdb, &cversion, ISC_FALSE);
 	db = cdb;
 	node = cnode;
@@ -2121,7 +2139,7 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 		}
 	}
 
-	CTRACE("query_addadditional2: addname");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2: addname");
 
 	/*
 	 * If we haven't added anything, then we're done.
@@ -2140,7 +2158,7 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	fname = NULL;
 
  cleanup:
-	CTRACE("query_addadditional2: cleanup");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2: cleanup");
 
 	if (rdataset != NULL)
 		query_putrdataset(client, &rdataset);
@@ -2159,7 +2177,7 @@ query_addadditional2(void *arg, dns_name_t *name, dns_rdatatype_t qtype) {
 	if (zone != NULL)
 		dns_zone_detach(&zone);
 
-	CTRACE("query_addadditional2: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addadditional2: done");
 	return (eresult);
 }
 
@@ -2174,7 +2192,7 @@ query_addrdataset(ns_client_t *client, dns_name_t *fname,
 	 * 'fname', a name in the response message for 'client'.
 	 */
 
-	CTRACE("query_addrdataset");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addrdataset");
 
 	ISC_LIST_APPEND(fname->list, rdataset, link);
 
@@ -2196,7 +2214,7 @@ query_addrdataset(ns_client_t *client, dns_name_t *fname,
 	additionalctx.rdataset = rdataset;
 	(void)dns_rdataset_additionaldata(rdataset, query_addadditional2,
 					  &additionalctx);
-	CTRACE("query_addrdataset: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addrdataset: done");
 }
 
 static isc_result_t
@@ -2228,7 +2246,7 @@ query_dns64(ns_client_t *client, dns_name_t **namep, dns_rdataset_t *rdataset,
 	 * stored in 'dbuf'.  In this case, query_addrrset() guarantees that
 	 * when it returns the name will either have been kept or released.
 	 */
-	CTRACE("query_dns64");
+	CTRACE(ISC_LOG_DEBUG(3), "query_dns64");
 	name = *namep;
 	mname = NULL;
 	mrdataset = NULL;
@@ -2245,7 +2263,8 @@ query_dns64(ns_client_t *client, dns_name_t **namep, dns_rdataset_t *rdataset,
 		 * We've already got an RRset of the given name and type.
 		 * There's nothing else to do;
 		 */
-		CTRACE("query_dns64: dns_message_findname succeeded: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_dns64: dns_message_findname succeeded: done");
 		if (dbuf != NULL)
 			query_releasename(client, namep);
 		return (ISC_R_SUCCESS);
@@ -2376,7 +2395,7 @@ query_dns64(ns_client_t *client, dns_name_t **namep, dns_rdataset_t *rdataset,
 		dns_message_puttemprdatalist(client->message, &dns64_rdatalist);
 	}
 
-	CTRACE("query_dns64: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_dns64: done");
 	return (result);
 }
 
@@ -2395,7 +2414,7 @@ query_filter64(ns_client_t *client, dns_name_t **namep,
 	isc_result_t result;
 	unsigned int i;
 
-	CTRACE("query_filter64");
+	CTRACE(ISC_LOG_DEBUG(3), "query_filter64");
 
 	INSIST(client->query.dns64_aaaaok != NULL);
 	INSIST(client->query.dns64_aaaaoklen == dns_rdataset_count(rdataset));
@@ -2415,7 +2434,8 @@ query_filter64(ns_client_t *client, dns_name_t **namep,
 		 * We've already got an RRset of the given name and type.
 		 * There's nothing else to do;
 		 */
-		CTRACE("query_filter64: dns_message_findname succeeded: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_filter64: dns_message_findname succeeded: done");
 		if (dbuf != NULL)
 			query_releasename(client, namep);
 		return;
@@ -2514,7 +2534,7 @@ query_filter64(ns_client_t *client, dns_name_t **namep,
 	if (dbuf != NULL)
 		query_releasename(client, &name);
 
-	CTRACE("query_filter64: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_filter64: done");
 }
 
 static void
@@ -2536,7 +2556,7 @@ query_addrrset(ns_client_t *client, dns_name_t **namep,
 	 * stored in 'dbuf'.  In this case, query_addrrset() guarantees that
 	 * when it returns the name will either have been kept or released.
 	 */
-	CTRACE("query_addrrset");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addrrset");
 	name = *namep;
 	rdataset = *rdatasetp;
 	if (sigrdatasetp != NULL)
@@ -2552,7 +2572,8 @@ query_addrrset(ns_client_t *client, dns_name_t **namep,
 		/*
 		 * We've already got an RRset of the given name and type.
 		 */
-		CTRACE("query_addrrset: dns_message_findname succeeded: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addrrset: dns_message_findname succeeded: done");
 		if (dbuf != NULL)
 			query_releasename(client, namep);
 		if ((rdataset->attributes & DNS_RDATASETATTR_REQUIRED) != 0)
@@ -2591,7 +2612,7 @@ query_addrrset(ns_client_t *client, dns_name_t **namep,
 		ISC_LIST_APPEND(mname->list, sigrdataset, link);
 		*sigrdatasetp = NULL;
 	}
-	CTRACE("query_addrrset: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addrrset: done");
 }
 
 static inline isc_result_t
@@ -2607,7 +2628,7 @@ query_addsoa(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version,
 	dns_clientinfomethods_t cm;
 	dns_clientinfo_t ci;
 
-	CTRACE("query_addsoa");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addsoa");
 	/*
 	 * Initialization.
 	 */
@@ -2635,12 +2656,14 @@ query_addsoa(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version,
 	dns_name_clone(dns_db_origin(db), name);
 	rdataset = query_newrdataset(client);
 	if (rdataset == NULL) {
+		CTRACE(ISC_LOG_ERROR, "unable to allocate rdataset");
 		eresult = DNS_R_SERVFAIL;
 		goto cleanup;
 	}
 	if (WANTDNSSEC(client) && dns_db_issecure(db)) {
 		sigrdataset = query_newrdataset(client);
 		if (sigrdataset == NULL) {
+			CTRACE(ISC_LOG_ERROR, "unable to allocate sigrdataset");
 			eresult = DNS_R_SERVFAIL;
 			goto cleanup;
 		}
@@ -2670,6 +2693,7 @@ query_addsoa(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version,
 		 * This is bad.  We tried to get the SOA RR at the zone top
 		 * and it didn't work!
 		 */
+		CTRACE(ISC_LOG_ERROR, "unable to find SOA RR at zone apex");
 		eresult = DNS_R_SERVFAIL;
 	} else {
 		/*
@@ -2734,7 +2758,7 @@ query_addns(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version) {
 	dns_clientinfomethods_t cm;
 	dns_clientinfo_t ci;
 
-	CTRACE("query_addns");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addns");
 	/*
 	 * Initialization.
 	 */
@@ -2752,21 +2776,24 @@ query_addns(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version) {
 	 */
 	result = dns_message_gettempname(client->message, &name);
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_addns: dns_message_gettempname failed: done");
+		CTRACE(ISC_LOG_DEBUG(3),
+		       "query_addns: dns_message_gettempname failed: done");
 		return (result);
 	}
 	dns_name_init(name, NULL);
 	dns_name_clone(dns_db_origin(db), name);
 	rdataset = query_newrdataset(client);
 	if (rdataset == NULL) {
-		CTRACE("query_addns: query_newrdataset failed");
+		CTRACE(ISC_LOG_ERROR,
+		       "query_addns: query_newrdataset failed");
 		eresult = DNS_R_SERVFAIL;
 		goto cleanup;
 	}
 	if (WANTDNSSEC(client) && dns_db_issecure(db)) {
 		sigrdataset = query_newrdataset(client);
 		if (sigrdataset == NULL) {
-			CTRACE("query_addns: query_newrdataset failed");
+			CTRACE(ISC_LOG_ERROR,
+			       "query_addns: query_newrdataset failed");
 			eresult = DNS_R_SERVFAIL;
 			goto cleanup;
 		}
@@ -2781,14 +2808,15 @@ query_addns(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version) {
 					     dns_rdatatype_ns, 0, client->now,
 					     rdataset, sigrdataset);
 	} else {
-		CTRACE("query_addns: calling dns_db_find");
+		CTRACE(ISC_LOG_DEBUG(3), "query_addns: calling dns_db_find");
 		result = dns_db_findext(db, name, NULL, dns_rdatatype_ns,
 					client->query.dboptions, 0, &node,
 					fname, &cm, &ci, rdataset, sigrdataset);
-		CTRACE("query_addns: dns_db_find complete");
+		CTRACE(ISC_LOG_DEBUG(3), "query_addns: dns_db_find complete");
 	}
 	if (result != ISC_R_SUCCESS) {
-		CTRACE("query_addns: "
+		CTRACE(ISC_LOG_ERROR,
+		       "query_addns: "
 		       "dns_db_findrdataset or dns_db_find failed");
 		/*
 		 * This is bad.  We tried to get the NS rdataset at the zone
@@ -2805,7 +2833,7 @@ query_addns(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version) {
 	}
 
  cleanup:
-	CTRACE("query_addns: cleanup");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addns: cleanup");
 	query_putrdataset(client, &rdataset);
 	if (sigrdataset != NULL)
 		query_putrdataset(client, &sigrdataset);
@@ -2814,7 +2842,7 @@ query_addns(ns_client_t *client, dns_db_t *db, dns_dbversion_t *version) {
 	if (node != NULL)
 		dns_db_detachnode(db, &node);
 
-	CTRACE("query_addns: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addns: done");
 	return (eresult);
 }
 
@@ -3082,7 +3110,7 @@ query_addbestns(ns_client_t *client) {
 	dns_clientinfomethods_t cm;
 	dns_clientinfo_t ci;
 
-	CTRACE("query_addbestns");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addbestns");
 	fname = NULL;
 	zfname = NULL;
 	rdataset = NULL;
@@ -3287,7 +3315,7 @@ query_addds(ns_client_t *client, dns_db_t *db, dns_dbnode_t *node,
 	isc_result_t result;
 	unsigned int count;
 
-	CTRACE("query_addds");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addds");
 	rname = NULL;
 	rdataset = NULL;
 	sigrdataset = NULL;
@@ -3417,7 +3445,7 @@ query_addwildcardproof(ns_client_t *client, dns_db_t *db,
 	dns_clientinfomethods_t cm;
 	dns_clientinfo_t ci;
 
-	CTRACE("query_addwildcardproof");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addwildcardproof");
 	fname = NULL;
 	rdataset = NULL;
 	sigrdataset = NULL;
@@ -3781,9 +3809,10 @@ query_resume(isc_task_t *task, isc_event_t *event) {
 		if (devent->sigrdataset != NULL)
 			query_putrdataset(client, &devent->sigrdataset);
 		isc_event_free(&event);
-		if (fetch_canceled)
+		if (fetch_canceled) {
+			CTRACE(ISC_LOG_ERROR, "fetch cancelled");
 			query_error(client, DNS_R_SERVFAIL, __LINE__);
-		else
+		} else
 			query_next(client, ISC_R_CANCELED);
 		/*
 		 * This may destroy the client.
@@ -4047,8 +4076,11 @@ rpz_ready(ns_client_t *client, dns_rdataset_t **rdatasetp)
 
 	if (*rdatasetp == NULL) {
 		*rdatasetp = query_newrdataset(client);
-		if (*rdatasetp == NULL)
+		if (*rdatasetp == NULL) {
+			CTRACE(ISC_LOG_ERROR,
+			       "rpz_ready: query_newrdataset failed");
 			return (DNS_R_SERVFAIL);
+		}
 	} else if (dns_rdataset_isassociated(*rdatasetp)) {
 		dns_rdataset_disassociate(*rdatasetp);
 	}
@@ -4187,6 +4219,7 @@ rpz_rrset_find(ns_client_t *client, dns_name_t *name, dns_rdatatype_t type,
 		st->r.r_rdataset = NULL;
 		result = st->r.r_result;
 		if (result == DNS_R_DELEGATION) {
+			CTRACE(ISC_LOG_ERROR, "RPZ recursing");
 			rpz_log_fail(client, DNS_RPZ_ERROR_LEVEL, name,
 				     rpz_type, " rpz_rrset_find(1)", result);
 			st->m.policy = DNS_RPZ_POLICY_ERROR;
@@ -4372,8 +4405,10 @@ rpz_find_p(ns_client_t *client, dns_name_t *self_name, dns_rdatatype_t qtype,
 	 */
 	rpz_clean(zonep, dbp, nodep, rdatasetp);
 	result = rpz_ready(client, rdatasetp);
-	if (result != ISC_R_SUCCESS)
+	if (result != ISC_R_SUCCESS) {
+		CTRACE(ISC_LOG_ERROR, "rpz_ready() failed");
 		return (DNS_R_SERVFAIL);
+	}
 	*versionp = NULL;
 	result = rpz_getdb(client, p_name, rpz_type, zonep, dbp, versionp);
 	if (result != ISC_R_SUCCESS)
@@ -4396,6 +4431,8 @@ rpz_find_p(ns_client_t *client, dns_name_t *self_name, dns_rdatatype_t qtype,
 		if (result != ISC_R_SUCCESS) {
 			rpz_log_fail(client, DNS_RPZ_ERROR_LEVEL, p_name,
 				     rpz_type, " allrdatasets()", result);
+			CTRACE(ISC_LOG_ERROR,
+			       "rpz_find_p: allrdatasets failed");
 			return (DNS_R_SERVFAIL);
 		}
 		for (result = dns_rdatasetiter_first(rdsiter);
@@ -4413,6 +4450,9 @@ rpz_find_p(ns_client_t *client, dns_name_t *self_name, dns_rdatatype_t qtype,
 				rpz_log_fail(client, DNS_RPZ_ERROR_LEVEL,
 					     p_name, rpz_type,
 					     " rdatasetiter", result);
+				CTRACE(ISC_LOG_ERROR,
+				       "rpz_find_p: rdatasetiter_destroy "
+				       "failed");
 				return (DNS_R_SERVFAIL);
 			}
 			/*
@@ -4467,6 +4507,8 @@ rpz_find_p(ns_client_t *client, dns_name_t *self_name, dns_rdatatype_t qtype,
 	default:
 		rpz_log_fail(client, DNS_RPZ_ERROR_LEVEL, p_name, rpz_type,
 			     "", result);
+		CTRACE(ISC_LOG_ERROR,
+		       "rpz_find_p: unexpected result");
 		return (DNS_R_SERVFAIL);
 	}
 }
@@ -4696,6 +4738,8 @@ rpz_rewrite_ip_rrset(ns_client_t *client,
 				     rpz_type, " NS address rewrite rrset",
 				     result);
 		}
+		CTRACE(ISC_LOG_ERROR,
+		       "rpz_rewrite_ip_rrset: unexpected result");
 		return (DNS_R_SERVFAIL);
 	}
 
@@ -5330,6 +5374,7 @@ cleanup:
 		rpz_match_clear(st);
 	}
 	if (st->m.policy == DNS_RPZ_POLICY_ERROR) {
+		CTRACE(ISC_LOG_ERROR, "SERVFAIL due to RPZ policy");
 		st->m.type = DNS_RPZ_TYPE_BAD;
 		result = DNS_R_SERVFAIL;
 	}
@@ -5563,7 +5608,7 @@ query_addnoqnameproof(ns_client_t *client, dns_rdataset_t *rdataset) {
 	dns_rdataset_t *neg, *negsig;
 	isc_result_t result = ISC_R_NOMEMORY;
 
-	CTRACE("query_addnoqnameproof");
+	CTRACE(ISC_LOG_DEBUG(3), "query_addnoqnameproof");
 
 	fname = NULL;
 	neg = NULL;
@@ -5977,7 +6022,7 @@ redirect(ns_client_t *client, dns_name_t *name, dns_rdataset_t *rdataset,
 	dns_clientinfo_t ci;
 	ns_dbversion_t *dbversion;
 
-	CTRACE("redirect");
+	CTRACE(ISC_LOG_DEBUG(3), "redirect");
 
 	if (client->view->redirect == NULL)
 		return (ISC_FALSE);
@@ -6044,7 +6089,7 @@ redirect(ns_client_t *client, dns_name_t *name, dns_rdataset_t *rdataset,
 		dns_db_detach(&db);
 		return (ISC_FALSE);
 	}
-	CTRACE("redirect: found data: done");
+	CTRACE(ISC_LOG_DEBUG(3), "redirect: found data: done");
 
 	dns_name_copy(found, name, NULL);
 	if (dns_rdataset_isassociated(rdataset))
@@ -6109,11 +6154,12 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 	isc_boolean_t nxrewrite = ISC_FALSE;
 	dns_clientinfomethods_t cm;
 	dns_clientinfo_t ci;
+	char errmsg[256];
 	isc_boolean_t associated;
 	dns_section_t section;
 	dns_ttl_t ttl;
 
-	CTRACE("query_find");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find");
 
 	/*
 	 * One-time initialization.
@@ -6205,11 +6251,15 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		 */
 		dbuf = query_getnamebuf(client);
 		if (dbuf == NULL) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: query_getnamebuf failed (1)");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
 		fname = query_newname(client, dbuf, &b);
 		if (fname == NULL) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: query_newname failed (1)");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
@@ -6221,6 +6271,8 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		}
 		result = dns_name_copy(tname, fname, NULL);
 		if (result != ISC_R_SUCCESS) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: dns_name_copy failed");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
@@ -6249,7 +6301,7 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		type = qtype;
 
  restart:
-	CTRACE("query_find: restart");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: restart");
 	want_restart = ISC_FALSE;
 	authoritative = ISC_FALSE;
 	version = NULL;
@@ -6326,8 +6378,11 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 				inc_stats(client, dns_nsstatscounter_authrej);
 			if (!PARTIALANSWER(client))
 				QUERY_ERROR(DNS_R_REFUSED);
-		} else
+		} else {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: query_getdb failed");
 			QUERY_ERROR(DNS_R_SERVFAIL);
+		}
 		goto cleanup;
 	}
 
@@ -6360,24 +6415,30 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 	}
 
  db_find:
-	CTRACE("query_find: db_find");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: db_find");
 	/*
 	 * We'll need some resources...
 	 */
 	dbuf = query_getnamebuf(client);
 	if (dbuf == NULL) {
+		CTRACE(ISC_LOG_ERROR,
+		       "query_find: query_getnamebuf failed (2)");
 		QUERY_ERROR(DNS_R_SERVFAIL);
 		goto cleanup;
 	}
 	fname = query_newname(client, dbuf, &b);
 	rdataset = query_newrdataset(client);
 	if (fname == NULL || rdataset == NULL) {
+		CTRACE(ISC_LOG_ERROR,
+		       "query_find: query_newname failed (2)");
 		QUERY_ERROR(DNS_R_SERVFAIL);
 		goto cleanup;
 	}
 	if (WANTDNSSEC(client) && (!is_zone || dns_db_issecure(db))) {
 		sigrdataset = query_newrdataset(client);
 		if (sigrdataset == NULL) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: query_newrdataset failed (2)");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
@@ -6394,7 +6455,7 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		dns_cache_updatestats(client->view->cache, result);
 
  resume:
-	CTRACE("query_find: resume");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: resume");
 
 	/*
 	 * Rate limit these responses to this client.
@@ -6759,6 +6820,8 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 				goto cleanup;
 			} else {
 				/* Unable to give root server referral. */
+				CTRACE(ISC_LOG_ERROR,
+				       "unable to give root server referral");
 				QUERY_ERROR(DNS_R_SERVFAIL);
 				goto cleanup;
 			}
@@ -7025,11 +7088,17 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 			if (fname == NULL) {
 				dbuf = query_getnamebuf(client);
 				if (dbuf == NULL) {
+					CTRACE(ISC_LOG_ERROR,
+					       "query_find: "
+					       "query_getnamebuf failed (3)");
 					QUERY_ERROR(DNS_R_SERVFAIL);
 					goto cleanup;
 				}
 				fname = query_newname(client, dbuf, &b);
 				if (fname == NULL) {
+					CTRACE(ISC_LOG_ERROR,
+					       "query_find: "
+					       "query_newname failed (3)");
 					QUERY_ERROR(DNS_R_SERVFAIL);
 					goto cleanup;
 				}
@@ -7128,6 +7197,10 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 					if (fname == NULL ||
 					    rdataset == NULL ||
 					    sigrdataset == NULL) {
+						CTRACE(ISC_LOG_ERROR,
+						       "query_find: "
+						       "failure getting "
+						       "closest encloser");
 						QUERY_ERROR(DNS_R_SERVFAIL);
 						goto cleanup;
 					}
@@ -7306,11 +7379,17 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 			if (fname == NULL) {
 				dbuf = query_getnamebuf(client);
 				if (dbuf == NULL) {
+					CTRACE(ISC_LOG_ERROR,
+					       "query_find: "
+					       "query_getnamebuf failed (4)");
 					QUERY_ERROR(DNS_R_SERVFAIL);
 					goto cleanup;
 				}
 				fname = query_newname(client, dbuf, &b);
 				if (fname == NULL) {
+					CTRACE(ISC_LOG_ERROR,
+					       "query_find: "
+					       "query_newname failed (4)");
 					QUERY_ERROR(DNS_R_SERVFAIL);
 					goto cleanup;
 				}
@@ -7567,6 +7646,10 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		/*
 		 * Something has gone wrong.
 		 */
+		snprintf(errmsg, sizeof(errmsg) - 1,
+			 "query_find: unexpected error after resuming: %s",
+			 isc_result_totext(result));
+		CTRACE(ISC_LOG_ERROR, errmsg);
 		QUERY_ERROR(DNS_R_SERVFAIL);
 		goto cleanup;
 	}
@@ -7625,6 +7708,8 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		rdsiter = NULL;
 		result = dns_db_allrdatasets(db, node, version, 0, &rdsiter);
 		if (result != ISC_R_SUCCESS) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: type any; allrdatasets failed");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
@@ -7759,12 +7844,18 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 				dns_rdatasetiter_destroy(&rdsiter);
 				fname = query_newname(client, dbuf, &b);
 				goto nxrrset_rrsig;
-			} else
+			} else {
+				CTRACE(ISC_LOG_ERROR,
+				       "query_find: no matching rdatasets "
+				       "in cache");
 				result = DNS_R_SERVFAIL;
+			}
 		}
 
 		dns_rdatasetiter_destroy(&rdsiter);
 		if (result != ISC_R_NOMORE) {
+			CTRACE(ISC_LOG_ERROR,
+			       "query_find: dns_rdatasetiter_destroy failed");
 			QUERY_ERROR(DNS_R_SERVFAIL);
 			goto cleanup;
 		}
@@ -7988,7 +8079,7 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 	}
 
  addauth:
-	CTRACE("query_find: addauth");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: addauth");
 	/*
 	 * Add NS records to the authority section (if we haven't already
 	 * added them to the answer section).
@@ -8016,7 +8107,7 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 				       dns_fixedname_name(&wildcardname),
 				       ISC_TRUE, ISC_FALSE);
  cleanup:
-	CTRACE("query_find: cleanup");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: cleanup");
 	/*
 	 * General cleanup.
 	 */
@@ -8124,7 +8215,7 @@ query_find(ns_client_t *client, dns_fetchevent_t *event, dns_rdatatype_t qtype)
 		query_send(client);
 		ns_client_detach(&client);
 	}
-	CTRACE("query_find: done");
+	CTRACE(ISC_LOG_DEBUG(3), "query_find: done");
 
 	return (eresult);
 }
@@ -8212,7 +8303,7 @@ ns_query_start(ns_client_t *client) {
 	unsigned int saved_extflags = client->extflags;
 	unsigned int saved_flags = client->message->flags;
 
-	CTRACE("ns_query_start");
+	CTRACE(ISC_LOG_DEBUG(3), "ns_query_start");
 
 	/*
 	 * Test only.
diff --git a/lib/dns/resolver.c b/lib/dns/resolver.c
index df35fa1f08..12a8fd567d 100644
--- a/lib/dns/resolver.c
+++ b/lib/dns/resolver.c
@@ -80,11 +80,13 @@
 				      DNS_LOGMODULE_RESOLVER, \
 				      ISC_LOG_DEBUG(3), \
 				      "res %p: %s", (r), (m))
-#define FCTXTRACE(m)    isc_log_write(dns_lctx, \
+#define FCTXTRACE(m) \
+			isc_log_write(dns_lctx, \
 				      DNS_LOGCATEGORY_RESOLVER, \
 				      DNS_LOGMODULE_RESOLVER, \
 				      ISC_LOG_DEBUG(3), \
-				      "fctx %p(%s): %s", fctx, fctx->info, (m))
+				      "fctx %p(%s): %s", \
+				      fctx, fctx->info, (m))
 #define FCTXTRACE2(m1, m2) \
 			isc_log_write(dns_lctx, \
 				      DNS_LOGCATEGORY_RESOLVER, \
@@ -92,6 +94,22 @@
 				      ISC_LOG_DEBUG(3), \
 				      "fctx %p(%s): %s %s", \
 				      fctx, fctx->info, (m1), (m2))
+#define FCTXTRACE3(m, res) \
+			isc_log_write(dns_lctx, \
+				      DNS_LOGCATEGORY_RESOLVER, \
+				      DNS_LOGMODULE_RESOLVER, \
+				      ISC_LOG_DEBUG(3), \
+				      "fctx %p(%s): [result: %s] %s", \
+				      fctx, fctx->info, \
+				      isc_result_totext(res), (m))
+#define FCTXTRACE4(m1, m2, res) \
+			isc_log_write(dns_lctx, \
+				      DNS_LOGCATEGORY_RESOLVER, \
+				      DNS_LOGMODULE_RESOLVER, \
+				      ISC_LOG_DEBUG(3), \
+				      "fctx %p(%s): [result: %s] %s %s", \
+				      fctx, fctx->info, \
+				      isc_result_totext(res), (m1), (m2))
 #define FTRACE(m)       isc_log_write(dns_lctx, \
 				      DNS_LOGCATEGORY_RESOLVER, \
 				      DNS_LOGMODULE_RESOLVER, \
@@ -1268,6 +1286,9 @@ process_sendevent(resquery_t *query, isc_event_t *event) {
 		case ISC_R_NOPERM:
 		case ISC_R_ADDRNOTAVAIL:
 		case ISC_R_CONNREFUSED:
+			FCTXTRACE3("query canceled in sendevent(): "
+				   "no route to host; no response",
+				   sevent->result);
 
 			/*
 			 * No route to remote.
@@ -1279,6 +1300,10 @@ process_sendevent(resquery_t *query, isc_event_t *event) {
 			break;
 
 		default:
+			FCTXTRACE3("query canceled in sendevent() due to "
+				   "unexpected event result; responding",
+				   sevent->result);
+
 			fctx_cancelquery(&query, NULL, NULL, ISC_FALSE);
 			break;
 		}
@@ -2359,6 +2384,9 @@ resquery_connected(isc_task_t *task, isc_event_t *event) {
 			isc_interval_set(&interval, 20, 0);
 			result = fctx_startidletimer(query->fctx, &interval);
 			if (result != ISC_R_SUCCESS) {
+				FCTXTRACE("query canceled: idle timer failed; "
+					  "responding");
+
 				fctx_cancelquery(&query, NULL, NULL, ISC_FALSE);
 				fctx_done(fctx, result, __LINE__);
 				break;
@@ -2395,6 +2423,9 @@ resquery_connected(isc_task_t *task, isc_event_t *event) {
 				result = resquery_send(query);
 
 			if (result != ISC_R_SUCCESS) {
+				FCTXTRACE("query canceled: "
+					  "resquery_send() failed; responding");
+
 				fctx_cancelquery(&query, NULL, NULL, ISC_FALSE);
 				fctx_done(fctx, result, __LINE__);
 			}
@@ -2406,6 +2437,10 @@ resquery_connected(isc_task_t *task, isc_event_t *event) {
 		case ISC_R_NOPERM:
 		case ISC_R_ADDRNOTAVAIL:
 		case ISC_R_CONNECTIONRESET:
+			FCTXTRACE3("query canceled in connected(): "
+				   "no route to host; no response",
+				   sevent->result);
+
 			/*
 			 * No route to remote.
 			 */
@@ -2415,6 +2450,10 @@ resquery_connected(isc_task_t *task, isc_event_t *event) {
 			break;
 
 		default:
+			FCTXTRACE3("query canceled in connected() due to "
+				   "unexpected event result; responding",
+				   sevent->result);
+
 			isc_socket_detach(&query->tcpsocket);
 			fctx_cancelquery(&query, NULL, NULL, ISC_FALSE);
 			break;
@@ -2495,11 +2534,12 @@ fctx_finddone(isc_task_t *task, isc_event_t *event) {
 	isc_event_free(&event);
 	dns_adb_destroyfind(&find);
 
-	if (want_try)
+	if (want_try) {
 		fctx_try(fctx, ISC_TRUE, ISC_FALSE);
-	else if (want_done)
+	} else if (want_done) {
+		FCTXTRACE("fetch failed in finddone(); return ISC_R_FAILURE");
 		fctx_done(fctx, ISC_R_FAILURE, __LINE__);
-	else if (destroy) {
+	} else if (destroy) {
 			fctx_destroy(fctx);
 		if (bucket_empty)
 			empty_bucket(res);
@@ -3479,6 +3519,7 @@ fctx_timeout(isc_task_t *task, isc_event_t *event) {
 
 		fctx->timeouts++;
 		fctx->timeout = ISC_TRUE;
+
 		/*
 		 * We could cancel the running queries here, or we could let
 		 * them keep going.  Since we normally use separate sockets for
@@ -3490,10 +3531,13 @@ fctx_timeout(isc_task_t *task, isc_event_t *event) {
 		 */
 		query = ISC_LIST_HEAD(fctx->queries);
 		if (query != NULL &&
-		    isc_time_compare(&tevent->due, &query->start) >= 0) {
+		    isc_time_compare(&tevent->due, &query->start) >= 0)
+		{
+			FCTXTRACE("query timed out; no response");
 			fctx_cancelquery(&query, NULL, NULL, ISC_TRUE);
 		}
 		fctx->attributes &= ~FCTX_ATTR_ADDRWAIT;
+
 		/*
 		 * Our timer has triggered.  Reestablish the fctx lifetime
 		 * timer.
@@ -3777,7 +3821,6 @@ fctx_create(dns_resolver_t *res, dns_name_t *name, dns_rdatatype_t type,
 	unsigned int findoptions = 0;
 	char buf[DNS_NAME_FORMATSIZE + DNS_RDATATYPE_FORMATSIZE];
 	char typebuf[DNS_RDATATYPE_FORMATSIZE];
-	dns_name_t suffix;
 	isc_mem_t *mctx;
 
 	/*
@@ -3789,6 +3832,11 @@ fctx_create(dns_resolver_t *res, dns_name_t *name, dns_rdatatype_t type,
 	fctx = isc_mem_get(mctx, sizeof(*fctx));
 	if (fctx == NULL)
 		return (ISC_R_NOMEMORY);
+
+	/*
+	 * Make fctx->info point to a copy of a formatted string
+	 * "name/type".
+	 */
 	dns_name_format(name, buf, sizeof(buf));
 	dns_rdatatype_format(type, typebuf, sizeof(typebuf));
 	strcat(buf, "/");       /* checked */
@@ -3798,6 +3846,7 @@ fctx_create(dns_resolver_t *res, dns_name_t *name, dns_rdatatype_t type,
 		result = ISC_R_NOMEMORY;
 		goto cleanup_fetch;
 	}
+
 	FCTXTRACE("create");
 	dns_name_init(&fctx->name, NULL);
 	result = dns_name_dup(name, mctx, &fctx->name);
@@ -3870,10 +3919,12 @@ fctx_create(dns_resolver_t *res, dns_name_t *name, dns_rdatatype_t type,
 		dns_forwarders_t *forwarders = NULL;
 		unsigned int labels;
 		dns_name_t *fwdname = name;
+		dns_name_t suffix;
 
 		/*
-		 * DS records are found in the parent server.
-		 * Strip label to get the correct forwarder (if any).
+		 * DS records are found in the parent server. Strip one
+		 * leading label from the name (to be used in finding
+		 * the forwarder).
 		 */
 		if (dns_rdatatype_atparent(fctx->type) &&
 		    dns_name_countlabels(name) > 1) {
@@ -3882,6 +3933,8 @@ fctx_create(dns_resolver_t *res, dns_name_t *name, dns_rdatatype_t type,
 			dns_name_getlabelsequence(name, 1, labels - 1, &suffix);
 			fwdname = &suffix;
 		}
+
+		/* Find the forwarder for this name. */
 		dns_fixedname_init(&fixed);
 		domain = dns_fixedname_name(&fixed);
 		result = dns_fwdtable_find2(fctx->res->view->fwdtable, fwdname,
@@ -7170,6 +7223,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 
 	if (fctx->res->exiting) {
 		result = ISC_R_SHUTTINGDOWN;
+		FCTXTRACE("resolver shutting down");
 		goto done;
 	}
 
@@ -7224,6 +7278,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 				    no_response = ISC_TRUE;
 			}
 		}
+		FCTXTRACE3("dispatcher failure", devent->result);
 		goto done;
 	}
 
@@ -7231,14 +7286,18 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 
 	if (query->tsig != NULL) {
 		result = dns_message_setquerytsig(message, query->tsig);
-		if (result != ISC_R_SUCCESS)
+		if (result != ISC_R_SUCCESS) {
+			FCTXTRACE3("unable to set query tsig", result);
 			goto done;
+		}
 	}
 
 	if (query->tsigkey) {
 		result = dns_message_settsigkey(message, query->tsigkey);
-		if (result != ISC_R_SUCCESS)
+		if (result != ISC_R_SUCCESS) {
+			FCTXTRACE3("unable to set tsig key", result);
 			goto done;
+		}
 	}
 
 	if ((options & DNS_FETCHOPT_TCP) == 0) {
@@ -7250,6 +7309,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 	}
 	result = dns_message_parse(message, &devent->buffer, 0);
 	if (result != ISC_R_SUCCESS) {
+		FCTXTRACE3("message failed to parse", result);
 		switch (result) {
 		case ISC_R_UNEXPECTEDEND:
 			if (!message->question_ok ||
@@ -7338,6 +7398,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		 */
 		resend = ISC_TRUE;
 		/* XXXMPA log it */
+		FCTXTRACE("bad sit");
 		goto done;
 	}
 #endif
@@ -7348,8 +7409,10 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 	 * returns success anyway.
 	 */
 	result = dns_message_checksig(message, fctx->res->view);
-	if (result != ISC_R_SUCCESS)
+	if (result != ISC_R_SUCCESS) {
+		FCTXTRACE3("signature check failed", result);
 		goto done;
+	}
 
 	/*
 	 * The dispatcher should ensure we only get responses with QR set.
@@ -7453,6 +7516,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 			options |= DNS_FETCHOPT_TCP;
 			resend = ISC_TRUE;
 		}
+		FCTXTRACE3("message truncated", result);
 		goto done;
 	}
 
@@ -7463,6 +7527,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		/* XXXRTH Log */
 		broken_server = DNS_R_UNEXPECTEDOPCODE;
 		keep_trying = ISC_TRUE;
+		FCTXTRACE("invalid message opcode");
 		goto done;
 	}
 
@@ -7497,6 +7562,8 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 	 */
 	if (message->rcode != dns_rcode_noerror &&
 	    message->rcode != dns_rcode_nxdomain) {
+		isc_buffer_t b;
+		char code[64];
 #ifdef ISC_PLATFORM_USESIT
 		unsigned char sit[64];
 
@@ -7623,6 +7690,11 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 			INSIST(broken_server != ISC_R_SUCCESS);
 			keep_trying = ISC_TRUE;
 		}
+
+		isc_buffer_init(&b, code, sizeof(code) - 1);
+		dns_rcode_totext(fctx->rmessage->rcode, &b);
+		code[isc_buffer_usedlength(&b)] = '\0';
+		FCTXTRACE2("remote server broken: returned ", code);
 		goto done;
 	}
 
@@ -7634,6 +7706,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		/* XXXRTH Log */
 		if (result == DNS_R_FORMERR)
 			keep_trying = ISC_TRUE;
+		FCTXTRACE3("response did not match question", result);
 		goto done;
 	}
 
@@ -7654,6 +7727,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 				      isc_result_totext(result));
 		broken_server = DNS_R_LAME;
 		keep_trying = ISC_TRUE;
+		FCTXTRACE("lame server");
 		goto done;
 	}
 
@@ -7706,22 +7780,32 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		 */
 		if ((message->flags & DNS_MESSAGEFLAG_AA) != 0 ||
 		    ISFORWARDER(query->addrinfo))
+		{
 			result = answer_response(fctx);
-		else if (iscname(fctx) &&
+			if (result != ISC_R_SUCCESS)
+				FCTXTRACE3("answer_response (AA/fwd)", result);
+		} else if (iscname(fctx) &&
 			 fctx->type != dns_rdatatype_any &&
-			 fctx->type != dns_rdatatype_cname) {
+			 fctx->type != dns_rdatatype_cname)
+		{
 			/*
 			 * A BIND8 server could return a non-authoritative
 			 * answer when a CNAME is followed.  We should treat
 			 * it as a valid answer.
 			 */
 			result = answer_response(fctx);
+			if (result != ISC_R_SUCCESS)
+				FCTXTRACE3("answer_response (!ANY/!CNAME)",
+					   result);
 		} else if (fctx->type != dns_rdatatype_ns &&
 			   !betterreferral(fctx)) {
 			/*
 			 * Lame response !!!.
 			 */
 			result = answer_response(fctx);
+			if (result != ISC_R_SUCCESS)
+				FCTXTRACE("answer_response (!NS)");
+				FCTXTRACE3("answer_response (!NS)", result);
 		} else {
 			if (fctx->type == dns_rdatatype_ns) {
 				/*
@@ -7734,6 +7818,9 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 				 */
 				result = noanswer_response(fctx, NULL,
 						   LOOK_FOR_NS_IN_ANSWER);
+				if (result != ISC_R_SUCCESS)
+					FCTXTRACE3("noanswer_response (NS)",
+						   result);
 			} else {
 				/*
 				 * Some other servers may still somehow include
@@ -7749,6 +7836,8 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 				 */
 				result = noanswer_response(fctx, NULL,
 						   LOOK_FOR_GLUE_IN_ANSWER);
+				if (result != ISC_R_SUCCESS)
+					FCTXTRACE3("noanswer_response", result);
 			}
 			if (result != DNS_R_DELEGATION) {
 				/*
@@ -7813,6 +7902,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 			 */
 			if (result == DNS_R_FORMERR)
 				keep_trying = ISC_TRUE;
+			FCTXTRACE3("noanswer_response", result);
 			goto done;
 		}
 	} else {
@@ -7822,6 +7912,7 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		/* XXXRTH Log */
 		broken_server = DNS_R_UNEXPECTEDRCODE;
 		keep_trying = ISC_TRUE;
+		FCTXTRACE("broken server: unexpected rcode");
 		goto done;
 	}
 
@@ -7836,8 +7927,10 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 	 */
 	if (WANTCACHE(fctx)) {
 		result = cache_message(fctx, query->addrinfo, now);
-		if (result != ISC_R_SUCCESS)
+		if (result != ISC_R_SUCCESS) {
+			FCTXTRACE3("cache_message complete", result);
 			goto done;
+		}
 	}
 
 	/*
@@ -7855,6 +7948,8 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 		 * Cache any negative cache entries in the message.
 		 */
 		result = ncache_message(fctx, query->addrinfo, covers, now);
+		if (result != ISC_R_SUCCESS)
+			FCTXTRACE3("ncache_message complete", result);
 	}
 
  done:
@@ -7864,6 +7959,10 @@ resquery_response(isc_task_t *task, isc_event_t *event) {
 	 */
 	addrinfo = query->addrinfo;
 
+	FCTXTRACE4("query canceled in response(); ",
+		   no_response ? "no response" : "responding",
+		   result);
+
 	/*
 	 * Cancel the query.
 	 *
@@ -8616,6 +8715,10 @@ log_fetch(dns_name_t *name, dns_rdatatype_t type) {
 	char typebuf[DNS_RDATATYPE_FORMATSIZE];
 	int level = ISC_LOG_DEBUG(1);
 
+	/*
+	 * If there's no chance of logging it, don't render (format) the
+	 * name and RDATA type (further below), and return early.
+	 */
 	if (! isc_log_wouldlog(dns_lctx, level))
 		return;
 
@@ -9022,6 +9125,11 @@ dns_resolver_flushbadcache(dns_resolver_t *resolver, dns_name_t *name) {
 	unsigned int i;
 	dns_badcache_t *bad, *prev, *next;
 
+	/*
+	 * Drop all entries that match the name, and also all expired
+	 * entries from the badcache.
+	 */
+
 	REQUIRE(VALID_RESOLVER(resolver));
 
 	LOCK(&resolver->lock);
@@ -9066,6 +9174,8 @@ dns_resolver_flushbadnames(dns_resolver_t *resolver, dns_name_t *name) {
 	isc_time_t now;
 	isc_result_t result;
 
+	/* Drop all expired entries from the badcache. */
+
 	REQUIRE(VALID_RESOLVER(resolver));
 	REQUIRE(name != NULL);
 
@@ -9105,6 +9215,13 @@ resizehash(dns_resolver_t *resolver, isc_time_t *now, isc_boolean_t grow) {
 	dns_badcache_t **new, *bad, *next;
 	unsigned int i;
 
+	/*
+	 * The number of buckets in the hashtable is modified in this
+	 * function. Afterwards, all the entries are remapped into the
+	 * corresponding new slot. Rehashing (hash computation) is
+	 * unnecessary as the hash values had been saved.
+	 */
+
 	if (grow)
 		newsize = resolver->badhash * 2 + 1;
 	else
@@ -9115,6 +9232,13 @@ resizehash(dns_resolver_t *resolver, isc_time_t *now, isc_boolean_t grow) {
 	if (new == NULL)
 		return;
 	memset(new, 0, sizeof(*resolver->badcache) * newsize);
+
+	/*
+	 * Because the hashtable implements a simple modulus mapping
+	 * from hash to bucket (no extendible hashing is used), every
+	 * name in the hashtable has to be remapped to its new slot.
+	 * Entries that have expired (time) are dropped.
+	 */
 	for (i = 0; i < resolver->badhash; i++) {
 		for (bad = resolver->badcache[i]; bad != NULL; bad = next) {
 			next = bad->next;
@@ -9143,6 +9267,18 @@ dns_resolver_addbadcache(dns_resolver_t *resolver, dns_name_t *name,
 	unsigned int i, hashval;
 	dns_badcache_t *bad, *prev, *next;
 
+	/*
+	 * The badcache is implemented as a hashtable keyed on the name,
+	 * and each bucket slot points to a linked list (separate
+	 * chaining).
+	 *
+	 * To avoid long list chains, if the number of entries in the
+	 * hashtable goes over number-of-buckets * 8, the
+	 * number-of-buckets is doubled. Similarly, if the number of
+	 * entries goes below number-of-buckets * 2, the number-of-buckets
+	 * is halved. See resizehash().
+	 */
+
 	REQUIRE(VALID_RESOLVER(resolver));
 
 	LOCK(&resolver->lock);
@@ -9167,6 +9303,7 @@ dns_resolver_addbadcache(dns_resolver_t *resolver, dns_name_t *name,
 		next = bad->next;
 		if (bad->type == type && dns_name_equal(name, &bad->name))
 			break;
+		/* Drop expired entries when walking the chain. */
 		if (isc_time_compare(&bad->expire, &now) < 0) {
 			if (prev == NULL)
 				resolver->badcache[i] = bad->next;
@@ -9179,6 +9316,12 @@ dns_resolver_addbadcache(dns_resolver_t *resolver, dns_name_t *name,
 			prev = bad;
 	}
 	if (bad == NULL) {
+		/*
+		 * Insert the name into the badcache hashtable at the
+		 * head of the linked list at the appropriate slot. The
+		 * name data follows right after the allocation for the
+		 * linked list node.
+		 */
 		isc_buffer_t buffer;
 		bad = isc_mem_get(resolver->mctx, sizeof(*bad) + name->length);
 		if (bad == NULL)
@@ -9337,6 +9480,12 @@ dns_resolver_disable_algorithm(dns_resolver_t *resolver, dns_name_t *name,
 	isc_result_t result;
 	dns_rbtnode_t *node = NULL;
 
+	/*
+	 * Whether an algorithm is disabled (or not) is stored in a
+	 * per-name bitfield that is stored as the node data of an
+	 * RBT.
+	 */
+
 	REQUIRE(VALID_RESOLVER(resolver));
 	if (alg > 255)
 		return (ISC_R_RANGE);
@@ -9358,7 +9507,17 @@ dns_resolver_disable_algorithm(dns_resolver_t *resolver, dns_name_t *name,
 
 	if (result == ISC_R_SUCCESS || result == ISC_R_EXISTS) {
 		algorithms = node->data;
+		/*
+		 * If algorithms is set, algorithms[0] contains its
+		 * length.
+		 */
 		if (algorithms == NULL || len > *algorithms) {
+			/*
+			 * If no bitfield exists in the node data, or if
+			 * it is not long enough, allocate a new
+			 * bitfield and copy the old (smaller) bitfield
+			 * into it if one exists.
+			 */
 			new = isc_mem_get(resolver->mctx, len);
 			if (new == NULL) {
 				result = ISC_R_NOMEMORY;
@@ -9368,8 +9527,10 @@ dns_resolver_disable_algorithm(dns_resolver_t *resolver, dns_name_t *name,
 			if (algorithms != NULL)
 				memmove(new, algorithms, *algorithms);
 			new[len-1] |= mask;
+			/* new[0] should contain the length of new. */
 			*new = len;
 			node->data = new;
+			/* Free the older bitfield. */
 			if (algorithms != NULL)
 				isc_mem_put(resolver->mctx, algorithms,
 					    *algorithms);
@@ -9451,6 +9612,11 @@ dns_resolver_disable_ds_digest(dns_resolver_t *resolver, dns_name_t *name,
 	isc_result_t result;
 	dns_rbtnode_t *node = NULL;
 
+	/*
+	 * Whether a digest is disabled (or not) is stored in a per-name
+	 * bitfield that is stored as the node data of an RBT.
+	 */
+
 	REQUIRE(VALID_RESOLVER(resolver));
 	if (digest_type > 255)
 		return (ISC_R_RANGE);
@@ -9472,7 +9638,14 @@ dns_resolver_disable_ds_digest(dns_resolver_t *resolver, dns_name_t *name,
 
 	if (result == ISC_R_SUCCESS || result == ISC_R_EXISTS) {
 		digests = node->data;
+		/* If digests is set, digests[0] contains its length. */
 		if (digests == NULL || len > *digests) {
+			/*
+			 * If no bitfield exists in the node data, or if
+			 * it is not long enough, allocate a new
+			 * bitfield and copy the old (smaller) bitfield
+			 * into it if one exists.
+			 */
 			new = isc_mem_get(resolver->mctx, len);
 			if (new == NULL) {
 				result = ISC_R_NOMEMORY;
@@ -9482,8 +9655,10 @@ dns_resolver_disable_ds_digest(dns_resolver_t *resolver, dns_name_t *name,
 			if (digests != NULL)
 				memmove(new, digests, *digests);
 			new[len-1] |= mask;
+			/* new[0] should contain the length of new. */
 			*new = len;
 			node->data = new;
+			/* Free the older bitfield. */
 			if (digests != NULL)
 				isc_mem_put(resolver->mctx, digests,
 					    *digests);