GitLab

Related to #1775 (closed) (and its successors) and to Support ticket #16212

Although we're aware that resizing (growing) the cache has tables can cause delays in processing client queries by a resolver, particularly when the hash table and cache have reached a significant size, we don't log anything when we do this operation.

This is a bit bizarre - we log when we resize the similar hash tables in ADB.

It was also requested that we add some logging in #1775 (closed), but this appears to have been overlooked:

It would also be really helpful if any hash table growing could be logged - to include what the size is expanding to (this will help admins to tune their servers accordingly).

The customer involved in Support ticket #16212 also suggests that it's probably not necessary to log all cache hash table resizing, just the significant/big events. However, I'd be inclined to: a) Log the initial size (when computed based on max-cache-size and whether or not the server allows recursion) b) Log all resizing/rehash actions

That way, we have something to search for in the logs, if there is a suspicion that hash table resizing - particularly on recursive resolvers of significant size - might have occurred unexpectedly (despite #1775 (closed)) and caused a short (likely a couple of seconds) blackout on the resolver.

Here's the proposed code submitted by the customer:

*** ./lib/dns/rbt.c-orig        2020-08-17 10:29:01.631928214 +0200
--- ./lib/dns/rbt.c     2020-08-17 10:29:33.567261898 +0200
***************
*** 2360,2365 ****
--- 2360,2373 ----
  
        rbt->hashbits = newbits;
        newsize = HASHSIZE(rbt->hashbits);
+ 
+ #ifdef WANT_LOG_REHASH
+         if (oldbits >= 14)
+                 isc_log_write(dns_lctx, DNS_LOGCATEGORY_DATABASE, DNS_LOGMODULE_CACHE, ISC_LOG_WARNING,
+                               "rehash %p: grow table from %d to %d starting", rbt, (int)oldsize, (int)newsize);
+ #endif
+  
+ 
        rbt->hashtable = isc_mem_get(rbt->mctx,
                                     newsize * sizeof(dns_rbtnode_t *));
        memset(rbt->hashtable, 0, newsize * sizeof(dns_rbtnode_t *));
***************
*** 2376,2381 ****
--- 2384,2393 ----
        }
  
        isc_mem_put(rbt->mctx, oldtable, oldsize * sizeof(dns_rbtnode_t *));
+ #ifdef WANT_LOG_REHASH
+         if (oldbits >= 14)
+                 isc_log_write(dns_lctx, DNS_LOGCATEGORY_DATABASE, DNS_LOGMODULE_CACHE, ISC_LOG_WARNING, "rehash %p: grow finished", rbt);
+ #endif
  }
  
  static void

Note - I have tagged this as a bug, since I consider it a failure of named not to log something that can affect its responsiveness when it occurs. If possible, I'd like to see this included in the December releases (and also back-ported to 9.11).