From 8cfacc6fe1648973e9ca9bbe71bbe0efe0eaa97a Mon Sep 17 00:00:00 2001
From: Aram Sargsyan <aram@isc.org>
Date: Tue, 19 Jul 2022 13:57:48 +0000
Subject: [PATCH 1/2] Improve fetch limit logging

When initially hitting the `fetches-per-zone` value, a log message
is being generated for the event of dropping the first fetch, then
any further log events occur only when another fetch is being dropped
and 60 seconds have been passed since the last logged message.

That logic isn't ideal because when the counter of the outstanding
fetches reaches zero, the structure holding the counters' values will
get deleted, and the information about the dropped fetches accumulated
during the last minute will not be logged.

Improve the fcount_logspill() function to makie sure that the final
values are getting logged before the counter object gets destroyed.
---
 lib/dns/resolver.c | 32 ++++++++++++++++++++++++--------
 1 file changed, 24 insertions(+), 8 deletions(-)

diff --git a/lib/dns/resolver.c b/lib/dns/resolver.c
index 7fa7040aa2..8001b649a9 100644
--- a/lib/dns/resolver.c
+++ b/lib/dns/resolver.c
@@ -1566,7 +1566,7 @@ fctx_cancelqueries(fetchctx_t *fctx, bool no_response, bool age_untried) {
 }
 
 static void
-fcount_logspill(fetchctx_t *fctx, fctxcount_t *counter) {
+fcount_logspill(fetchctx_t *fctx, fctxcount_t *counter, bool final) {
 	char dbuf[DNS_NAME_FORMATSIZE];
 	isc_stdtime_t now;
 
@@ -1574,18 +1574,33 @@ fcount_logspill(fetchctx_t *fctx, fctxcount_t *counter) {
 		return;
 	}
 
+	/* Do not log a message if there were no dropped fetches. */
+	if (counter->dropped == 0) {
+		return;
+	}
+
+	/* Do not log the cumulative message if the previous log is recent. */
 	isc_stdtime_get(&now);
-	if (counter->logged > now - 60) {
+	if (!final && counter->logged > now - 60) {
 		return;
 	}
 
 	dns_name_format(fctx->domain, dbuf, sizeof(dbuf));
 
-	isc_log_write(dns_lctx, DNS_LOGCATEGORY_SPILL, DNS_LOGMODULE_RESOLVER,
-		      ISC_LOG_INFO,
-		      "too many simultaneous fetches for %s "
-		      "(allowed %d spilled %d)",
-		      dbuf, counter->allowed, counter->dropped);
+	if (!final) {
+		isc_log_write(dns_lctx, DNS_LOGCATEGORY_SPILL,
+			      DNS_LOGMODULE_RESOLVER, ISC_LOG_INFO,
+			      "too many simultaneous fetches for %s "
+			      "(allowed %d spilled %d)",
+			      dbuf, counter->allowed, counter->dropped);
+	} else {
+		isc_log_write(dns_lctx, DNS_LOGCATEGORY_SPILL,
+			      DNS_LOGMODULE_RESOLVER, ISC_LOG_INFO,
+			      "fetch counters for %s now being discarded "
+			      "(allowed %d spilled %d; cumulative since "
+			      "initial trigger event)",
+			      dbuf, counter->allowed, counter->dropped);
+	}
 
 	counter->logged = now;
 }
@@ -1653,7 +1668,7 @@ fcount_incr(fetchctx_t *fctx, bool force) {
 		uint_fast32_t spill = atomic_load_acquire(&res->zspill);
 		if (!force && spill != 0 && counter->count >= spill) {
 			counter->dropped++;
-			fcount_logspill(fctx, counter);
+			fcount_logspill(fctx, counter, false);
 			result = ISC_R_QUOTA;
 		} else {
 			counter->count++;
@@ -1696,6 +1711,7 @@ fcount_decr(fetchctx_t *fctx) {
 		fctx->zbucket = NULL;
 
 		if (counter->count == 0) {
+			fcount_logspill(fctx, counter, true);
 			ISC_LIST_UNLINK(zbucket->list, counter, link);
 			isc_mem_put(fctx->res->mctx, counter, sizeof(*counter));
 		}

From 50d57a75511dc50240c1a99385d38aa97136afd0 Mon Sep 17 00:00:00 2001
From: Aram Sargsyan <aram@isc.org>
Date: Tue, 19 Jul 2022 14:34:33 +0000
Subject: [PATCH 2/2] Add CHANGES and release notes for [GL #3461]

---
 CHANGES                     | 5 +++++
 doc/notes/notes-current.rst | 4 ++++
 2 files changed, 9 insertions(+)

diff --git a/CHANGES b/CHANGES
index deecead614..08ac2bdf03 100644
--- a/CHANGES
+++ b/CHANGES
@@ -1,3 +1,8 @@
+5934.	[func]		Improve fetches-per-zone fetch limit logging to log
+			the final allowed and spilled values of the fetch
+			counters before the counter object gets destroyed.
+			[GL #3461]
+
 5933.	[port]		Automatically disable RSASHA1 and NSEC3RSASHA1 in
 			named on Fedorda 33, Oracle Linux 9 and RHEL9 when
 			they are disabled by the security policy. [GL #3469]
diff --git a/doc/notes/notes-current.rst b/doc/notes/notes-current.rst
index a41370d496..5509cdcf82 100644
--- a/doc/notes/notes-current.rst
+++ b/doc/notes/notes-current.rst
@@ -48,6 +48,10 @@ Feature Changes
   to different DNSSEC algorithms is not possible when RSASHA1 is
   disallowed by the OS. :gl:`#3469`
 
+- Fetch limit log messages have been improved to provide more complete
+  information. Specifically, the final values of allowed and spilled fetches
+  will now be logged before the counter object gets destroyed. :gl:`#3461`
+
 Bug Fixes
 ~~~~~~~~~