[Solved] Unbound backend going away: dnsbl_module: Logging backend closed conn…

[pbk]

Hi guys,

this is something bugging me for some time now, I guess is startet with upgrading from 23.7.2 to .3 and is happening ever since.

Every few hours (sometimes it works for up to two days) the dnsbl_module is losing its backend. Unbound then still resolves domain names but the whole blocklist filtering stops. I'm not 100% sure since when it startet because nobody checks the unbound graph all the time.

Code Select Expand

[76481:1] info: dnsbl_module: Logging backend closed
connection. Closing pipe and continuing.
[76481:2] info: dnsbl_module: attempting to open pipe
[76481:2] info: dnsbl_module: no logging backend found.


Restarting Unbound resolves the issue for a few hours. It'll never resolve on its own.

I was unable to find some kind of a scheme happening, I first thought it could be because too many SERVFAILs, but that was a red herring. I then thought it might happen after many hours of not logging anything to the Unbound log, but that's not the case.
I've been unable to duplicate that behaviour in a VM, but that might be related to nothing being blocklisted on this VM-Net. All other OPNsenses I'm dealing with are still on 23.1 so I have nothing to compare it to.

The only "solution" is to restart unbound every three hours by cron – which is a full blown redneck solution.

I've attached two unbound log screenshots and the corresponding unbound reporting graph (the are a tad small, because limits).

[CJ]

That's odd.  Have you tried resetting the reporting data?  Do the logs show anything if you change them to Debug instead of Info?

[pbk]

The screenshot shows what is shown with level set to "debug". There's nothing really usable reported unfortunately.

I did reset the data today, I did so after one of the updates without luck. Waiting for it to error out again.

[CJ]

You might be able to get some more details by increasing the unbound logging verbosity, but I'm not sure if that will provide anything related to the reporting.  Unbound by default doesn't log much.  A word of warning, it gets quite spammy once you start increasing the verbosity.

[pbk]

A quick follow up... After last clearing the Unbound reporting it's running now for the longest time since it first started crashing.

I'll keep it watched. It could be that the changes in 23.7.5 fixed it and I just had to clear the reporting again.

I'll report back on Monday.

[CJ]

Glad to hear it's working.  Something may have gotten corrupted at one point.

[pbk]

So, it didn't happen after resetting the DNS reporting data last week. I guess it was a hiccup or caused by the changes with unbound in the latest updates why resetting it the first time didn't solve it. Whatever it was, it's stable again.
Thanks.