Unbound keeps restarting

[adk20]

Hi forum,

I am on OPNsense 21.1.4-amd64|FreeBSD 12.1-RELEASE-p15-HBSD|OpenSSL 1.1.1k 25 Mar 2021.

Unbound stops and restarts about every one to two hours for no apparent reason, rendering DNS unavailable for about 2 minutes.

I understand from other forum threads that this is a known behaviour. However, I couldn't find a solutions thus far. The other threads are several months old and I gather that the issue should have been fixed by an update by now.

Can anyone confirm this issue or give me some hints as to how to fix it?

Thanks a heap!

-----------------

2021-04-15T10:58:03   unbound[1444]   [1444:0] info: start of service (unbound 1.13.1).   
2021-04-15T10:58:03   unbound[1444]   [1444:0] notice: init module 0: iterator   
2021-04-15T10:56:36   unbound[1444]   [1444:0] notice: Restart of unbound 1.13.1.   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.262144 0.524288 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.131072 0.262144 19   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.065536 0.131072 30   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.032768 0.065536 7   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.016384 0.032768 3   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: lower(secs) upper(secs) recursions   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: [25%]=0.0764587 median[50%]=0.109227 [75%]=0.165565   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: histogram of recursion processing times   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: average recursion processing time 0.117457 sec   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 3: requestlist max 7 avg 3.7377 exceeded 0 jostled 0   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 3: 74 queries, 13 answers from cache, 61 recursions, 0 prefetch, 0 rejected by ip ratelimiting   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.131072 0.262144 57   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.065536 0.131072 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.016384 0.032768 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.008192 0.016384 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: lower(secs) upper(secs) recursions   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: [25%]=0.158666 median[50%]=0.193159 [75%]=0.227651   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: histogram of recursion processing times   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: average recursion processing time 0.194095 sec   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 2: requestlist max 4 avg 3.68333 exceeded 0 jostled 0   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 2: 72 queries, 12 answers from cache, 60 recursions, 0 prefetch, 0 rejected by ip ratelimiting   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.131072 0.262144 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.032768 0.065536 32   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.008192 0.016384 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: lower(secs) upper(secs) recursions   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: [25%]=0.040448 median[50%]=0.049152 [75%]=0.057856   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: histogram of recursion processing times   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: average recursion processing time 0.056732 sec   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 1: requestlist max 3 avg 2.70588 exceeded 0 jostled 0   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 1: 42 queries, 8 answers from cache, 34 recursions, 0 prefetch, 0 rejected by ip ratelimiting   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.262144 0.524288 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.065536 0.131072 35   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.032768 0.065536 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: 0.016384 0.032768 1   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: lower(secs) upper(secs) recursions   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: [25%]=0.0795794 median[50%]=0.0973678 [75%]=0.115156   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: histogram of recursion processing times   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: average recursion processing time 0.077592 sec   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 0: requestlist max 3 avg 2.60526 exceeded 0 jostled 0   
2021-04-15T10:56:36   unbound[1444]   [1444:0] info: server stats for thread 0: 46 queries, 8 answers from cache, 38 recursions, 0 prefetch, 0 rejected by ip ratelimiting   
2021-04-15T10:56:33   unbound[1444]   [1444:0] info: service stopped (unbound 1.13.1).

[Fright]

Hi

[1444:0] notice: Restart of unbound 1.13.1.

you need to look in the General log what is triggering the unbound restart

[adk20]

Thanks a lot, Fright, for your reply. Your hint led me in the right direction.

After some more investigation, I found out that it appears to be related to connecting devices to the network ports. Unbound seems to restart when the system receives a LINK UP event.