OPNsense 22.1.1_3 Upgrade to 22.1.2 - UNBOUND 100% CPU - Recovery needed

[devhunter55]

7.3.2022: Did an upgrade from:OPNsense 22.1.1_3 TO:OPNsense 22.1.2.

After that, UNBOUND got permanent CPU of 100% & was most of time unresponsive.

Had to do a FULL ZFS-Recovery to the previous version (22.1.1_3).
Now system is running stable again.

[devhunter55]

(reboot did not solve the issue, that's why the only option available was the full recovery)

[devhunter55]

just saw - that i'd had another possbility - but it did not remember this option for that moment:

     opnsense-revert – OPNsense revert utility

SYNOPSIS

     opnsense-revert [-i] [-l] [-r release] package ...

DESCRIPTION

     The opnsense-revert utility offers to securely install previous versions
     of packages found in an OPNsense release as long as the selected mirror
     caches said release.

     Package flags ‘automatic’ and ‘vital’ will be restored to their expected
     values.

     The options are as follows:

           -i                Ignore the signature verification result.

           -l                Honour active locks.  The default is to strip
                             them and proceed with the revert.

           -r release        Select the release of the package to be
                             installed.  Note that the release is not the
                             individual package version, but rather the
                             version found in said OPNsense release.

[ilikenwf]

I reverted to the 22.1 version of Unbound to fix this same issue, and after a reboot, it appears resolved.

For what it is worth, I'm using DNS over TLS, and have blocklists turned on. Otherwise I'm not sure beyond that what could cause this issue, but it is something that needs addressed for sure!

I'm now on unbound 1.14.0 from 1.15.0 and went from bad CPU usage to perfect behavior once again.

[devhunter55]

Thx ilikenwf for your answer.

Yes, me too .. have got blocklists turned on in UNBOUND.
May be the blocklists can have a negative "side-effect" !?

But you're right ... this is severe behave and need to be addressed.

Wondering, if we both are the only ones, who caught this error ?

[hushcoden]

I'm on v22.1.2, using Unbound + DoT + blocklist (also custom URLs) - how big is your dnsbl.conf ?

My CPU usage didn't change, it's low pretty much all the time

[Superduke]

FWIW....I found that Unbound was pretty unreliable when blocklists were on.  It worked and then didn't work...haha.

I've since moved to using AdGuard with Unbound resolving but Adguard performing the filtering and blocking.  I haven't had any Unbound related issues since.

Thx ilikenwf for your answer.

Yes, me too .. have got blocklists turned on in UNBOUND.
May be the blocklists can have a negative "side-effect" !?

But you're right ... this is severe behave and need to be addressed.

Wondering, if we both are the only ones, who caught this error ?

[devhunter55]

@huscoden - my dnsbl.conf is: 133M

@Superduke, thx 4 your hint - yes .. may be the BlockLists (you see - my BlockList conf (dnsbl.conf is pretty big)) could be reason for .. on the other hand .. i've got a power machine :

Intel(R) Core(TM) i5-8365U CPU @ 1.60GHz (4 cores, 8 threads) - so - i think it's a serious new bug into the UNBOUND Application), because before the load was quite normal (near zero on this machine). After Upgrading all the CORE got near 100% the machine got very, very HOT.

i searched for Adguard, if it is a OPNSense Plugin, but i didn't found.

[devhunter55]

big issue with OPNSense v22.1.2 and UNBOUND

Did the upgrade on another system from 22.1.1_3, too.

In this case UNBOUND did disturb the WAN 1000baseT <full-duplex> Interface.

It came up & down, up & down, up & down .. every 5 seconds.

So, even fetching the old (1.14.0) Unbound version failed, because, i was not able anymore to connect to the web:

Fetching unbound.txz: ... ...Latest/unbound.txz.sig: Not foun] failed

So, again i did need to do a full ZFS Restore

(Thx God, that ZFS is now in place).

After zfs full recovery system runs normally.

[devhunter55]

btw .. dmesg output is ok (all the OPN-Hardware has got enough memory, means:
16G of memory & 10GB of swap space = 26 GB usable memory) ..

So memory is definitively not the issue here (because i saw some comments from Franco in previous posts from Franco)

[Vincent]

Hello devhunter55,

If you're seeking for adguard home plugin, mimugmail made it available through his opn-repo:
https://github.com/mimugmail/opn-repo

There's a forum thread on steps to follow to install it smoothly:
https://forum.opnsense.org/index.php?topic=22162.msg128415#msg128415

I'm using it since a while now, and works like a charm.

Kind regards,
Vincent

[devhunter55]

thx very much, Vicent, i do appreciate your help. I'm going to check this.

Cheers
Mike

[devhunter55]

on my side - UNBOUND is not working anymore since 22.1.2 or since UNBOUND version: unbound 1.15.0

Yesterday, i gave it a try again - and upgraded to 22.1.6.

I've got a lot of UNBOUND "overrides" in place & BlockLists.
I did disable the BlockLists - but this didn't help.

DNS is not working anymore - it seems that the DNS Resolver will switch from offline to online & vice versa in a very short time - so sometimes a can connect to the WEB (but resolution is very, very slow).
..getting a WAN DHCP ip & and then it disappears again.

The whole machine gets very hot, CPU & unbound is about 100% - restart UNBOUND does not fix this issue.

Fortunately i'm using ZFS, so Restore is quick & easy - but full RESTORE was needed in every upgrade after version: 22.1.1 (with UNBOUND 1.15.0).

I tried the upgrades also with different hardware - same result - no chance to get UNBOUND working again - and DNS - of course is fundamental.

messages:
------------
<11>1 2022-04-15T20:59:19+02:00 opnsense-host opnsense 88624 - [meta sequenceId="32"] /usr/local/etc/rc.linkup: DEVD: Ethernet attached event for dynamic wan(igb1)
<27>1 2022-04-15T20:59:19+02:00 opnsense-host dhclient 96268 - [meta sequenceId="33"] dhclient already running, pid: 86990.
<26>1 2022-04-15T20:59:19+02:00 opnsense-host dhclient 96268 - [meta sequenceId="34"] exiting.
<11>1 2022-04-15T20:59:19+02:00 opnsense-host opnsense 88624 - [meta sequenceId="35"] /usr/local/etc/rc.linkup: The command '/sbin/dhclient -c '/var/etc/dhclient_wan.conf' -p '/var/run/d
hclient.igb1.pid' 'igb1'' returned exit code '1', the output was 'dhclient already running, pid: 86990. exiting.'
<11>1 2022-04-15T20:59:19+02:00 opnsense-host opnsense 88624 - [meta sequenceId="36"] /usr/local/etc/rc.linkup: Accept router advertisements on interface igb1
<13>1 2022-04-15T20:59:19+02:00 opnsense-host dhcp6c 3104 - [meta sequenceId="37"] RTSOLD script - Sending SIGHUP to dhcp6c
<11>1 2022-04-15T20:59:19+02:00 opnsense-host opnsense 88624 - [meta sequenceId="38"] /usr/local/etc/rc.linkup: ROUTING: entering configure using 'wan'
<11>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="39"] /usr/local/etc/rc.linkup: ROUTING: IPv4 default gateway set to lan
<11>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="40"] /usr/local/etc/rc.linkup: ROUTING: skipping IPv4 default route
<11>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="41"] /usr/local/etc/rc.linkup: ROUTING: IPv6 default gateway set to wan
<11>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="42"] /usr/local/etc/rc.linkup: ROUTING: skipping IPv6 default route
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="43"] plugins_configure ipsec (,wan)
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="44"] plugins_configure ipsec (execute task : ipsec_configure_do(,wan))
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="45"] plugins_configure dhcp ()
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="46"] plugins_configure dhcp (execute task : dhcpd_dhcp_configure())
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="47"] plugins_configure dns ()
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="48"] plugins_configure dns (execute task : dnsmasq_configure_do())
<13>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="49"] plugins_configure dns (execute task : unbound_configure_do())
<11>1 2022-04-15T20:59:20+02:00 opnsense-host opnsense 88624 - [meta sequenceId="50"] /usr/local/etc/rc.linkup: warning: ignoring missing default tunable request: debug.pfftpproxy
<13>1 2022-04-15T20:59:24+02:00 opnsense-host dhcp6c 64283 - [meta sequenceId="51"] RTSOLD script - Sending SIGHUP to dhcp6c
<27>1 2022-04-15T20:59:36+02:00 opnsense-host upsmon 39698 - [meta sequenceId="52"] UPS [ups@localupsip]: connect failed: Connection failure: Operation timed out
<13>1 2022-04-15T20:59:49+02:00 opnsense-host configctl 68544 - [meta sequenceId="53"] event @ 1650049188.54 msg: Apr 15 20:59:48 opnsense-host config[87361]: [2022-04-15T20:59:48+02
:00][info] config-event: new_config /conf/backup/config-1650049188.5364.xml
<13>1 2022-04-15T20:59:49+02:00 opnsense-host configctl 68544 - [meta sequenceId="54"] event @ 1650049188.54 exec: system event config_changed
<27>1 2022-04-15T21:00:56+02:00 opnsense-host upsmon 39698 - [meta sequenceId="1"] UPS [ups@localupsip]: connect failed: Connection failure: Operation timed out
<29>1 2022-04-15T21:00:56+02:00 opnsense-host upsmon 39698 - [meta sequenceId="2"] UPS ups@localupsip is unavailable
<11>1 2022-04-15T21:01:19+02:00 opnsense-host configctl 87822 - [meta sequenceId="3"] error in configd communication  Traceback (most recent call last):   File "/usr/local/sbin/configctl
", line 66, in exec_config_cmd     line = sock.recv(65536).decode() socket.timeout: timed out
<11>1 2022-04-15T21:01:19+02:00 opnsense-host opnsense 99032 - [meta sequenceId="4"] /usr/local/etc/rc.linkup: DEVD: Ethernet detached event for dynamic wan(igb1)
<11>1 2022-04-15T21:01:19+02:00 opnsense-host opnsense 99032 - [meta sequenceId="5"] /usr/local/etc/rc.linkup: Clearing states for stale wan route on igb1
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="6"] /usr/local/etc/rc.linkup: DEVD: Ethernet attached event for dynamic wan(igb1)
<27>1 2022-04-15T21:01:20+02:00 opnsense-host dhclient 23026 - [meta sequenceId="7"] dhclient already running, pid: 86990.
<26>1 2022-04-15T21:01:20+02:00 opnsense-host dhclient 23026 - [meta sequenceId="8"] exiting.
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="9"] /usr/local/etc/rc.linkup: The command '/sbin/dhclient -c '/var/etc/dhclient_wan.conf' -p '/var/run/dh
client.igb1.pid' 'igb1'' returned exit code '1', the output was 'dhclient already running, pid: 86990. exiting.'
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="10"] /usr/local/etc/rc.linkup: Accept router advertisements on interface igb1
<13>1 2022-04-15T21:01:20+02:00 opnsense-host dhcp6c 30500 - [meta sequenceId="11"] RTSOLD script - Sending SIGHUP to dhcp6c
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="12"] /usr/local/etc/rc.linkup: ROUTING: entering configure using 'wan'
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="13"] /usr/local/etc/rc.linkup: ROUTING: IPv4 default gateway set to lan
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="14"] /usr/local/etc/rc.linkup: ROUTING: skipping IPv4 default route
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="15"] /usr/local/etc/rc.linkup: ROUTING: IPv6 default gateway set to wan
<11>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="16"] /usr/local/etc/rc.linkup: ROUTING: skipping IPv6 default route
<13>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="17"] plugins_configure ipsec (,wan)
<13>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="18"] plugins_configure ipsec (execute task : ipsec_configure_do(,wan))
<13>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="19"] plugins_configure dhcp ()
<13>1 2022-04-15T21:01:20+02:00 opnsense-host opnsense 16955 - [meta sequenceId="20"] plugins_configure dhcp (execute task : dhcpd_dhcp_configure())
<13>1 2022-04-15T21:01:21+02:00 opnsense-host opnsense 16955 - [meta sequenceId="21"] plugins_configure dns ()
<13>1 2022-04-15T21:01:21+02:00 opnsense-host opnsense 16955 - [meta sequenceId="22"] plugins_configure dns (execute task : dnsmasq_configure_do())
<13>1 2022-04-15T21:01:21+02:00 opnsense-host opnsense 16955 - [meta sequenceId="23"] plugins_configure dns (execute task : unbound_configure_do())
<11>1 2022-04-15T21:01:21+02:00 opnsense-host opnsense 16955 - [meta sequenceId="24"] /usr/local/etc/rc.linkup: warning: ignoring missing default tunable request: debug.pfftpproxy
<13>1 2022-04-15T21:01:24+02:00 opnsense-host dhcp6c 88779 - [meta sequenceId="25"] RTSOLD script - Sending SIGHUP to dhcp6c

[cookiemonster]

These errors seem to be to do with setting up or renewing the public ip on the wan, so it might need a different diagnostic.
For Unbound, my suggestion although painful is to remove the blocklists, not only disable them prior to the upgrade.

[devhunter55]

Yes, might be - but i see the missbehave from process diagnostics, too - on UNBOUND site ..
100%CPU of unbound - unbound restarts serveral time itself .. but yes, there can be any sideeffect .. but - quite sure - together with UNBOUND.

22.1.1_3 Version runs perfectly.

This is the normal load when running 22.1.1_3: (unbound only 0.14%) !

  PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
25561 root          9  20    0  4977M  1922M nanslp   7  92:53   5.69% suricata
48667 root          1  52    0    48M    27M accept   5   0:00       1.94% php-cgi
 469    root          2  52    0    82M    43M accept   2   0:27       0.23% python3.8
18919 unbound    8  20    0  1563M  1341M kqread   1   2:26   0.14% unbound

i've got a powerful machine: Intel(R) Core(TM) i5-8365U CPU @ 1.60GHz (4 cores, 8 threads),16GB RAM

At the moment i'm completely knocked-out. No chance to upgrade as long UNBOUND is on version:1.15.0.