Log query and depth counters during fetches when querytrace is enabled (#41787)

(cherry picked from commit 275265ab27815d2261ebf68b48201fb7bffdf426)

diff --git a/CHANGES b/CHANGES
index 41d3d15b1d79dba5468140e8e5380baf177f3f48..f4a8d60d21a5fb3002ff2d85ef8568709727ce9a 100644 (file)
--- a/CHANGES
+++ b/CHANGES
@@ -1,3 +1,7 @@
+4327.  [func]          Log query and depth counters during fetches when
+                       querytrace is enabled (helps in diagnosing).
+                       [RT #41787]
+
 4326.  [protocol]      Add support for AVC. [RT #41819]
 
 4324.  [bug]           When deleting records from a zone database, interior

diff --git a/lib/dns/resolver.c b/lib/dns/resolver.c
index 753bbd75820a5e2f9b995fa0f7b16b245e057a1d..ec7799731db175da5af40f818e0240b70cb749bc 100644 (file)
--- a/lib/dns/resolver.c
+++ b/lib/dns/resolver.c
@@ -110,6 +110,13 @@
                                      "fctx %p(%s): [result: %s] %s %s", \
                                      fctx, fctx->info, \
                                      isc_result_totext(res), (m1), (m2))
+#define FCTXTRACE5(m1, m2, v) \
+                       isc_log_write(dns_lctx, \
+                                     DNS_LOGCATEGORY_RESOLVER, \
+                                     DNS_LOGMODULE_RESOLVER, \
+                                     ISC_LOG_DEBUG(3), \
+                                     "fctx %p(%s): %s %s%u", \
+                                     fctx, fctx->info, (m1), (m2), (v))
 #define FTRACE(m)       isc_log_write(dns_lctx, \
                                      DNS_LOGCATEGORY_RESOLVER, \
                                      DNS_LOGMODULE_RESOLVER, \
@@ -132,6 +139,8 @@
 #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 FCTXTRACE5(m1, m2, v) \
+       do { UNUSED(m1); UNUSED(m2); UNUSED(v); } while (0)
 #define FTRACE(m) do { UNUSED(m); } while (0)
 #define QTRACE(m) do { UNUSED(m); } while (0)
 #endif /* WANT_QUERYTRACE */
@@ -3117,7 +3126,7 @@ fctx_getaddresses(fetchctx_t *fctx, isc_boolean_t badcache) {
        isc_boolean_t all_spilled = ISC_TRUE;
 #endif /* ENABLE_FETCHLIMIT */
 
-       FCTXTRACE("getaddresses");
+       FCTXTRACE5("getaddresses", "fctx->depth=", fctx->depth);
 
        /*
         * Don't pound on remote servers.  (Failsafe!)
@@ -3133,8 +3142,9 @@ fctx_getaddresses(fetchctx_t *fctx, isc_boolean_t badcache) {
        if (fctx->depth > res->maxdepth) {
                isc_log_write(dns_lctx, DNS_LOGCATEGORY_RESOLVER,
                              DNS_LOGMODULE_RESOLVER, ISC_LOG_DEBUG(3),
-                             "too much NS indirection resolving '%s'",
-                             fctx->info);
+                             "too much NS indirection resolving '%s' "
+                             "(depth=%u, maxdepth=%u)",
+                             fctx->info, fctx->depth, res->maxdepth);
                return (DNS_R_SERVFAIL);
        }
 
@@ -3608,7 +3618,7 @@ fctx_try(fetchctx_t *fctx, isc_boolean_t retrying, isc_boolean_t badcache) {
        unsigned int bucketnum;
        isc_boolean_t bucket_empty;
 
-       FCTXTRACE("try");
+       FCTXTRACE5("try", "fctx->qc=", isc_counter_used(fctx->qc));
 
        REQUIRE(!ADDRWAIT(fctx));
 
@@ -3618,8 +3628,10 @@ fctx_try(fetchctx_t *fctx, isc_boolean_t retrying, isc_boolean_t badcache) {
        if (isc_counter_used(fctx->qc) > res->maxqueries) {
                isc_log_write(dns_lctx, DNS_LOGCATEGORY_RESOLVER,
                              DNS_LOGMODULE_RESOLVER, ISC_LOG_DEBUG(3),
-                             "exceeded max queries resolving '%s'",
-                             fctx->info);
+                             "exceeded max queries resolving '%s' "
+                             "(querycount=%u, maxqueries=%u)",
+                             fctx->info,
+                             isc_counter_used(fctx->qc), res->maxqueries);
                fctx_done(fctx, DNS_R_SERVFAIL, __LINE__);
                return;
        }