pfSense resolver stops working

Gertjan

@johnpoz said in pfSense resolver stops working:

The traffic between

Correct. DNSSEC traffic is send over the wire in clear.
But it's the "check the crypting", the check of hashes, signing keys etc that makes me think : is the same openssl library used ? Guess so : https://www.cloudflare.com/dns/dnssec/dnssec-complexities-and-considerations/
And if so, is openssl using hardware for this, if aviable ? The same hardware it uses for "AES" TLS etc.

maverickws

@johnpoz said in pfSense resolver stops working:

@maverickws if your saying its running, but not responding..

So when you query directly, you get a timeout, NX, refused? Do you have unbound using what interfaces - did you have an interface go down, like wan or vpn, or whatever?

It resolves nothing, not pfsense own name? Or local - or doesn't resolve public stuff like google.com?

example I just send a empty query to unbound from my pc, and I get back roots.. Your saying this fails? With what error, timeout?

Alright so back to the issue again. It happened again yesterday at local time 17:46 GMT +1 (daylight savings) - Not resolving.

In the meanwhile it recovered and I waited until it failed again.
Today it didn't recover, I had to restart the unbound service manually, and before I did all of the remaining tests.

DNS Resolver System logs. Yesterday had no entries since 16:50 (issue occurred at ~17:45) and today no entries on the log since 10:35 and the issue occurred after 12h00). No start/stops;
Last of process dhcpleases is also of 16:50, today of 10:36;
No interface changes or other issues within the timeframe where the issue started occurring, let's say the last 20 minutes;

Last entries on resolver log:


Time	Process	PID	Message
Jul 26 16:50:08	unbound	94538	[94538:0] info: generate keytag query _ta-4f66. NULL IN
Jul 26 16:50:07	unbound	94538	[94538:0] info: start of service (unbound 1.15.0).
Jul 26 16:50:07	unbound	94538	[94538:0] notice: init module 1: iterator
Jul 26 16:50:07	unbound	94538	[94538:0] notice: init module 0: validator
Jul 26 16:50:07	unbound	94538	[94538:0] notice: Restart of unbound 1.15.0.

On the general log:


Time	Process	PID	Message
Jul 26 17:36:00	sshguard	75200	Now monitoring attacks.
Jul 26 17:36:00	sshguard	67697	Exiting on signal.
Jul 26 17:10:00	sshguard	67697	Now monitoring attacks.
Jul 26 17:10:00	sshguard	26927	Exiting on signal.

When I do dig to the interface CARP VIP without any query:

# dig @10.0.0.254

; <<>> DiG 9.11.36-RedHat-9.11.36-3.el8 <<>> @10.0.0.254
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 45328
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 13, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1332
;; QUESTION SECTION:
;.				IN	NS

;; ANSWER SECTION:
.			83046	IN	NS	j.root-servers.net.
.			83046	IN	NS	k.root-servers.net.
.			83046	IN	NS	l.root-servers.net.
.			83046	IN	NS	m.root-servers.net.
.			83046	IN	NS	a.root-servers.net.
.			83046	IN	NS	b.root-servers.net.
.			83046	IN	NS	c.root-servers.net.
.			83046	IN	NS	d.root-servers.net.
.			83046	IN	NS	e.root-servers.net.
.			83046	IN	NS	f.root-servers.net.
.			83046	IN	NS	g.root-servers.net.
.			83046	IN	NS	h.root-servers.net.
.			83046	IN	NS	i.root-servers.net.

;; Query time: 1 msec
;; SERVER: 10.0.0.254#53(10.0.0.254)
;; WHEN: Tue Jul 26 17:46:02 WEST 2022
;; MSG SIZE  rcvd: 239

When I do the dig with a query:

# dig @10.0.0.254 google.com

; <<>> DiG 9.11.36-RedHat-9.11.36-3.el8 <<>> @10.0.0.254 google.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 10156
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1332
;; QUESTION SECTION:
;google.com.			IN	A

;; Query time: 0 msec
;; SERVER: 10.0.0.254#53(10.0.0.254)
;; WHEN: Tue Jul 26 17:47:28 WEST 2022
;; MSG SIZE  rcvd: 39

So the error is SERVFAIL.

If the query has a fqdn of the internal domain, it returns the results successfully without any error. (NOERROR) So it does resolves locally.

result of nslookup

# nslookup stackoverflow.com
;; Got SERVFAIL reply from PUB.LIC.DNS.SV0, trying next server
;; Got SERVFAIL reply from PUB.LIC.DNS.SV1, trying next server
Server:		10.0.0.254
Address:	10.0.0.254#53

** server can't find stackoverflow.com: SERVFAIL

After restarting unbound it starts working again.
I have no stopped/started messages anywhere near the time it stops working.

EDIT:
In the meanwhile I disabled the Register DHCP Leases option on the Resolver to see how it goes.
But while looking for possible causes behind this, I found this blog article and also got me thinking that, in fact, the issue occurs with domain names that have many CNAME records, as google, stripe, stackoverflow, etc. But really dunno. Just trying to look everywhere to see if the culprit is found.

This is causing us major concerns as, for example, customers try to login to websites on servers behind this pfSense, and if the server can't resolve google for the recaptcha - people can't login, if it can't resolve stripe, we get payments issues, so this is creating a bit of a grief.

EDIT2:
I just remembered one of the issues that occur is with our email server, and that record is an A Record not a CNAME so what I mentioned before must be unrelated.

johnpoz

@maverickws said in pfSense resolver stops working:

So it does resolves locally

This is good info, so unbound is running and can resolve locally - so the trick here is figuring out why servfail on specific domains or fqdns

Not sure exactly what this is

;; Got SERVFAIL reply from PUB.LIC.DNS.SV0, trying next server
;; Got SERVFAIL reply from PUB.LIC.DNS.SV1, trying next server

To me that reads that your forwarding, and where your forwarding sent back fail.

Did you obfuscate the server IP or something with that? Who exactly got asked that reported servfail?

Or is that just the client saying hey I asked these 2 servers and they both reported servfail - and what are those 2 servers?

maverickws

@johnpoz its obfuscation of server IP.

The records obfuscated correspond to the pfSense's CARP WAN VIP and CARP DMZ VIP.

On the DHCP Server options, beside only having static leases, we use those IP's as DNS servers (instead of using the LAN CARP VIP, which would be something alike 10.0.0.254).

On normal conditions (like now, it recovered after the manual restart to unbound) it works normally and resolves without issues.

johnpoz

@maverickws ok that makes more sense ;)

So when it fails like that with servfail - all things you try fail, or does anything work?

Problem with servfail is its sort of a catchall - and isn't specific in what exactly failed.. But knowing that local resources are resolving tells us unbound didn't go full belly up.

Might help to up the verbosity of the unbound logs all the way, but that can be a lot of logging ;)

I have a 3100 sitting here in a box.. I am thinking of firing it up, and then running some dnsperf testing on it, say have it run through million different queries at like 100 queries a second or something, and then loop that to see if can cause failure.. There are sample files you can download that have 10million records in them to lookup..

hmmmm - need to check my cal to what real work is going to be like today ;)

bmeeks

Here is my suspicion about the unbound problems.

pfSense is currently running the 1.15.0 version of unbound in the RELEASE branches. That version has a bug that is discussed at length here: https://github.com/NLnetLabs/unbound/issues/670. That bug should be fixed in the latest unbound package version (which is 1.16.1).

FreeBSD ports has the most recent unbound version (1.16.1). Because unbound is a built-in package within pfSense, I don't think it is easy for them to push an update unless they change the pfSense version.

And just to be clear, turning on the "Register DHCP Leases" option is also problematic because it results in a ton of unbound restarts. While updating to the latest unbound version, I would also like to see the Netgate team fix the "Register DHCP Leases" option so that it works properly and does not restart the resolver with each lease renewal.

maverickws

This post is deleted!

maverickws

@johnpoz sorry for not being clearer!

Ok so I'm not sure what is your question when you say

So when it fails like that with servfail - all things you try fail, or does anything work?

What things you mean? Usually it goes like we start catching some errors like captcha stops working or API connection to stripe stops, also our mail server sends warnings on failed resolutions, so we get about that occurrence.
We then login to our jump box and to the server where the errors come from, could be a web server or the mail server or other, eg. yesterday I was testing on the webserver and jump box and today I was testing on the mail server. On that regard these are VM's, and the hosts where these VM's sit are maybe a thousand clicks apart, the host with the webserver VM is at a DC in Germany, the jumpbox is on one DC in Scandinavia, and the mail server is also in Scandinavia but on another DC room.

Since I've disabled the DHCP leases option, haven't had any more hiccups.

EDIT:
@bmeeks 's comment and issue do seem very to the point.

Gertjan

@maverickws said in pfSense resolver stops working:

the pfSense's CARP WAN VIP and CARP DMZ VIP.
....
dig @10.0.0.254 google.com
....
Server: 10.0.0.254
Address: 10.0.0.254#53

This 10.0.0.254 is a virtual or 'software' defined interface ?
( I never used VIP or CARP stuff )

While failing, what happens when you do the mighty :

dig @127.0.0.1 google.com

I recall (a couple of years ago) seeing on my own pfSense that "127.0.0.1" didn't exist any more.
That was bad.
I wasn't unbound's fault, and unbound didn't like this situation that all.
I, as an admin, could still 'dig' using any of my LAN IP interfaces.
I didn't know what killed 127.0.0.1, had to reboot.

@bmeeks That bug report was already mentioned no so long ago.
My thoughts : It is an OpenBSD 7 compiled version.
The fact that "OpenBSD" is mentioned here, means that it is OpenBSD related ?
One of the unbound coders is posting : wouldn't he know that it could be an "any OS issue" ?

The patch goes into iterator/iterator.c : that, for me, the core of the resolver.

Btw : the patch :

The green 'added' code :

	iter_mark_cycle_targets(qstate, iq->dp);
	missing = (int)delegpt_count_missing_targets(iq->dp);
	log_assert(maxtargets != 0); /* that would not be useful */

	/* Generate target requests. Basically, any missing targets
	 * are queried for here, regardless if it is necessary to do
	 * so to continue processing. */
	if(maxtargets < 0 || maxtargets > missing)
		toget = missing;
	else	toget = maxtargets;
	if(toget == 0) {
		*num = 0;
		return 1;
	}

The removed "red" code

	iter_mark_cycle_targets(qstate, iq->dp);
	missing = (int)delegpt_count_missing_targets(iq->dp);
	log_assert(maxtargets != 0); /* that would not be useful */

	/* Generate target requests. Basically, any missing targets 
	 * are queried for here, regardless if it is necessary to do 
	 * so to continue processing. */
	if(maxtargets < 0 || maxtargets > missing)
		toget = missing;
	else	toget = maxtargets;
	if(toget == 0) {
		*num = 0;
		return 1;
	}

The WTF part : both are identical to me.
That's what I call a NOP.

johnpoz

@maverickws Yeah I concur with @bmeeks unbound should be updated if there is known issues in the 1.15 that could cause failure, even if not directly related. Any sort of issues that could cause failure

From that thread, makes mention of

do-ip6: no

And that user unable to reproduce the problem... That could be something you could try.. Its easy enough to add to the custom options box.

What I meant with my question is while you do mention a few domains fail.. Is nothing resolving, do cached entries still work I take it.. When you were testing and seeing servfail - did anything respond, or everything nonlocal you tried was servfail. You can always look in the cache - if there is issue with resolving but cache still works, that is just another piece of the puzzle that could be helpful.

bmeeks

@gertjan:
The new code is added to the source file up higher. That code is a type of "limit check". It is called earlier in the revised code than it was in the v1.15.0 code.

It now makes its test earlier in the processing logic. That is the "fix" for the bug.

maverickws

@johnpoz we do have ipv6 enabled we can look at that but ... not ideal.

Please tell me how do we proceed from here to get in touch with Netgate to urge for a patch on the OS to update unbound? It would be nice to get someone's attention to the matter.

Right now even having the register dhcp leases option disabled, unbound failed again. I'll take a look into the no-ip6 option now and see if it helps.

EDIT:
@gertjan sorry I missed your reply!!

Ok I'll make that test once it fails again. I'll hold the no-ip6 option for a while and will get back to the dig to localhost on the pfSense

This 10.0.0.254 is a virtual or 'software' defined interface ?
( I never used VIP or CARP stuff )

The 10.0.0.254 is a Virtual IP type "CARP" on interface LAN network 10.0.0.0/24. the primary pfSense is 10.0.0.1 and the secondary is 10.0.0.2. To ensure traffic continuity, this VIP is used as Gateway and DNS Resolver on the DHCP options for machines that connect to the LAN interface.

maverickws

This post is deleted!

johnpoz

@maverickws said in pfSense resolver stops working:

we do have ipv6 enabled we can look at that but ... not ideal.

keep in mind, that doesn't turn off ipv6 - it just tells unbound to not resolve using IPv6..

maverickws

@johnpoz I know I know! Its just in the sense that if it is a feature (and crucial on ipv6 only networks - but that isn't the case here) and we're disabling it. So ideal would be not having to do so.

I'm just waiting it to blow again to do the dig against localhost as asked by @Gertjan

ik13

@gertjan said in pfSense resolver stops working:

Without any proof, I think that arm based devices are more sensible to this issues.
@ik13 : arm or intel ?
Intel

maverickws

@Gertjan

[22.05-RELEASE][root@pf.net]/root: dig @127.0.0.1 stackoverflow.com A

; <<>> DiG 9.16.26 <<>> @127.0.0.1 stackoverflow.com A
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 63882
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1332
;; QUESTION SECTION:
;stackoverflow.com.		IN	A

;; Query time: 0 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Wed Jul 27 20:22:50 WEST 2022
;; MSG SIZE  rcvd: 46

So logged in as root on the pfSense and doing the dig against localhost also returns SERVFAIL.
BTW the CPU here is also x86_64.

johnpoz

@maverickws but local resources resolve, does anything work that is remote - check whats in your cache and try and query something that is currently cached.

maverickws

@johnpoz ah man I just restarted the service ;_;

will check that out tomorrow. in the meanwhile, and seriously, what would be a reasonable expectation for the unbound version to be bumped on a patch release?

maverickws

@johnpoz good morning guys,

So this morning we saw the connection to Stripe API failing. Tests from the pfSense:

[22.05-RELEASE][root@pf.net]/root: dig stripe.com A

; <<>> DiG 9.16.26 <<>> stripe.com A
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 48056
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1332
;; QUESTION SECTION:
;stripe.com.			IN	A

;; Query time: 0 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jul 28 10:19:09 WEST 2022
;; MSG SIZE  rcvd: 39

[22.05-RELEASE][root@pf.net]/root: nslookup stripe.com
Server:		127.0.0.1
Address:	127.0.0.1#53

** server can't find stripe.com: SERVFAIL

Checked that stackoverflow.com was still on the DNS cache. So if I do that:

[22.05-RELEASE][root@pf.net]/root: dig stackoverflow.com A

; <<>> DiG 9.16.26 <<>> stackoverflow.com A
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 9120
;; flags: qr rd ra; QUERY: 1, ANSWER: 4, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1332
;; QUESTION SECTION:
;stackoverflow.com.		IN	A

;; ANSWER SECTION:
stackoverflow.com.	191	IN	A	151.101.129.69
stackoverflow.com.	191	IN	A	151.101.193.69
stackoverflow.com.	191	IN	A	151.101.65.69
stackoverflow.com.	191	IN	A	151.101.1.69

;; Query time: 0 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jul 28 10:23:13 WEST 2022
;; MSG SIZE  rcvd: 110

[22.05-RELEASE][root@pf.net]/root: nslookup stackoverflow.com
Server:		127.0.0.1
Address:	127.0.0.1#53

Non-authoritative answer:
Name:	stackoverflow.com
Address: 151.101.129.69
Name:	stackoverflow.com
Address: 151.101.193.69
Name:	stackoverflow.com
Address: 151.101.65.69
Name:	stackoverflow.com
Address: 151.101.1.69

I get the answers and no error.

EDIT:
After these last tests I've added the do-ip6: no option to the resolver. So far, we haven't had any more hiccups. Hoping it mitigates the issue until a proper fix is out at least.