Unbound stops working over time

[dominick-cc]

Hi all,

Since my update to 24.1.x, I've noticed that Unbound stops working randomly at times until I restart the Unbound service or reboot the router manually.

In the attached screenshot, you can see the Unbound reporting showing that all client activity has stopped. On my network, I have so many devices being used, there really should never be a period of no activity like this. Unbound has stopped working somehow and restarting the service would temporarily resolve it. This occurs 1 to 2 times per day.

Under System: Log Files: General, I see only the following unrelated messages for warning and above:

Code: [Select]

2024-04-16T01:15:50-04:00 Error php remove config-1693717200.xml from Google Drive
2024-04-16T01:15:49-04:00 Error php backup configuration as config-1713244548.xml
2024-04-15T01:49:02-04:00 Error php remove config-1693630800.xml from Google Drive
2024-04-15T01:49:01-04:00 Error php backup configuration as config-1713160140.xml
Under Services: Unbound DNS: Log File, I don't see any corresponding events with the time that Unbound stopped working:

Code: [Select]

2024-04-16T02:00:53-04:00 Informational unbound [73324:0] info: dnsbl_module: blocklist loaded. length is 243545
2024-04-16T02:00:52-04:00 Informational unbound [73324:0] info: dnsbl_module: updating blocklist.
2024-04-16T02:00:02-04:00 Notice unbound blocklist parsing done in 2.59 seconds (243545 records)
2024-04-16T02:00:02-04:00 Notice unbound blocklist: https://big.oisd.nl/domainswild (exclude: 0 block: 233645 wildcard: 233645)
2024-04-16T02:00:02-04:00 Notice unbound blocklist download: 233660 total lines downloaded for https://big.oisd.nl/domainswild
2024-04-16T02:00:00-04:00 Notice unbound blocklist: https://threatfox.abuse.ch/downloads/hostfile (exclude: 1 block: 14123 wildcard: 0)
2024-04-16T02:00:00-04:00 Notice unbound blocklist download: 14133 total lines downloaded for https://threatfox.abuse.ch/downloads/hostfile
2024-04-16T02:00:00-04:00 Notice unbound blocklist download : exclude domains matching .*localhost$
Environment:

OPNsense 24.1.5_3-amd64
FreeBSD 13.2-RELEASE-p11
OpenSSL 3.0.13
Intel(R) N100 (4 cores, 4 threads)

[dominick-cc]

Attached is the output of System: Diagnostics: Activity filtered for the term "unbound"

[dominick-cc]

Attached is the output of System: Diagnostics: Activity filtered for the term "unbound" after manually restarting the Unbound service (to temporarily resolve this issue)

[dominick-cc]

What sticks out to me between the two diagnostic outputs is that unbound/logger.py was on the "lockf" state. But after restarting it, it became "kqread".

Also, unbound_watcher.py is not present on the list prior to restarting the service. So perhaps whatever that is fails silently and isn't present in the Opnsense logs.

Since unbound_watcher.py seems to be dhcp-related, I pulled some general Opnsense logs for the term "dhcp" and I see that every hour at the 50-minute mark dhcp6c_script is running. Not sure if this is helpful/related but figured I'd include it:

Code: [Select]

2024-04-16T08:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T07:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T06:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T05:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T04:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T03:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T02:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T01:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-16T00:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-15T23:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-15T22:50:24-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
2024-04-15T21:50:23-04:00 Notice dhcp6c dhcp6c_script: RENEW on igc0 executing
...
I did some searching on the forums for why this renewal could be happening, and I saw that someone asked to post the dhcp6c.conf files. I don't really know how these files are produced but on my box here is the output if its helpful to anyone:

Code: [Select]

root@OPNsense:/var/etc # cat dhcp6c.conf
interface igc0 {
  send ia-pd 0; # request prefix delegation
  request domain-name-servers;
  request domain-name;
  script "/var/etc/dhcp6c_wan_script.sh"; # we'd like some nameservers please
};
id-assoc pd 0 {
  prefix ::/56 infinity;
  prefix-interface igc1 {
    sla-id 0;
    sla-len 8;
  };
};
root@OPNsense:/var/etc # cat dhcp6c_wan.conf
interface igc0 {
  send ia-pd 0; # request prefix delegation
  request domain-name-servers;
  request domain-name;
  script "/var/etc/dhcp6c_wan_script.sh"; # we'd like some nameservers please
};
id-assoc pd 0 {
  prefix ::/56 infinity;
  prefix-interface igc1 {
    sla-id 0;
    sla-len 8;
  };
};


Just providing whatever I can that might be helpful for context:

Code: [Select]

root@OPNsense:/var/unbound # cat /var/etc/radvd.conf
# Automatically generated, do not edit
# Generated RADVD config for dhcp6 assignment from wan on lan
interface igc1 {
        AdvSendAdvert on;
        AdvLinkMTU 1500;
        AdvManagedFlag on;
        AdvOtherConfigFlag on;
        prefix REDACTED::/64 {
                DeprecatePrefix on;
                AdvOnLink on;
                AdvAutonomous on;
        };
        RDNSS REDACTED { };
        DNSSL home.arpa { };
};