2.1-BETA0 -> 2.1-BETA1 unbound won't install
-
2.1-Beta1(amd64).
Standard Package Install installed Unbound 1.4.20_3, both service and UI, fine. Functioning without issues for a couple of hours.
Thanks Renato and all others involved. Brilliant package - worth waiting for.
-
Something is not quite right yet. It restarts every hour on my system (NanoBSD), at exactly the same time.
Apr 28 14:16:50 unbound: [61715:0] notice: Restart of unbound 1.4.20. Apr 28 14:16:50 unbound: [61715:0] notice: init module 0: validator Apr 28 14:16:50 unbound: [61715:0] notice: init module 1: iterator Apr 28 14:16:50 unbound: [61715:0] info: start of service (unbound 1.4.20). Apr 28 15:16:50 unbound: [61715:0] info: service stopped (unbound 1.4.20). Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 0: 1096 queries, 874 answers from cache, 222 recursions, 23 prefetch Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 0: requestlist max 13 avg 1.2898 exceeded 0 jostled 0 Apr 28 15:16:50 unbound: [61715:0] info: average recursion processing time 0.159908 sec Apr 28 15:16:50 unbound: [61715:0] info: histogram of recursion processing times Apr 28 15:16:50 unbound: [61715:0] info: [25%]=0.0201766 median[50%]=0.0504123 [75%]=0.237086 Apr 28 15:16:50 unbound: [61715:0] info: lower(secs) upper(secs) recursions Apr 28 15:16:50 unbound: [61715:0] info: 0.000000 0.000001 25 Apr 28 15:16:50 unbound: [61715:0] info: 0.002048 0.004096 1 Apr 28 15:16:50 unbound: [61715:0] info: 0.008192 0.016384 17 Apr 28 15:16:50 unbound: [61715:0] info: 0.016384 0.032768 54 Apr 28 15:16:50 unbound: [61715:0] info: 0.032768 0.065536 26 Apr 28 15:16:50 unbound: [61715:0] info: 0.065536 0.131072 16 Apr 28 15:16:50 unbound: [61715:0] info: 0.131072 0.262144 34 Apr 28 15:16:50 unbound: [61715:0] info: 0.262144 0.524288 34 Apr 28 15:16:50 unbound: [61715:0] info: 0.524288 1.000000 13 Apr 28 15:16:50 unbound: [61715:0] info: 1.000000 2.000000 2 Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 1: 599 queries, 465 answers from cache, 134 recursions, 20 prefetch Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 1: requestlist max 19 avg 1.32468 exceeded 0 jostled 0 Apr 28 15:16:50 unbound: [61715:0] info: average recursion processing time 0.113623 sec Apr 28 15:16:50 unbound: [61715:0] info: histogram of recursion processing times Apr 28 15:16:50 unbound: [61715:0] info: [25%]=0.0207076 median[50%]=0.0431942 [75%]=0.199339 Apr 28 15:16:50 unbound: [61715:0] info: lower(secs) upper(secs) recursions Apr 28 15:16:50 unbound: [61715:0] info: 0.000000 0.000001 15 Apr 28 15:16:50 unbound: [61715:0] info: 0.001024 0.002048 1 Apr 28 15:16:50 unbound: [61715:0] info: 0.008192 0.016384 8 Apr 28 15:16:50 unbound: [61715:0] info: 0.016384 0.032768 36 Apr 28 15:16:50 unbound: [61715:0] info: 0.032768 0.065536 22 Apr 28 15:16:50 unbound: [61715:0] info: 0.065536 0.131072 6 Apr 28 15:16:50 unbound: [61715:0] info: 0.131072 0.262144 24 Apr 28 15:16:50 unbound: [61715:0] info: 0.262144 0.524288 21 Apr 28 15:16:50 unbound: [61715:0] info: 1.000000 2.000000 1 Apr 28 15:16:50 unbound: [61715:0] notice: Restart of unbound 1.4.20. Apr 28 15:16:50 unbound: [61715:0] notice: init module 0: validator Apr 28 15:16:50 unbound: [61715:0] notice: init module 1: iterator Apr 28 15:16:50 unbound: [61715:0] info: start of service (unbound 1.4.20). Apr 28 15:16:50 unbound: [61715:0] info: service stopped (unbound 1.4.20). Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 0: 1 queries, 1 answers from cache, 0 recursions, 0 prefetch Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch Apr 28 15:16:50 unbound: [61715:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Apr 28 15:16:50 unbound: [61715:0] notice: Restart of unbound 1.4.20. Apr 28 15:16:50 unbound: [61715:0] notice: init module 0: validator Apr 28 15:16:50 unbound: [61715:0] notice: init module 1: iterator Apr 28 15:16:50 unbound: [61715:0] info: start of service (unbound 1.4.20).Maybe this is linked to DHCP somehow?
Apr 28 15:16:50 dhcpd: Wrote 0 deleted host decls to leases file. Apr 28 15:16:50 dhcpd: Wrote 0 new dynamic host decls to leases file. Apr 28 15:16:50 dhcpd: Wrote 14 leases to leases file.I don't know why dhcpd does this, it's not configured to backup it's leases and I don't see any cronjob that maybe related.
There are quite a few monitor instances running, too:
ps auxwww | grep unb root 5605 0.0 0.1 3644 1520 ?? SN 10:47AM 0:08.85 /bin/sh /usr/local/etc/rc.d/unbound_monitor.sh start root 59518 0.0 0.1 3644 1348 ?? SN 10:32AM 0:09.01 /bin/sh /usr/local/etc/rc.d/unbound_monitor.sh start unbound 61715 0.0 1.0 31352 19644 ?? Is 11:10AM 0:10.83 unbound -c /usr/pbi/unbound-i386/etc/unbound/unbound.conf root 70174 0.0 0.1 3644 1520 ?? SN 10:45AM 0:09.04 /bin/sh /usr/local/etc/rc.d/unbound_monitor.sh start root 72082 0.0 0.1 3644 1364 ?? SN 10:33AM 0:09.75 /bin/sh /usr/local/etc/rc.d/unbound_monitor.sh start root 59935 0.0 0.1 3644 1364 u0- S 10:33AM 0:09.09 /bin/sh /usr/local/etc/rc.d/unbound_monitor.sh startAlso odd, that the running unbound process has a start time of 11:10AM, shouldn't that be 3:16PM if it really restarted?
Any hints for me? -
I, on the other hand, after 12 hours have no instances of unbound_monitor.sh running!
-
Please try 1.4.20_4 and let me know the results.
-
Looks really good on the commandline now, only one unbound_monitor.sh. Works fine!
But it still restarts every hour, any idea what might be causing that? -
Looks really good on the commandline now, only one unbound_monitor.sh. Works fine!
But it still restarts every hour, any idea what might be causing that?No idea until now, I couldn't replicate it on my local test env.
-
Not quite there yet! Every time I change and save new dhcpd settings a new unbound_monitor.sh is added.
-
At the beginning of the /usr/local/etc/rc.d/unbound_monitor.sh script, there is the following:
**PROCS=
/bin/pgrep -f unbound_monitor.sh | wc -l | awk '{print $1}'if [ ${PROCS} -gt [color=red]2 ]; then
echo "There are another unbound monitor proccess running"
exit 0
fi**
Shouldn't it be:**PROCS=
/bin/pgrep -f unbound_monitor.sh | wc -l | awk '{print $1}'if [ ${PROCS} -gt [color=red]1 ]; then
echo "There are other unbound monitor proccess running"
exit 0
fi**
??? -
Still reloads every hour, I cannot find a reason for that. The only thing I found out was that I have to issue```
unbound-control reloadAnother problem is that my DMZ on opt1 is missing the option``` domain-name-servers 192.168.1.254; ```in /var/dhcpd/etc/dhcpd.conf when I use unbound. I have opt1 defined as Network interface in unbound configuration and I can "dig" it from the DMZ. Using the system forwarder the option is there. -
unbound_monitor.sh was not working with last change, I changed the logic a bit and the way it's called and released 1.4.20_5. Let me know if you find any issues. I tested it on nanobsd and full installation.
-
I found the reason for the unbound reloads on my syslog server. Why would dhcpleases do this?
May 1 07:29:20 pfsense dhcpleases: Sending HUP signal to dns daemon(36838) May 1 07:29:20 pfsense unbound: [36838:0] info: service stopped (unbound 1.4.20).And domain-name-servers is still missing from my opt1 DHCPD config as stated in my reply above.
Other than that, everything looks good now, only one monitor process.
Thanks for looking into this! -
I found the reason for the unbound reloads on my syslog server. Why would dhcpleases do this?
PERHAPS it sends a signal to the local DNS to tell it the local name to IP address mapping has changed and the local DNS should read the updated information.
-
Hmm, but I have not enabled "Register DHCP static mappings". What else could cause this?
-
Hmm, but I have not enabled "Register DHCP static mappings". What else could cause this?
Perhaps it is trying to register a DHCP dynamic mapping! The thread at http://forum.pfsense.org/index.php/topic,33240.msg suggests dhcpleases sends a signal to the DNS to update the DNS registrations.
DNS forwarder has an option Register DHCP leases in DNS forwarder. Do you have the equivalent set in Unbound? I don't know about Unbound and don't run it - does it "inherit" DNS forwarder settings?
Maybe Unbound shouldn't stop when it gets a signal from dhcpleases.
-
Thanks wallabybob, now I was able to solve it:
I had to turn DNS Forwarder back on, uncheck
"Register DHCP leases in DNS forwarder"
turn it off again and finally reboot. Otherwise dhcpleases would not pick up the change.
It (or something else) filled
/var/etc/hosts
with many of these:# dhcpleases automatically entered # dhcpleases automatically entered # dhcpleases automatically enteredNow they don't show up anymore an unbound runs uninterrupted.
Thanks again for the help!
-
I found the reason for the unbound reloads on my syslog server. Why would dhcpleases do this?
May 1 07:29:20 pfsense dhcpleases: Sending HUP signal to dns daemon(36838) May 1 07:29:20 pfsense unbound: [36838:0] info: service stopped (unbound 1.4.20).And domain-name-servers is still missing from my opt1 DHCPD config as stated in my reply above.
Other than that, everything looks good now, only one monitor process.
Thanks for looking into this!Just to make sure, does this issue still persist? If yes, could you send more details about it?
-
Hi Renato,
thanks for asking!
the reload issue was tracked down, please see post #55 for the details. Maybe something could be done about it by clearing the system DNS forwarder's config when it's diabled? Or by making "Register DHCP leases in DNS forwarder" an option in unbound an syncing it with the system setting?
The "domain-name-servers" entry still does not get configured for my opt1 as it does when using the system DNS forwarder. As a workaround I configured this entry in my DHCP config for opt1 now. What details do you need? I guess it can be easily reproduced by configuring an opt1 interface, enabling DHCP Server/Unbound for that interface and looking at /var/dhcpd/etc/dhcpd.conf. It should be missing the domain-name-servers entry for the opt1 IP.
-
the reload issue was tracked down, please see post #55 for the details. Maybe something could be done about it by clearing the system DNS forwarder's config when it's diabled? Or by making "Register DHCP leases in DNS forwarder" an option in unbound an syncing it with the system setting?
I pushed a fix for this, it was not being checked if DNS Fowarder was enabled or not. It should be fine on current 2.1 code.
The "domain-name-servers" entry still does not get configured for my opt1 as it does when using the system DNS forwarder. As a workaround I configured this entry in my DHCP config for opt1 now. What details do you need? I guess it can be easily reproduced by configuring an opt1 interface, enabling DHCP Server/Unbound for that interface and looking at /var/dhcpd/etc/dhcpd.conf. It should be missing the domain-name-servers entry for the opt1 IP.
It's done automatically for DNS Forwarder but not for unbound, the only way is to configure it on DHCP config, as you already did.
-
Hi everyone, does this mean Unbound has now been fixed to work with PfSense 2.1?
-
