core: 21.7.1: Unbound fails to start up automatically / from GUI

As per https://forum.opnsense.org/index.php?topic=24264.0:

• I have read the contributing guide lines at https://github.com/opnsense/core/blob/master/CONTRIBUTING.md
• I am convinced that my issue is new after having checked both open and closed issues at https://github.com/opnsense/core/issues?q=is%3Aissue

Description

Unbound fails to start up (and stay running) when booting OPNsense - it seems to start initially and then fails/stops. Unbound fails to start up when pressing “start” in the OPNsense GUI.

Background:

• On 21.1, I used Adguard Home as DNS server on port 53 and Unbound on Port 5553 for local resolves. Setup worked fine.
• On a fresh install + import config of 21.7, Unbound shows the above behaviour, i.e. it fails to keep running (Adguard does start and keep running).
• upd: Manually running “unbound -c /var/unbound/unbound.conf” works and unbound is operative thereafter (until reboot).

To Reproduce

Steps to reproduce the behavior:

1. Use Adguard Home on port 53 and unbound on port 5553.
2. Boot OPNsense.
3. Unbound enters failed state.

Expected behavior

Unbound to start, bind to port 5553 and keep running.

Describe alternatives you considered

Reboots did not change anything.

Relevant log files

2021-08-08T13:28:07 unbound[2474] daemonize unbound dhcpd watcher. 2021-08-08T13:28:05 unbound[2663] daemonize unbound dhcpd watcher. 2021-08-08T13:28:00 unbound[38473] daemonize unbound dhcpd watcher. 2021-08-08T13:27:52 unbound[60119] daemonize unbound dhcpd watcher. 2021-08-08T13:27:52 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:52 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:52 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:52 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:52 unbound[25826] [25826:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:51 unbound[25826] [25826:0] info: service stopped (unbound 1.13.1). 2021-08-08T13:27:51 unbound[25826] [25826:0] info: control cmd: dump_cache 2021-08-08T13:27:45 unbound[25826] [25826:0] info: start of service (unbound 1.13.1). 2021-08-08T13:27:45 unbound[25826] [25826:0] notice: init module 2: iterator 2021-08-08T13:27:45 unbound[25826] [25826:0] notice: init module 1: validator 2021-08-08T13:27:45 unbound[25826] [25826:0] notice: init module 0: dns64 2021-08-08T13:27:39 unbound[25826] [25826:0] notice: Restart of unbound 1.13.1. 2021-08-08T13:27:39 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:39 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:39 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:39 unbound[25826] [25826:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:39 unbound[25826] [25826:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:38 unbound[25826] [25826:0] info: service stopped (unbound 1.13.1). 2021-08-08T13:27:38 unbound[25826] [25826:0] info: start of service (unbound 1.13.1). 2021-08-08T13:27:38 unbound[25826] [25826:0] notice: init module 2: iterator 2021-08-08T13:27:38 unbound[25826] [25826:0] notice: init module 1: validator 2021-08-08T13:27:38 unbound[25826] [25826:0] notice: init module 0: dns64 2021-08-08T13:27:31 unbound[66648] daemonize unbound dhcpd watcher. 2021-08-08T13:27:31 unbound[2967] [2967:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:31 unbound[2967] [2967:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:31 unbound[2967] [2967:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:31 unbound[2967] [2967:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 2021-08-08T13:27:31 unbound[2967] [2967:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting 2021-08-08T13:27:31 unbound[2967] [2967:0] info: service stopped (unbound 1.13.1). 2021-08-08T13:27:31 unbound[2967] [2967:0] info: control cmd: dump_cache 2021-08-08T13:27:19 unbound[2967] [2967:0] info: control cmd: list_local_data 2021-08-08T13:27:19 unbound[2967] [2967:0] info: start of service (unbound 1.13.1). 2021-08-08T13:27:19 unbound[2967] [2967:0] notice: init module 2: iterator 2021-08-08T13:27:19 unbound[2967] [2967:0] notice: init module 1: validator 2021-08-08T13:27:19 unbound[2967] [2967:0] notice: init module 0: dns64 2021-08-08T13:27:12 unbound[87717] daemonize unbound dhcpd watcher. [*** REBOOT ***]

Additional context

Pressing “start” button in the GUI will only generate the following log entry (nothing more!), but not start unbound up: 2021-08-08T13:28:07 unbound[2474] daemonize unbound dhcpd watcher.

Environment

Software version used and hardware type if relevant, e.g.:

OPNsense 21.7.1-amd64 FreeBSD 12.1-RELEASE-p19-HBSD OpenSSL 1.1.1k 25 Mar 2021