Weird issue with unbound using VPN Gateway Group

[Apex]

I'm a recent convert from PFSense to OPNSense. I have run this configuration for years in PFSense, and for about a month the same configuration was working in OPNSense.

I am using 2 unbound servers that are external to OPNsense located on my LAN. I had a firewall rule for any protocol from DNS servers (in a firewall alias) the traffic would be directed to the VPN Gateway group. I have a VPN Gateway Group with 2 Tier 1 connections for load balancing the requests, and for everything else including policy base routing it works just fine.

But for Unbound up until 2 days ago was working the same way. Then out of nowhere I started seeing DNS lookup failures with a status return of SERVFAIL and I'm not sure why.

Even the DNS servers themselves if I do a traceroute, the VPN gateway passes traffic but for Unbound at least according to the Unbound logs it appears to be failing to retrieve a proper response.

Here is the logs, I performed a lookup using the domain name "pickles.com" to make it easier to find in the unbound logs.

[1709696403] unbound[1816:2] info: 1RDdc mod2 rep pickles.com. A IN
[1709696403] unbound[1816:2] debug: cache memory msg=132120 rrset=132120 infra=14229 val=132400 subnet=140552
[1709696403] unbound[1816:2] debug: svcd callbacks end
[1709696403] unbound[1816:2] debug: close of port 45447
[1709696403] unbound[1816:2] debug: close fd 33
[1709696403] unbound[1816:2] debug: answer cb
[1709696403] unbound[1816:2] debug: Incoming reply id = 9021
[1709696403] unbound[1816:2] debug: Incoming reply addr = ip4 192.5.5.241 port 53 (len 16)
[1709696403] unbound[1816:2] debug: lookup size is 1 entries
[1709696403] unbound[1816:2] debug: received udp reply.
[1709696403] unbound[1816:2] debug: udp message[28:0] 902180950001000000000001000002000100002904D0000080000000
[1709696403] unbound[1816:2] debug: outnet handle udp reply
[1709696403] unbound[1816:2] debug: measured roundtrip at 18 msec
[1709696403] unbound[1816:2] debug: svcd callbacks start
[1709696403] unbound[1816:2] debug: worker svcd callback for qstate 0x7f8bbc3311b0
[1709696403] unbound[1816:2] debug: mesh_run: start
[1709696403] unbound[1816:2] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1709696403] unbound[1816:2] info: iterator operate: query . NS IN
[1709696403] unbound[1816:2] debug: process_response: new external response event
[1709696403] unbound[1816:2] info: scrub for . NS IN
[1709696403] unbound[1816:2] info: response for . NS IN
[1709696403] unbound[1816:2] info: reply from <.> 192.5.5.241#53
[1709696403] unbound[1816:2] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: REFUSED, id: 0
;; flags: qr ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
.   IN   NS

;; ANSWER SECTION:

;; AUTHORITY SECTION:

;; ADDITIONAL SECTION:
;; MSG SIZE  rcvd: 17

[1709696403] unbound[1816:2] debug: iter_handle processing q with state QUERY RESPONSE STATE
[1709696403] unbound[1816:2] info: query response was THROWAWAY
[1709696403] unbound[1816:2] debug: iter_handle processing q with state QUERY TARGETS STATE
[1709696403] unbound[1816:2] info: processQueryTargets: . NS IN
[1709696403] unbound[1816:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 32
[1709696403] unbound[1816:2] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (25 result, 0 avail) parentNS
[1709696403] unbound[1816:2] info:   a.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   b.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   c.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   d.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   e.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   f.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   g.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   h.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   i.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   j.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   k.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   l.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] info:   m.root-servers.net. * A AAAA
[1709696403] unbound[1816:2] debug:    ip4 198.41.0.4 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 199.9.14.201 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:200::b port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.33.4.12 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:2::c port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 199.7.91.13 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:2d::d port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.203.230.10 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:a8::e port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.5.5.241 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:2f::f port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.112.36.4 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:12::d0d port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 198.97.190.53 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:1::53 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.36.148.17 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:7fe::53 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 192.58.128.30 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 193.0.14.129 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:7fd::1 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 199.7.83.42 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:500:9f::42 port 53 (len 28)
[1709696403] unbound[1816:2] debug:    ip4 202.12.27.33 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    ip6 2001:dc3::35 port 53 (len 28)
[1709696403] unbound[1816:2] debug: servselect ip4 202.12.27.33 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=302
[1709696403] unbound[1816:2] debug: servselect ip4 199.7.83.42 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=170
[1709696403] unbound[1816:2] debug: servselect ip4 193.0.14.129 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=302
[1709696403] unbound[1816:2] debug: servselect ip4 192.58.128.30 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: servselect ip4 192.36.148.17 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: servselect ip4 192.112.36.4 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: servselect ip4 192.5.5.241 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: servselect ip4 192.203.230.10 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=205
[1709696403] unbound[1816:2] debug: servselect ip4 199.7.91.13 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: servselect ip4 192.33.4.12 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=205
[1709696403] unbound[1816:2] debug: servselect ip4 199.9.14.201 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=205
[1709696403] unbound[1816:2] debug: servselect ip4 198.41.0.4 port 53 (len 16)
[1709696403] unbound[1816:2] debug:    rtt=248
[1709696403] unbound[1816:2] debug: selrtt 170
[1709696403] unbound[1816:2] info: sending query: . NS IN
[1709696403] unbound[1816:2] debug: sending to target: <.> 192.203.230.10#53
[1709696403] unbound[1816:2] debug: dnssec status: expected
[1709696403] unbound[1816:2] debug: EDNS lookup known=1 vs=0
[1709696403] unbound[1816:2] debug: serviced query UDP timeout=205 msec
[1709696403] unbound[1816:2] debug: inserted new pending reply id=4c35
[1709696403] unbound[1816:2] debug: opened UDP if=0 port=13824
[1709696403] unbound[1816:2] debug: comm point start listening 33 (-1 msec)
[1709696403] unbound[1816:2] debug: mesh_run: iterator module exit state is module_wait_reply
[1709696403] unbound[1816:2] info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out
[1709696403] unbound[1816:2] info: 0pvCD mod2  . NS IN
[1709696403] unbound[1816:2] info: 1RDdc mod2 rep pickles.com. A IN
[1709696403] unbound[1816:2] debug: cache memory msg=132120 rrset=132120 infra=14229 val=132400 subnet=140552
[1709696403] unbound[1816:2] debug: svcd callbacks end
[1709696403] unbound[1816:2] debug: close of port 19468
[1709696403] unbound[1816:2] debug: close fd 34
[1709696404] unbound[1816:2] debug: answer cb
[1709696404] unbound[1816:2] debug: Incoming reply id = 4c35
[1709696404] unbound[1816:2] debug: Incoming reply addr = ip4 192.203.230.10 port 53 (len 16)
[1709696404] unbound[1816:2] debug: lookup size is 1 entries
[1709696404] unbound[1816:2] debug: received udp reply.
[1709696404] unbound[1816:2] debug: udp message[28:0] 4C3580950001000000000001000002000100002904D0000080000000
[1709696404] unbound[1816:2] debug: outnet handle udp reply
[1709696404] unbound[1816:2] debug: measured roundtrip at 19 msec
[1709696404] unbound[1816:2] debug: svcd callbacks start
[1709696404] unbound[1816:2] debug: worker svcd callback for qstate 0x7f8bbc3311b0
[1709696404] unbound[1816:2] debug: mesh_run: start
[1709696404] unbound[1816:2] debug: iterator[module 2] operate: extstate:module_wait_reply event:module_event_reply
[1709696404] unbound[1816:2] info: iterator operate: query . NS IN
[1709696404] unbound[1816:2] debug: process_response: new external response event
[1709696404] unbound[1816:2] info: scrub for . NS IN
[1709696404] unbound[1816:2] info: response for . NS IN
[1709696404] unbound[1816:2] info: reply from <.> 192.203.230.10#53
[1709696404] unbound[1816:2] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: REFUSED, id: 0
;; flags: qr ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
.   IN   NS

;; ANSWER SECTION:

;; AUTHORITY SECTION:

;; ADDITIONAL SECTION:
;; MSG SIZE  rcvd: 17

[1709696404] unbound[1816:2] debug: iter_handle processing q with state QUERY RESPONSE STATE
[1709696404] unbound[1816:2] info: query response was THROWAWAY
[1709696404] unbound[1816:2] debug: iter_handle processing q with state QUERY TARGETS STATE
[1709696404] unbound[1816:2] info: processQueryTargets: . NS IN
[1709696404] unbound[1816:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 33
[1709696404] unbound[1816:2] debug: request has exceeded the maximum number of sends with 33
[1709696404] unbound[1816:2] debug: return error response SERVFAIL
[1709696404] unbound[1816:2] debug: mesh_run: iterator module exit state is module_finished
[1709696404] unbound[1816:2] debug: validator[module 1] operate: extstate:module_state_initial event:module_event_moddone
[1709696404] unbound[1816:2] info: validator operate: query . NS IN
[1709696404] unbound[1816:2] debug: validator: nextmodule returned
[1709696404] unbound[1816:2] debug: not validating response, is valrec(validation recursion lookup)
[1709696404] unbound[1816:2] debug: mesh_run: validator module exit state is module_finished


I'm at a bit of a loss to explain this as everything else works except for DNS lookups over the VPN tunnel.

[Apex]

I wanted to provide an update to this thread.

I went and setup another VPN with a different provider (Trying the free option with ProtonVPN). Just wanted to see if there was an issue with my current VPN provider.

As of now all of my DNS traffic is routing over the ProtonVPN tunnel without an issue. So either NordVPN is blocking DNS traffic, or possibly root DNS servers are blocking traffic from NordVPN? I wouldn't think so, but I really don't have much to go on for why it stopped working when everything BUT DNS worked and I point DNS traffic through a different provider its working flawlessly.

[strarsis]

In case this being helpful for others:
I encountered a similar issue where I get REFUSED answers from Unbound DNS server on OpnSense over a VPN network.
This happened only using nslookup on a Windows machine. Finally I found out the reason: nslookup automatically adds the DNS suffix to the domain, e.g. google.com becomes google.com.localdomain. One has to add an additional dot for the apex/DNS root (google.com.) to preven this. However, as I used nslookup with the OpnSense Unbound DNS server IP address as 2nd parameter, the dot at the end of the domain causes issues with nslookup parsing the arguments.