Repeated priming queries from forwarding caching resolver?

[Havard Eidnes]

Hi,

I recently upgraded one of our caching resolvers to BIND 9.12.3, and
it is configured to do forwarding via

options {
        forwarders {
                <ip-address-1>;
                <ip-address-2>;
        };
        // But if both are dead (unlikely), do resolution ourselves
        forward first;
};

The resolver appears to basically work as intended.

However, I seem to recall that it's expected from a normal recursive
resolver running BIND that it does one so-called "priming query"
shortly after startup, and that it doesn't need to do so again for a
very long time.

This does however appear not to be the case for BIND with the above
configuration.  I noticed this because named keeps on logging
"resolver priming query complete" messages incessantly; here's a brief
sample:


% awk '/resolver priming query complete/ { print $3 " " $5 " " $6 " " $7 " " $8 " " $9 }' /var/log/messages
10:00:01 named[5116]: resolver priming query complete
10:00:02 named[5116]: resolver priming query complete
10:00:02 named[5116]: resolver priming query complete
10:00:08 named[5116]: resolver priming query complete
10:00:10 named[5116]: resolver priming query complete
10:00:11 named[5116]: resolver priming query complete
10:00:11 named[5116]: resolver priming query complete
10:00:13 named[5116]: resolver priming query complete
10:00:13 named[5116]: resolver priming query complete
10:00:15 named[5116]: resolver priming query complete
10:00:21 named[5116]: resolver priming query complete
10:00:21 named[5116]: resolver priming query complete
10:00:23 named[5116]: resolver priming query complete
10:00:23 named[5116]: resolver priming query complete
10:00:25 named[5116]: resolver priming query complete
10:00:33 named[5116]: resolver priming query complete
10:00:33 named[5116]: resolver priming query complete
10:00:35 named[5116]: resolver priming query complete
10:00:40 named[5116]: resolver priming query complete
10:00:45 named[5116]: resolver priming query complete
10:00:50 named[5116]: resolver priming query complete
10:00:54 named[5116]: resolver priming query complete
10:00:57 named[5116]: resolver priming query complete
10:00:57 named[5116]: resolver priming query complete
...

and according to the stats, now after 12-13 hours uptime, it's done
14641 priming queries.  The behaviour doesn't seem to be new for
9.12.3, it's just that I've not noticed this earlier...

Looking at a pcap file of the DNS traffic, the recursive resolver
sends the priming query to one of its forwarders.  In the reply it
gets back the 'aa' flag is of course not set, but the response
contains the RRSIG for the NS set for the root (the answer section),
but no RRSIGs for the data in the additional section (I guess that's
to be expected).  Perhaps the lack of the 'aa' flag (which would be
there if it didn't foward) is part of the reason it keeps on making
these queries?

Anyway, my question is basically whether some of the logic around
"priming queries" needs to be re-visited to get rid of these repeated
seemingly unnecessary queries?

The logic for when to do a priming query is, apparently, found in
lib/dns/view.c, in dns_view_find2(), where after initial attempts at
looking up in local zones or the cache(?), it does:

...
        if (result == ISC_R_NOTFOUND && use_hints && view->hints != NULL) {
...
                result = dns_db_find(view->hints, name, NULL, type, options,
                                     now, &node, foundname,
                                     rdataset, sigrdataset);
                if (result == ISC_R_SUCCESS || result == DNS_R_GLUE) {
                        /*
                         * We just used a hint.  Let the resolver know it
                         * should consider priming.
                         */
                        dns_resolver_prime(view->resolver);
                        dns_db_attach(view->hints, &db);
                        result = DNS_R_HINT;
...

but there's probably more to it than immediately meets the eye...

Best regards,

- Håvard