From 47e4ef0696a3f0c0aa802e24391a9479727d6a67 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.

(cherry picked from commit 039871ceb767088205563965f7aae622a3f77082)
---
 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 e8213c855f..8883008420 100644
--- a/lib/dns/resolver.c
+++ b/lib/dns/resolver.c
@@ -1561,7 +1561,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;
 
@@ -1569,18 +1569,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;
 }
@@ -1626,7 +1641,7 @@ fcount_incr(fetchctx_t *fctx, bool force) {
 		uint_fast32_t spill = atomic_load_acquire(&fctx->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++;
@@ -1670,6 +1685,7 @@ fcount_decr(fetchctx_t *fctx) {
 		fctx->dbucketnum = RES_NOBUCKET;
 
 		if (counter->count == 0) {
+			fcount_logspill(fctx, counter, true);
 			ISC_LIST_UNLINK(dbucket->list, counter, link);
 			isc_mem_put(fctx->res->mctx, counter, sizeof(*counter));
 		}

From 0179459d837169df39f7aa771c8a9807098d76b4 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]

(cherry picked from commit 0d64f55f5dee7ffee76ddc1e4df15514ab7882c9)
---
 CHANGES                     | 5 +++++
 doc/notes/notes-current.rst | 4 ++++
 2 files changed, 9 insertions(+)

diff --git a/CHANGES b/CHANGES
index 073b1ed277..70466f220c 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 48ef2ef8ab..198ba78f2a 100644
--- a/doc/notes/notes-current.rst
+++ b/doc/notes/notes-current.rst
@@ -42,6 +42,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
 ~~~~~~~~~