Cached DNS lookups taking significantly longer with newly released Pi-hole FTL v5.9, Web v5.6 and Core v5.4

One potential issue I want to point out:
the response time for Cached DNS lookups takes significantly longer than before using this beta. Previously it would show up sub-1ms when cached.
Now it tends to hover around 5-6 ms, sometimes even reaching over 20 ms. That's a little bit unusual. Currently running it on DietPi 7.3.2 (64bit) + Cloudflared (for DOH on port 5053) on a RPI4 4Gb. Maybe worth looking deeper.

I'm happy to provide logs or a debug code.

Local cache lookups taking much longer than on master branch. On master usually less than .5ms. On beta some are upwards of 70ms, most around 25ms.

It's good to be able to verify these bugs with others. Thanks for sharing!

Yes, thanks for your reports. We've seen this and are currently checking where it comes from. The upcoming version embedded dnsmasq has still a few bugs as well and Pi-hole users already helped us identifying a quite severe bug which we reported upstream already. It is a subtle bug that manifests in the DNS server believing the upstream DNS server munged a domain name. As this also prevents domains from entering the cache at all (without logging that this happens), it may be that the issue is more widespread and more domains are just never really added to the cache, resulting in queries being incorrectly reported as cached whereas we had to ask upstream. This seems to be the best explanation for the observed behavior.

Could you provide a few examples of such domains from your /var/log/pihole.log file? Even when the timestamps are not millisecond accurate, it should show us what happened to the queries.

Jul 5 22:11:58 dnsmasq[431]: query[type=65] api.overcast.fm from 2a02:
Jul 5 22:11:58 dnsmasq[431]: cached api.overcast.fm is
Jul 5 22:11:58 dnsmasq[431]: forwarded api.overcast.fm to 127.0.0.1
Jul 5 22:11:58 dnsmasq[431]: query[AAAA] api.overcast.fm from 2a02:
Jul 5 22:11:58 dnsmasq[431]: cached api.overcast.fm is
Jul 5 22:11:58 dnsmasq[431]: cached overcast.fm is NODATA-IPv6
Jul 5 22:11:58 dnsmasq[431]: query[A] api.overcast.fm from 2a02:
Jul 5 22:11:58 dnsmasq[431]: cached api.overcast.fm is
Jul 5 22:11:58 dnsmasq[431]: cached overcast.fm is 45.79.15.101
Jul 5 22:11:58 dnsmasq[431]: cached overcast.fm is 45.79.46.187
Jul 5 22:11:58 dnsmasq[431]: query[AAAA] overcast.fm from 2a02:
Jul 5 22:11:58 dnsmasq[431]: cached overcast.fm is NODATA-IPv6
Jul 5 22:12:03 dnsmasq[431]: query[type=65] smoot-searchv2-euc1a.v.aaplimg.com from 2a02:
Jul 5 22:12:03 dnsmasq[431]: forwarded smoot-searchv2-euc1a.v.aaplimg.com to 127.0.0.1
Jul 5 22:12:03 dnsmasq[431]: query[AAAA] smoot-searchv2-euc1a.v.aaplimg.com from 2a02:
Jul 5 22:12:03 dnsmasq[431]: cached smoot-searchv2-euc1a.v.aaplimg.com is NODATA-IPv6
Jul 5 22:12:06 dnsmasq[431]: query[type=65] clients1.google.com from 2a02:
Jul 5 22:12:06 dnsmasq[431]: forwarded clients1.google.com to 127.0.0.1
Jul 5 22:12:06 dnsmasq[431]: query[AAAA] clients1.google.com from 2a02:
Jul 5 22:12:06 dnsmasq[431]: query[A] clients1.google.com from 2a02:
Jul 5 22:12:24 dnsmasq[431]: query[type=65] gateway.fe.apple-dns.net from 2a02:908:d86
Jul 5 22:12:24 dnsmasq[431]: forwarded gateway.fe.apple-dns.net to 127.0.0.1

I shortened my IPV6 addresses

Trying out the new FTL update. Improved the lookup time, but not significantly.

The delay issues should be resolved now, please update and test again if the delay is still an issue for you.

Yes, FTL v5.9, vDev-f31ff95 did solve the cached DNS lookup delay!

Thank you very much :slight_smile: