Unbound DNS resolver - high latency at resolution of local mappings

carpet

I do all the administration with a Windows PC
So I'm using the best onboard tools available -> Powershell

I already attached the script an its results als txt.
Here it comes again:
A lookup compared to complete lookup.txt

But I also searched for a "dig" tool withing microsoft store and made a query with it:

As you can see the responsetime of the query was 119ms.

Just to provide you some more information:
My PC is directly connected to my main switch.
Calbe length is ~2m.
Switchport is configured as an access port with untagged vlan 31.
Switch is an D-Link DGS-1100-24 (I know that's crappy but it does it's job - at least until now)
Port 24 of the switch is connected with pfsense; configured as trunk allowing only tagged packets from vlan 21,31,32,33,41,42,43,44,45,46,47.
All these vlans have appropiate interfaces and gateways at pfsene.
Each vlan has its subnet, so vlan 21 is subnet 192.168.21.0/24 and so on...gateway for each subnet is 254.

Windows version of my PC is up to date.

I encounter the dns problem but not only at my windows pc, but with all other devices (Crestron control system, ESP01, ESP8266, ...) in different subnets.
All devices use pfsense for DNS resolution and all of the communiaction relies on the DNS resolution of unbounf resolver for the static DHCP mappings.

regards
Markus

carpet

OK I've spent the complete afternoon with investigation.
Only thing I can say, is that I am now 100% sure that the problem comes from pfsense or my configuration.

How did I test?
I've used a second sg1100 and a spare switch (netgear s3300-52x), applied my current pfsense config (from my live system) to this testing system.
I configured the switch with all neccessary vlans and connected pfsense to port 48 and my Laptop by cable to port 13.
Port 13 = Untagged 31
Port 48 = Trunk Tagged 21,31,32,33,41,42,43,44,45,46,47
nothing else is connected - pfsense has no WAN connection

Then I startet the powershell script at my laptop queriing for static dhcp entries and got responses in ~20ms, but again with some spikes (up to 1xxms).
After connecting to the web interface of this pfsense and checking some logs the spikes accumulated - but I still have no idea why this happens.

johnpoz

@carpet said in Unbound DNS resolver - high latency at resolution of local mappings:

powershell script

did you post this script - like to try it on my setup.

carpet

@johnpoz

posted it here, don't know if thats visible to you

I can't share *ps1 files - so please see my screenshot or use the txt-file posted.

edit:
while (1)
{
try{
$timestamp = Get-Date
$timeout = measure-command{Resolve-DnsName -Name fw01.localdomain -Type A -DnsOnly -server 192.168.31.254 -QuickTimeout -ErrorAction stop} | Select-Object -Property @{n="time";e={$_.Milliseconds,"Milliseconds" -join " "}}
Write-Output "$($timestamp) - $($timeout)"
}
catch
{
$error
break
}
sleep -Milliseconds 1000
}

johnpoz

@carpet hmmm... yeah that is odd..

I created a local record of that same name on mine.. 1ms response.

while (1)
>> {
>> try{
>> $timestamp = Get-Date
>> $timeout = measure-command{Resolve-DnsName -Name fw01.localdomain -Type A -DnsOnly -server 192.168.9.253 -QuickTimeout -ErrorAction stop} | Select-Object -Property @{n="time";e={$_.Milliseconds,"Milliseconds" -join " "}}
>> Write-Output "$($timestamp) - $($timeout)"
>> }
>> catch
>> {
>> $error
>> break
>> }
>> sleep -Milliseconds 1000
>> }
05/13/2023 17:26:33 - @{time=1 Milliseconds}
05/13/2023 17:26:34 - @{time=1 Milliseconds}
05/13/2023 17:26:35 - @{time=1 Milliseconds}
05/13/2023 17:26:36 - @{time=1 Milliseconds}
05/13/2023 17:26:37 - @{time=1 Milliseconds}
05/13/2023 17:26:38 - @{time=1 Milliseconds}
05/13/2023 17:26:39 - @{time=1 Milliseconds}
05/13/2023 17:26:40 - @{time=1 Milliseconds}
05/13/2023 17:26:41 - @{time=1 Milliseconds}
05/13/2023 17:26:42 - @{time=2 Milliseconds}
05/13/2023 17:26:43 - @{time=1 Milliseconds}
05/13/2023 17:26:44 - @{time=1 Milliseconds}
05/13/2023 17:26:45 - @{time=1 Milliseconds}
05/13/2023 17:26:46 - @{time=1 Milliseconds}
05/13/2023 17:26:47 - @{time=1 Milliseconds}

carpet

@johnpoz

OK, I think unbound is not the problem.
I disabled pfblockerng and rebooted my testing pfsense.
Result:

testing envireonment.jpg

so my next assumption: pfblockerng is causing my problems - but I'm still wondering why I don't get 1ms replies like you got.

Apart from pfblockerng only avahi package is running.

But one thing is still there: if I make any change in the pfsense GUI (i.e. page flip to dashboard) the responsetime of one DNS reply takes longer about +10-15ms. Afterwards it's again at 2-5ms....

Maybe another interesting detail:
both of my sg1100 were affected by this:
https://forum.netgate.com/topic/178049/pfsense-plus-23-01-updates-on-the-1100-and-2100-systems
so I had to request the firmwareimage from TAC lite and had to format the systems with ZFS.
I have no idea how this is related to my problems, but I think I should share this information.

EDIT:
after disabling avahi

PS C:\WINDOWS\system32> while (1)
{
try{
$timestamp = Get-Date
$timeout = measure-command{Resolve-DnsName -Name fw01.localdomain -Type A -DnsOnly -server 192.168.31.254 -QuickTimeout -ErrorAction stop} | Select-Object -Property @{n="time";e={$_.Milliseconds,"Milliseconds" -join " "}}
Write-Output "$($timestamp) - $($timeout)"
}
catch
{
$error
break
}
sleep -Milliseconds 1000
}
05/14/2023 11:40:28 - @{time=27 Milliseconds}
05/14/2023 11:40:29 - @{time=2 Milliseconds}
05/14/2023 11:40:30 - @{time=3 Milliseconds}
05/14/2023 11:40:31 - @{time=2 Milliseconds}
05/14/2023 11:40:32 - @{time=13 Milliseconds}
05/14/2023 11:40:33 - @{time=3 Milliseconds}
05/14/2023 11:40:34 - @{time=3 Milliseconds}
05/14/2023 11:40:35 - @{time=14 Milliseconds}
05/14/2023 11:40:36 - @{time=3 Milliseconds}
05/14/2023 11:40:37 - @{time=3 Milliseconds}
05/14/2023 11:40:38 - @{time=3 Milliseconds}
05/14/2023 11:40:39 - @{time=9 Milliseconds}
05/14/2023 11:40:40 - @{time=3 Milliseconds}
05/14/2023 11:40:41 - @{time=2 Milliseconds}
05/14/2023 11:40:42 - @{time=4 Milliseconds}
05/14/2023 11:40:43 - @{time=2 Milliseconds}
05/14/2023 11:40:44 - @{time=3 Milliseconds}
05/14/2023 11:40:45 - @{time=2 Milliseconds}
05/14/2023 11:40:46 - @{time=3 Milliseconds}
05/14/2023 11:40:47 - @{time=2 Milliseconds}
05/14/2023 11:40:48 - @{time=3 Milliseconds}
05/14/2023 11:40:49 - @{time=2 Milliseconds}
05/14/2023 11:40:50 - @{time=3 Milliseconds}
05/14/2023 11:40:51 - @{time=2 Milliseconds}
05/14/2023 11:40:52 - @{time=7 Milliseconds}
05/14/2023 11:40:53 - @{time=14 Milliseconds}
05/14/2023 11:40:54 - @{time=5 Milliseconds}
05/14/2023 11:40:55 - @{time=2 Milliseconds}
05/14/2023 11:40:56 - @{time=8 Milliseconds}
05/14/2023 11:40:58 - @{time=3 Milliseconds}

PS C:\WINDOWS\system32>

SteveITS

@carpet

DNS resolver is configured to forward queries to an external DNS server if neccessary.

It either forwards or doesn’t. I’m not aware of a way to forward as a fallback. It should cache answers though and I’d expect local LAN traffic should be ~1ms.

You might check the last few messages in https://forum.netgate.com/topic/178413/major-dns-bug-23-01-with-quad9-on-ssl/140 seems there’s a bug in unbound with ASLR enabled in FreeBSD 14.

carpet

@steveits

thank you for this information!

I'm not sure if this problem is related to my topic.
I'm encountering high delays for lookups of local ressources - and in my testing environment pfsense has no WAN connection but still the delays.

about forwarding:
As I understand unbound uses it's local cache for lookups - if a ressource is not cached it uses the external DNS resolver(s) configured in the general tab of pfsense.
The cache is built from static DHCP mappings + former queries. (+ DHCP leases if you checked this box - I did not!)
Former queries will be kept in cache for the period defined under "Advanced Options" -> Minimum TTL... (see pic)
Restarting unbound empties the cache.
So changing ASLR setting should not change the handling of cached ressources (in my eyes)
Please help me if I'm wrong with that! :)

johnpoz

@carpet I wish I had a sg1100 to test with..

But couple of thoughts - is it possible you have something else bombing your dns.. Like iot devices? I had an issue with my isp a while back and was down for like a day.. In that time my alexas where pretty much dosing my dns - in the 24 hour period they were asking for the same shit over and over again - like 2.6 million queries each, I have 4 of them in the house.. While was trying to access anything while my internet was down - I have to believe this would of caused me some slowness in trying to resolve even local stuff..

Even with working dns, since I block stuff devices love to hammer over and over again trying to resolve that thing I block.

Here is a test I would do - turn off the pfblocker, and make sure its 1000 or 10 or even 100's of thousands of entries are not being loaded into unbound.. Remove that load thing in your custom options box. Wouldn't be a bad test to turn off forwarding completely for testing, and make sure your hitting pfsense IP directly without any redirect firewall rule natting the traffic to loopback..

Now do your test.. Also check to make sure your not getting lots of queries from something else on your network while your doing your test..

Once you restart your unbound, you can check what number of queries your seeing via stats

unbound-control -c /var/unbound/unbound.conf stats

carpet

@johnpoz

I'm sure that there is no spamming (because this was also my first thought and I checked that).

And please remember the problem also occurs at my testing environment with nothing connected not even WAN uplink.

@johnpoz said in Unbound DNS resolver - high latency at resolution of local mappings:

Here is a test I would do - turn off the pfblocker, and make sure its 1000 or 10 or even 100's of thousands of entries are not being loaded into unbound.. Remove that load thing in your custom options box. Wouldn't be a bad test to turn off forwarding completely for testing, and make sure your hitting pfsense IP directly without any redirect firewall rule natting the traffic to loopback..
Now do your test.. Also check to make sure your not getting lots of queries from something else on your network while your doing your test..
Once you restart your unbound, you can check what number of queries your seeing via stats
unbound-control -c /var/unbound/unbound.conf stats

I will go for this and post my results.

Thank you very much for your support until now!

oh btw. I opened a case at TAC Lite and requested the image for +22.05 - if everything else doesn't work - this will be my last option - maybe i will give my old zotac zbox a try with +23.01...

SteveITS

@carpet Without rereading the long thread they tied the FreeBSD bug to slow queries. Agree it makes little sense unless the coding maybe assumes memory locations and somehow fails or retries without crashing but I didn’t write it. :)

If forwarding is enabled then the settings/general list is used. If not enabled then it will use the root DNS servers to do lookups directly.

If you are querying info from registered DHCP leases or host or domain overrides it should do neither. If it can’t find info locally it will presumably try to connect out and time out.

carpet

@steveits
thank you for this explanation!

@johnpoz
after a lot of testing I'm now sure my problems are realted to pfblockerng blacklists.
I do not understand why local DNS entries are checked against pfblocker blacklists with unbound.... but I hope I find a way to change this behaviour.

Please handle this topic as closed!
Thanks for your help!

johnpoz

@carpet said in Unbound DNS resolver - high latency at resolution of local mappings:

I do not understand why local DNS entries are checked against pfblocker blacklists with unbound

You understand how it blocks is it creates local entries for say baddomain.tld points to 127.0.0.1

If you have 10,000 entries in your local db, then looking for fw01.localdomain takes a bit longer.. vs looking through 100 records..

carpet

@johnpoz said in Unbound DNS resolver - high latency at resolution of local mappings:

@carpet said in Unbound DNS resolver - high latency at resolution of local mappings:

I do not understand why local DNS entries are checked against pfblocker blacklists with unbound

You understand how it blocks is it creates local entries for say baddomain.tld points to 127.0.0.1

If you have 10,000 entries in your local db, then looking for fw01.localdomain takes a bit longer.. vs looking through 100 records..

I understand now.
I expected unbound only checking blacklists as a second step (and not creating these entries at the same level)