pfSense 2.7 DNS Resolver doesn't start
-
@Gertjan Thanks for your help. I'm not sure what to look for in /var/log/system.log, as I see no obvious errors. I so see these entries around every reboot, but nothing has changed regarding IPv6 to my connection (there is no IPv6...) There is nothing error-related around reboot in /var/log/resolver.log either.
Jul 7 14:50:35 pfSense php-cgi[433]: rc.bootup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6' Jul 7 14:50:35 pfSense kernel: done. Jul 7 14:50:36 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:37 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:38 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:39 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:40 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:41 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:42 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:43 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:44 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:45 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c. Jul 7 14:50:47 pfSense php-cgi[433]: rc.bootup: sync unbound done.More worryingly, today Unbound just stopped randomly, with these entries in /var/log/resolver.log
Jul 27 11:36:43 pfSense unbound[55305]: [55305:0] info: service stopped (unbound 1.17.1). Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 0: 217676 queries, 205849 answers from cache, 11827 recursions, 85435 prefetch, 0 rejected by ip ratelimiting Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 0: requestlist max 27 avg 0.457507 exceeded 0 jostled 0 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: average recursion processing time 0.117910 sec Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: histogram of recursion processing times Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: [25%]=0.00668812 median[50%]=0.0199249 [75%]=0.0507544 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: lower(secs) upper(secs) recursions Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000000 0.000001 1300 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000064 0.000128 1 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000128 0.000256 1 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000512 0.001024 4 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.001024 0.002048 4 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.002048 0.004096 96 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.004096 0.008192 2439 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.008192 0.016384 1558 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.016384 0.032768 2295 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.032768 0.065536 2096 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.065536 0.131072 1156 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.131072 0.262144 348 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.262144 0.524288 166 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.524288 1.000000 115 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 1.000000 2.000000 73 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 2.000000 4.000000 87 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 4.000000 8.000000 34 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 8.000000 16.000000 18 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 16.000000 32.000000 7 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 1: 238090 queries, 227071 answers from cache, 11019 recursions, 80655 prefetch, 0 rejected by ip ratelimiting Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 1: requestlist max 32 avg 0.452058 exceeded 0 jostled 0 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: average recursion processing time 0.121988 sec Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: histogram of recursion processing times Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: [25%]=0.00714891 median[50%]=0.0223932 [75%]=0.0535574 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: lower(secs) upper(secs) recursions Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000000 0.000001 1176 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000128 0.000256 1 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.000512 0.001024 1 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.001024 0.002048 4 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.002048 0.004096 88 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.004096 0.008192 1985 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.008192 0.016384 1425 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.016384 0.032768 2233 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.032768 0.065536 2105 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.065536 0.131072 1205 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.131072 0.262144 318 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.262144 0.524288 140 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 0.524288 1.000000 101 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 1.000000 2.000000 77 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 2.000000 4.000000 80 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 4.000000 8.000000 38 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 8.000000 16.000000 12 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 16.000000 32.000000 8 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: 32.000000 64.000000 1 Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] notice: Restart of unbound 1.17.1. Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] fatal error: Could not read config file: /unbound.conf. Maybe try unbound -dd, it stays on the commandline to see more errors, or unbound-checkconfThe logs indicate Unbound is being restarted, but it just seems to hang instead. The service appears as stopped, and requires a manual start.
-
Remember this one :
@SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:
I'm not using DHCP, it's disabled, unbound working in resolve mode.
I saw what you saw :
Jul 7 14:50:36 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:37 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:38 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:39 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:40 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:41 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:42 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:43 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:44 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul 7 14:50:45 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.So, - ok, silly joke, you are using DHCP.
First line : rc.bootup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
dhcp6c is the client process, normally activated on WAN interface, so it can deliver IPv6 info to the system, like a IPv6 gateway, IP, DNS, and prefixes.
dhcp6c fails, that's for sure.
What about : on your WAN interface : set
and call it a day.
Or : ask pfSense / dhcp6c what's up.
Start by :System > Advanced > Networking and check "DHCP6 Debug".
From now on, in the DHCP log you'll see what happens, what the dhcpv6 has to say.
-
@Gertjan Perhaps @SergBrNord does not use DHCP, I do and never claimed otherwise :)
My WAN interface indeed had 'DHCP6' set as 'IPv6 Configuration Type', but in System/Advanced/Networking 'Allow IPv6' was unchecked (= disabled). Setting 'IPv6 Configuration Type' to 'None' fixes the issue of Unbound not starting at boot, I'll monitor for random halts. Interesting that this has not been an issue up until 2.7, my config did not change.
-
This post is deleted! -
Cheered too early, just had another random crash of Unbound. Digging deeper into the logs, it seems that an OpenVPN client instance may be involved. Look at the timing:
/var/log/openvpn.log
Jul 31 17:57:50 pfSense openvpn[6398]: [{OpenVPN server name}] Inactivity timeout (--ping-restart), restarting Jul 31 17:57:50 pfSense openvpn[6398]: SIGUSR1[soft,ping-restart] received, process restarting Jul 31 17:57:50 pfSense openvpn[6398]: Restart pause, 1 second(s)/var/log/resolver.log
Jul 31 17:58:57 pfSense unbound[77815]: [77815:0] info: service stopped (unbound 1.17.1).So OpenVPN initiates a restart, and a few seconds later Unbound crashes. I'm not using the OpenVPN server provided DNS servers (Pull DNS disabled), and the connection is set to IPv4 only Any ideas on this combo @Gertjan ?
-
@TampertK if your unbound outbound interfaces is set to all, then the restart of any of your interfaces can cause a problem with unbound that is bound to that interface.
Just use localhost as the only outbound interface. Should remove any care if some other interface resets for any reason.
-
@johnpoz Thanks for the suggestion. The outgoing interface was set to WAN, now changed to localhost. Nothing about my configuration has changed between 2.6 and 2.7, so I can't help but feel that this is a bug or regression of some sort.
-
Just checking : you don't have the pfSense watchdog package loaded and activated for unbound ?
If so, don't.Not using IPv6, and have dhcpv6 trying to get an IPv6 (and if it does work out, this will impact the WAN interface).
So, as proposed : set dhcpv6 to none.You are using the OpenVPN client - and it is ordered to "ping-restart" == when ping loss, it will restart the connection.
If unbound uses this VPN connection as an outgoing connection == WAN to upstream DNS servers, then unbound will restart. This means that a 'bad' upstream' connection will influence the uptime of unbound.
You've set unbound outgoing to 'localhost'. This doesn't mean unbound doesn't use whatever route is available to the internet (straight WAN or VPN routed WAN) , as 'localhost' won't offer any upstream DNS servers.What device is this ? bare bone ? VM ? Netgate device, Intel or AMD ?
-
@Gertjan Watchdog package is not installed.
As per your earlier suggestion, I set 'IPv6 Configuration Type' on WAN to 'None'. This resolved Unbound not starting at boot, but did not resolve Unbound crashing randomly.
Unbound did not use the OpenVPN client as outgoing connection, only WAN was selected under 'Outgoing Network Interfaces'. Per @johnpoz 's suggestion I've now set this to 'localhost'.
My pfSense installation is running in ESXi 8, on a Dell 5070. The NICs (Intel X520) are passed through to the VM. But again, nothing has changed to the hardware or hypervisor between my 2.6 and 2.7 installations.
-
Hi, I believe I'm seeing a somewhat similar unbound issue.
Unbound goes for a restart but does not complete the reload. This happens roughly once a week and appears to be random in terms of the time.Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: lower(secs) upper(secs) recursions Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.008192 0.016384 1 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.016384 0.032768 3 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.032768 0.065536 6 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.065536 0.131072 14 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.131072 0.262144 8 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.262144 0.524288 7 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 0.524288 1.000000 1 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: 1.000000 2.000000 1 Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: Restart of unbound 1.17.1. Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: init module 0: validator Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: init module 1: iterator Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: start of service (unbound 1.17.1). Aug 12 07:55:31 pfSense unbound[26068]: [26068:1] info: generate keytag query _ta-4f66. NULL IN Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: service stopped (unbound 1.17.1). Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: server stats for thread 0: 1850 queries, 788 answers from cache, 1062 recursions, 0 prefetch, 0 rejected by ip ratelimit ing Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: server stats for thread 0: requestlist max 56 avg 4.08569 exceeded 0 jostled 0 Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: average recursion processing time 0.239038 sec Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: histogram of recursion processing timesHere we can see that unbound restarted at 07:53:44 but appears to have incompletely loaded.
Interestingly the Service Status widget on the dashboard was showing that unbound was running/green-ticked.
I manually restarted the service at 10:03 and it came up ok.I have OpenVPN, but there are no log entries since the 9th Aug, so it's not similar to @TampertK 's logs.
I did have IPV6 Configuration Type set to DHCP6 on the WAN interface, I have changed that to None now.The system is an ALIX apu2e4 with 2.7.0-RELEASE.
-
Oh I've cursed it now! Failed again at 11:03:45!
In the combined grep-log below I do see a HUP coming from dhcpd at 11:03:42, then the service fails to load afterwards...[2.7.0-RELEASE][root@pfSense.homenet.local]/var/log: grep -r -n . -i -e "Aug 12 11:03:4" ./filter.log:338:Aug 12 11:03:40 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,3949,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76 ./filter.log:339:Aug 12 11:03:41 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,245,62789,0,none,6,tcp,40,79.124.62.86,109.255.17.211,58350,16502,0,S,2150868192,,1024,, ./filter.log:340:Aug 12 11:03:42 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4249,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76 ./filter.log:341:Aug 12 11:03:43 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4546,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76 ./filter.log:342:Aug 12 11:03:44 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,51,34872,0,none,17,udp,132,92.178.111.50,109.255.17.211,49732,33737,112 ./filter.log:343:Aug 12 11:03:45 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4831,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76 ./dhcpd.log:5693:Aug 12 11:03:42 pfSense dhcpleases[64065]: Sending HUP signal to dns daemon(47791) ./resolver.log:4636:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: service stopped (unbound 1.17.1). ./resolver.log:4637:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 0: 145 queries, 10 answers from cache, 135 recursions, 0 prefetch, 0 rejected by ip ratelimiting ./resolver.log:4638:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 0: requestlist max 13 avg 0.488889 exceeded 0 jostled 0 ./resolver.log:4639:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.158614 sec ./resolver.log:4640:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times ./resolver.log:4641:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0383535 median[50%]=0.0945591 [75%]=0.197778 ./resolver.log:4642:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions ./resolver.log:4643:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.000000 0.000001 7 ./resolver.log:4644:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.008192 0.016384 5 ./resolver.log:4645:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.016384 0.032768 18 ./resolver.log:4646:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.032768 0.065536 22 ./resolver.log:4647:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.065536 0.131072 35 ./resolver.log:4648:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.131072 0.262144 28 ./resolver.log:4649:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.262144 0.524288 12 ./resolver.log:4650:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.524288 1.000000 6 ./resolver.log:4651:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 1.000000 2.000000 2 ./resolver.log:4652:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 1: 95 queries, 7 answers from cache, 88 recursions, 0 prefetch, 0 rejected by ip ratelimiting ./resolver.log:4653:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 1: requestlist max 10 avg 0.443182 exceeded 0 jostled 0 ./resolver.log:4654:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.222569 sec ./resolver.log:4655:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times ./resolver.log:4656:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0512 median[50%]=0.123362 [75%]=0.297097 ./resolver.log:4657:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions ./resolver.log:4658:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.000000 0.000001 7 ./resolver.log:4659:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.016384 0.032768 6 ./resolver.log:4660:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.032768 0.065536 16 ./resolver.log:4661:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.065536 0.131072 17 ./resolver.log:4662:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.131072 0.262144 18 ./resolver.log:4663:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.262144 0.524288 15 ./resolver.log:4664:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.524288 1.000000 7 ./resolver.log:4665:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 1.000000 2.000000 1 ./resolver.log:4666:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 2.000000 4.000000 1 ./resolver.log:4667:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 2: 148 queries, 11 answers from cache, 137 recursions, 0 prefetch, 0 rejected by ip ratelimiting ./resolver.log:4668:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 2: requestlist max 12 avg 0.423358 exceeded 0 jostled 0 ./resolver.log:4669:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.169696 sec ./resolver.log:4670:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times ./resolver.log:4671:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0385707 median[50%]=0.102085 [75%]=0.221432 ./resolver.log:4672:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions ./resolver.log:4673:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.000000 0.000001 11 ./resolver.log:4674:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.008192 0.016384 3 ./resolver.log:4675:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.016384 0.032768 16 ./resolver.log:4676:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.032768 0.065536 24 ./resolver.log:4677:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.065536 0.131072 26 ./resolver.log:4678:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.131072 0.262144 33 ./resolver.log:4679:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.262144 0.524288 16 ./resolver.log:4680:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.524288 1.000000 6 ./resolver.log:4681:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 1.000000 2.000000 2 ./resolver.log:4682:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 3: 211 queries, 19 answers from cache, 192 recursions, 0 prefetch, 0 rejected by ip ratelimiting ./resolver.log:4683:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 3: requestlist max 6 avg 0.322917 exceeded 0 jostled 0 ./resolver.log:4684:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.146060 sec ./resolver.log:4685:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times ./resolver.log:4686:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0295969 median[50%]=0.0855609 [75%]=0.2046 ./resolver.log:4687:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions ./resolver.log:4688:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.000000 0.000001 17 ./resolver.log:4689:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.008192 0.016384 6 ./resolver.log:4690:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.016384 0.032768 31 ./resolver.log:4691:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.032768 0.065536 31 ./resolver.log:4692:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.065536 0.131072 36 ./resolver.log:4693:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.131072 0.262144 41 ./resolver.log:4694:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.262144 0.524288 22 ./resolver.log:4695:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 0.524288 1.000000 6 ./resolver.log:4696:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: 1.000000 2.000000 2 ./resolver.log:4697:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: Restart of unbound 1.17.1. ./resolver.log:4698:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: init module 0: validator ./resolver.log:4699:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: init module 1: iterator ./resolver.log:4700:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: start of service (unbound 1.17.1). ./resolver.log:4701:Aug 12 11:03:45 pfSense unbound[47791]: [47791:0] info: generate keytag query _ta-4f66. NULL INAny clues?
-
Any update on this? I was having the same issue and trying to find a way to fix it but still failed to.
-
@LastOfTheRonnies said in pfSense 2.7 DNS Resolver doesn't start:
I do see a HUP coming from dhcpd at 11:03:42
You're close
This is the one :@LastOfTheRonnies said in pfSense 2.7 DNS Resolver doesn't start:
pfSense dhcpleases[64065]: Sending HUP signal to dns daemon(47791)
'some one' has checked the option "Register DHCP ...." under the Resolver settings.
So, whenever a DHCP lease comes in or is renew, your unbound resolver gets shot (sorry : restarted).
Btw : "dhcpleases" asks for a restart, not a stop.
If your unbound won't restart any more then ... dono why ( maybe it was getting getting tired of being restarted all the time ? )Anyway : now you know what to do.
Btw : I just discovered that these options do not exist any more under 23.09, so they probably wont exist any more under the upcoming 2.7.1.
-
@Gertjan
Hi, yes I selected to register DNS names as I needed it for mDNS functionality with IOT devices. I moved to a Technitium DNS server instead, setting PFSense to forward, and it has been stable ever since (and I get pretty little graphs and better DNS management as a bonus).So the option to register DNS on lease creation or renewal has now been removed? So how does local DNS work then if it's gone?
-
@LastOfTheRonnies said in pfSense 2.7 DNS Resolver doesn't start:
needed it for mDNS functionality
Think you might need to relook up how mdns works ;)
https://en.wikipedia.org/wiki/Multicast_DNS
the multicast DNS (mDNS) protocol resolves hostnames to IP addresses within small networks that do not include a local name server.
When an mDNS client needs to resolve a hostname, it sends an IP multicast query message that asks the host having that name to identify itself. That target machine then multicasts a message that includes its IP address. All machines in that subnet can then use that information to update their mDNS caches.
-
@johnpoz Hmm - fair enough point. .local name resolution was what I was looking for rather than mDNS discovery specifically.
But the point stands: I should be able to register hostnames on DHCP register leases/renewals without the service dumping and not restarting, right? -
@LastOfTheRonnies said in pfSense 2.7 DNS Resolver doesn't start:
I should be able to hostnames on DHCP register leases/renewals without the service dumping and not restarting, right?
That has been an issue with pfsense and unbound for very long time. While you can register dhcp, it forces a restart of unbound. Depending on how many clients you have, how often you have clients renew there lease it may not be a problem for you.
How fast your unbound restarts, also comes into play.
One solution is to just set a reservation for your devices, so they will always get the same IP. And just register these static/reservations which are only loaded when unbound starts.. So there are no restarts that happen every time a client renews a lease.
There is some hope that with the move to KEA vs isc dhcp that this issue will go away. But Kea is not yet fully functional, it is in preview mode and many features are not yet implemented in pfsense.
.local name resolution
if your trying to use that with your normal dns, your doing it wrong to start with. .local is really only for use with mdns.. Use some other domain, home.apra is the recommended/approved domain to use for local dns..
I use local.lan, but slowing moving away from that to home.arpa
-
@johnpoz Ok, thanks for the pointers & education. I do have static reservations for ~98% of my devices. The issue only started once I updated from 2.6.x to 2.7.0.
-
@LastOfTheRonnies what issue exactly? There is not any issues that I am aware of with dns registration of reservations in 2.7..
-
@johnpoz said in pfSense 2.7 DNS Resolver doesn't start:
what issue exactly?
@LastOfTheRonnies said in pfSense 2.7 DNS Resolver doesn't start:
Unbound goes for a restart but does not complete the reload.
