Unbound seems to be restarting frequently



  • From the logs, it seems that unbound is stopping/starting fairly frequently.. Is this expected/normal behavior? Any suggestions on how I could troubleshoot?

    Thanks,
    -Ryan



  • bump



  • Does this happen consistently?

    I know certain config changes will cause Unbound to restart so if you made a few changes you might see a few of these restarts in a row.



  • Fairly consistent. On average every 2-3mins.. Occasionally multiple times in a minute.



  • I'd post my DNS resolver configuration, DNS forwarder configuration, any port forwards or anything you have running on port 53, etc etc and see if something stands out.



  • Where can I find / how can I export unbound's config?

    I did experiment with unbound and forwarder a few times.. Perhaps toggling between the two caused some issues.

    I have no confirmed at least that forwarder is off.

    Thanks!



  • Flush experimental & crap by rebooting ?


  • LAYER 8 Global Moderator

    curious is this a clean install of 2.2, and upgrade?  Did you have or try to install the unbound package before it was part of 2.2?



  • The problem persists after subsequent reboots. This was a clean 2.2 install.

    Can someone tell me where to find the config? I'll try and grab it to post. Perhaps that may shed some light.



  • services > DNS resolver - unbound

    services > DNS forwarder - dnsmasq

    I was suggesting that you take a screen shot of the settings in there and post to see if there is anything strange there.

    Or, you can post here daily "my unbound is weird" over and over…



  • Attached.










  • With these settings, your unbound is just acting as a forwarder.  May as well use dnsmasq instead (dns forwarder)



  • But I still get the benefit of pre-fetch and caching.

    My actual unbound config is here.

    I found the unbound logs but I'm getting permission denied when I try to view them. I also can't do a sudo or sudo su. Any suggestions on how I can get the raw logs?

    I'd still like to fix unbound should I decide to not forward queries.

    unbound.txt



  • Were you using unbound in 2.1.5?  (yes or no)



  • I never used 2.1. My 2.2 build was a fresh install on a new pc engines build.



  • If I filter for restarts, I get the following:

    Mar 2 11:52:20	unbound: [28167:0] notice: init module 0: iterator
    Mar 2 11:52:20	unbound: [28167:0] notice: Restart of unbound 1.5.1.
    Mar 2 10:49:14	unbound: [28167:0] notice: init module 0: iterator
    Mar 2 10:49:14	unbound: [28167:0] notice: Restart of unbound 1.5.1.
    Mar 2 10:49:12	unbound: [28167:0] notice: init module 0: iterator
    Mar 2 10:49:12	unbound: [28167:0] notice: Restart of unbound 1.5.1.
    Mar 2 10:49:12	unbound: [28167:0] notice: init module 0: iterator
    Mar 2 10:09:59	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 10:09:59	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 10:03:14	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 10:03:14	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:53:20	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:53:20	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:43:24	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:43:24	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:33:30	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:33:30	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:33:30	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:33:30	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:31:00	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:31:00	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:30:56	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:30:56	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:30:20	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:30:20	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:24:02	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:24:02	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:23:29	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:23:29	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:13:34	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:13:34	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:12:04	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:12:04	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 09:09:56	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 09:09:56	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 08:09:43	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 08:09:43	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 08:02:39	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 08:02:39	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:52:44	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 07:52:44	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:49:50	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 07:49:50	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:42:49	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 07:42:49	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:40:24	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 07:40:24	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:38:15	unbound: [45732:0] notice: init module 0: iterator
    Mar 2 07:38:15	unbound: [45732:0] notice: Restart of unbound 1.5.1.
    Mar 2 07:37:28	unbound: [45732:0] notice: init module 0: iterator
    


  • Hmmmm.  Is there a reason you don't want to use the root DNS servers (just curious)?



  • Comcast operates a bunch of caching servers for content from Akamai, Netflix. I'd like to hit the locally cached servers when that content is requested. Netflix definitely streams a little faster, I think.



  • Thing is, I think hitting the local DNS without DNSSEC and harden glue and all that might be whats crashing your unbound.

    Would you be opposed to trying it in resolver mode instead of forwarder mode for a while?  See if it stops crashing?



  • Is there any additional logging I can enable that may offer better insight?

    Would someone mind posting their config so I can try running a good one that I know works?

    Thanks!



  • How do I reset the Resolver general settings to their defaults? The GUI retains the settings from the previous config, even if I wipe out the .conf file.



  • Why are you hard on yourself with CLI. Just use the webGUI to stop and start what you want.

    Stop Services: DNS forwarder.
    Clear out System: General Setup for DNS servers
    Set Services: DNS Resolver(interfaces & DNSSEC) only
    Services: DNS Resolver: Advanced(Harden = true)

    Maybe reboot.



  • Disabling the forwarder and adding in the hardening both worked. I'll continue to troubleshoot w/ the forwards or perhaps just enable dnsmasq.



  • It seems adding DNS servers into the general settings tab causes the unbound restarts. This seems like a bug. Does anyone know how I would report this?



  • I don't know if its a bug or if something malicious is being done to your DNS…  Glad its working now.



  • Even if it's something malicious, unbound shouldn't reboot all the time. lol



  • I am also seeing this issue with unbound restarting frequently on a clean 2.2 install.  It is triggered by DHCPREQUEST events in dhcpd, but only when a host name is specified in the request.  For example, a request to dhcpd like this:

    Mar 2 15:43:41 dhcpd: DHCPREQUEST for 192.168.1.208 from xx:xx:xx:xx:xx:xx (ipcam_xxxxxxxxxxxx) via em1

    …always results in a restart of unbound at the same exact time:

    Mar 2 15:43:41 unbound: [55204:0] info: service stopped (unbound 1.5.1).
    (followed by a bunch of info logging and then…)
    Mar 2 15:43:41 unbound: [55204:0] notice: Restart of unbound 1.5.1.
    Mar 2 15:43:41 unbound: [55204:0] notice: init module 0: iterator
    Mar 2 15:43:41 unbound: [55204:0] info: start of service (unbound 1.5.1).

    However, a DHCPREQUEST without a host name does not trigger the restart (also this is a static mapping, the one above is from the DHCP pool):

    Mar 2 15:47:46 dhcpd: DHCPREQUEST for 192.168.1.11 from xx:xx:xx:xx:xx:xx via em1

    I do not have "DNS Query Forwarding" enabled in the unbound configuration.  After reading this thread, I tried disabling DNSSEC and it had no effect on the restarting behavior.  I do have "Register DHCP leases in the DNS Resolver" and "Register DHCP static mappings in the DNS Resolver" enabled which leads me to believe the problem lies in the DHCP -> DNS registration functionality.

    I would not normally notice this behavior except that there are times where the frequent restarting of unbound sometimes seems to cause unbound to stop resolving DNS queries properly.  This usually happens when there are a lot of devices going on or offline and requesting DHCP leases.  A manual restart of unbound in the web GUI fixes it, although the restart behavior continues whenever a DHCPREQUEST with hostname is received.



  • I think people were seeing crashes when they had devices (such as cameras or laptops) that have both a wired and wireless connection and both were connected simultaneously and shouldn't have been…

    You sure you don't have something like that going on?



  • It is unlikely that is the case with my installation.  Of the wireless devices I have on a wired connection, most don't even have the wireless SSID configured.  Also, my AP and all wireless devices are on a separate subnet, so anything on the 192.168.1 subnet is 100% wired.



  • For me, the reboots stopped when I removed the DNS settings from System -> General Setup.

    Interestingly, I also have DNS Registration and Static DHCP enabled in resolver.. For the time being, I'm switching back to dnsmasq while I can sort it out.



  • My logs (and resultant DNS problems) indicate that previously known MAC addresses and DHCP leases frequently trigger a restart, although not necessarily 100% of the time.  I found that I can reproduce the unbound restart behavior 100% of the time by bringing a machine online with a new (to the firewall) MAC and having it initiate a DHCP request.  This is on a wired machine with no wireless card.  With this, I ran a few testing scenarios:

    Register DHCP leases in the DNS Resolver - enabled
    Register DHCP static mappings in the DNS Resolver - enabled
    Result when DHCP is requested - unbound restart

    So I disabled both:

    Register DHCP leases in the DNS Resolver - disabled
    Register DHCP static mappings in the DNS Resolver - disabled
    Result when DHCP is requested - NO unbound restart

    I enabled static only:

    Register DHCP leases in the DNS Resolver - disabled
    Register DHCP static mappings in the DNS Resolver - enabled
    Result when DHCP is requested - NO unbound restart

    I went back to the original config with both enabled:

    Register DHCP leases in the DNS Resolver - enabled
    Register DHCP static mappings in the DNS Resolver - enabled
    Result when DHCP is requested - unbound restart

    This lends some weight to the theory that the restarts are related to the "Register DHCP leases in the DNS Resolver" setting.  However, one amendment to my previous post is that my testing scenario does not set a host name, yet it still triggers a restart.  This is the dhcpd log that will reliably trigger unbound to restart when Register DHCP in DNS is enabled and the MAC address is not previously known to the firewall (newest on top):

    Mar 2 17:40:42 dhcpd: DHCPACK on 192.168.200.212 to xx:xx:xx:xx:xx:xx via em3
    Mar 2 17:40:42 dhcpd: DHCPREQUEST for 192.168.200.212 (192.168.200.1) from xx:xx:xx:xx:xx:xx via em3
    Mar 2 17:40:42 dhcpd: DHCPOFFER on 192.168.200.212 to xx:xx:xx:xx:xx:xx via em3
    Mar 2 17:40:41 dhcpd: DHCPDISCOVER from xx:xx:xx:xx:xx:xx via em3



  • This sounds like a bug to me.


  • LAYER 8 Global Moderator

    So your saying unbound restarts on a dhcp request… Yeah I have not seen this, but when I get home I will check.. If a bug then it would be very simple to duplicate.



  • With the proper settings you can break anything.


  • LAYER 8 Global Moderator

    Well I know for sure I have both those options enabled and have not seen or atleast noticed unbound restarting.. And I would assume I would see lots of dhcp requests.  When I get home I will take a double look and force a request, etc.

    To be honest if this was a real bug you would think the forums would be blowing up with this happening.



  • For me it was configuring DNS servers in System -> General Setup, regardless if I had Forwarding Mode disabled/enabled. Simply having external servers caused the restarts for me.

    dparring, what are your System -> General Setup DNS settings? If you remove them and only use local host, do the reboots stop?



  • CiscoKid85 is on to something.  I had Google DNS configured under general settings (8.8.8.8/8.8.4.4).  When I cleared those entries, saved, and redid the test, DHCP did NOT cause unbound to restart.  Even stranger is that when I put the entries back in, the test no longer causes unbound to restart.  However, when I ran my previous tests again, it started happening after I reanabled "Register DHCP leases in the DNS Resolver".  Here is the sequence:

    New DHCP causes unbound restart
    +Removed 8.8.8.8/8.8.4.4 from general settings DNS
    New DHCP does NOT cause unbound restart
    +Added 8.8.8.8/8.8.4.4 back to general settings
    New DHCP does NOT cause unbound restart
    +Rebooted pfSense
    New DHCP does NOT cause unbound restart
    +Unchecked "Register DHCP leases in the DNS Resolver"
    New DHCP does NOT cause unbound restart
    +Checked "Register DHCP leases in the DNS Resolver"
    New DHCP causes unbound restart
    +Removed 8.8.8.8/8.8.4.4 from general settings DNS
    New DHCP does NOT cause unbound restart
    +Unchecked "Register DHCP leases in the DNS Resolver"
    New DHCP does NOT cause unbound restart
    +Checked "Register DHCP leases in the DNS Resolver"
    New DHCP causes unbound restart

    Confusing right?  If I had to guess, there is a bug related to enabling "Register DHCP leases in the DNS Resolver" that causes unbound to restart when dhcpd issues leases, and that making other changes to the DNS system somehow fixes it.  There is another thread on the forum about unbound restarts where people seem to have resolved it by playing with similar settings, so it makes sense that this is only happening in certain difficult to reproduce scenarios.  Also, unless you're digging in the logs or experiencing DNS outages, most people wouldn't even notice this is happening.  I'd be interested to see if anyone else can produce similar findings by enabling and disabling the "Register DHCP leases in the DNS Resolver" setting.



  • One more data point as a direct continuation from the sequence above:

    +Left general settings exactly the same (dns servers are blank) and hit save
    New DHCP does NOT cause unbound restart

    My best guess of the bug at this point:

    Enabling "Register DHCP leases in the DNS Resolver" causes it
    Something on the general settings page save sequence fixes it (logs indicate the save kicks off a dhcpd and unbound restart, possibly other actions)



  • Even more craziness when I cleared out some of the old DHCP leases from my testing earlier:

    +Deleted leases using the delete button in DHCP Leases page (this seems to trigger a dhcpd and unbound restart with each delete request)
    New DHCP causes unbound restart
    +Left general settings exactly the same (dns servers are blank) and hit save
    New DHCP does NOT cause unbound restart


  • LAYER 8 Global Moderator

    Well dhcp doesn't seem to be restarting mine..  But now that take a closer look it does seem to have restarted a few time when seems odd that it did.  But must not be happening enough for me to notice.  Last time I looked at the log didn't see any craziness there.. But now there is more restarts than you would think should be there.

    If its a combinations of things, and something removes the issue like save or no dns in general, etc.  Then sure that makes sense that less people would see it that had the specific settings and combinations of things.

    Will keep an eye on it more, have not noticed any issue with resolving anything.  But does seem to have been restarting more than it should..

    Mar 3 04:15:10 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 04:03:19 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 03:25:24 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 03:05:42 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 01:33:22 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 01:10:28 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 00:36:41 unbound: [26324:0] notice: Restart of unbound 1.5.1.
    Mar 3 00:12:51 unbound: [26324:0] notice: Restart of unbound 1.5.1.

    If I look in the dhcp log there is lots of dhcp stuff going on with renews and such at 2 in the morning but no restart that matches up to then, etc.  I don't see any dhcp traffic that matches up with these restart times.


Log in to reply