Revert unbound to 18.7.7 - not possible?

[chemlud]

Hi!

I'm still on

19.1.1
LibreSSL 2.7.5
Unbound 1.8.1

Anybody tried to update and unbound still stable? (Last try is some days ago, iirc 19.1.2, and unbound was stable for about 24h)

[franco]

It sounds a bit like upstream servers are part of the crashes...


Cheers,
Franco

[chemlud]

That was what I expected, to be true...

But doesn't this imply there is something wrong with openSSL, if it can't work correctly with LibreSSL?

[franco]

Remember Heartbleed? It was known that OpenSSL has its own "memory allocation" to speed it up, which kinda wraps around malloc and free and never really gives back memory to the system leading to "solicited" use after free. LibreSSL doesn't do this anymore so it would naturally crash sooner.

The underlying issue could be the same in OpenSSL and LibreSSL still (same fix) but barely escapes crashing in OpenSSL leaving a vulnerability door open for the future. ;)


Cheers,
Franco

[franco]

PS: Or for the paranoia fans out there: it could already be exploited in the wild and LibreSSL actually protects you properly. ;)

[chemlud]

Yeah, franco, reminds me that I have to take my pills :-D

But I'm kinda locked at the moment... stay on 19.1.1 as long as possible, until someone (me, on an experimental box? But no time currently...) confirms another setup is working well. Don't want to run around restarting unbound  every now and then.

[chemlud]

PS: What really bugs me is that apparently nobody cares and the big players keep using this pile of trash called openSSL, whatever it takes, no matter what the price will be...

[chemlud]

OK, I updated my test system (which I wanted to deploy weeks ago, anyways...) to 19.1.4 and unbound fails quite quickly and reliably.

Of note there is only ONE (1) client attached to the opnsense, unly running  a Firefox to keep the GUI of opnsense in sight for restarting unbound. Nothing else attached...

I get in GENERAL LOG:

Code Select Expand

Mar 16 02:59:12 kernel: [HBSD SEGVGUARD] [unbound (17174)] Suspension expired.
Mar 16 02:59:12 kernel: pid 17174 (unbound), uid 59: exited on signal 11
Mar 15 22:00:33 kernel: [HBSD SEGVGUARD] [unbound (93551)] Suspension expired.
Mar 15 22:00:33 kernel: pid 93551 (unbound), uid 59: exited on signal 11
Mar 15 20:01:59 kernel: [HBSD SEGVGUARD] [unbound (77728)] Suspension expired.
Mar 15 20:01:59 kernel: pid 77728 (unbound), uid 59: exited on signal 11
Mar 15 19:31:27 kernel: pid 5130 (unbound), uid 59: exited on signal 11
Mar 15 18:27:32 opnsense: /usr/local/etc/rc.linkup: The command '/usr/local/sbin/unbound -c '/var/unbound/unbound.conf'' returned exit code '1', the output was '[1552670852] unbound[74683:0] error: can't bind socket: Address already in use for 127.0.0.1 port 953 [1552670852] unbound[74683:0] error: cannot open control interface 127.0.0.1 953 [1552670852] unbound[74683:0] fatal error: could not open ports'

18:27 should be the time of REBOOT after updating from 18.7.10_4

...and in UNBOUND LOG:

Code Select Expand

Mar 16 08:55:00 unbound: [55520:2] info: generate keytag query _ta-4f66. NULL IN
Mar 16 08:54:08 unbound: [55520:0] info: start of service (unbound 1.9.0).
Mar 16 08:54:08 unbound: [55520:0] notice: init module 1: iterator
Mar 16 08:54:08 unbound: [55520:0] notice: init module 0: validator
Mar 16 00:17:18 unbound: [17174:3] info: generate keytag query _ta-4f66. NULL IN
Mar 16 00:17:17 unbound: [17174:0] info: start of service (unbound 1.9.0).
Mar 16 00:17:17 unbound: [17174:0] notice: init module 1: iterator
Mar 16 00:17:17 unbound: [17174:0] notice: init module 0: validator
Mar 15 21:04:14 unbound: [93551:0] info: generate keytag query _ta-4f66. NULL IN
Mar 15 21:04:10 unbound: [93551:0] info: start of service (unbound 1.9.0).
Mar 15 21:04:10 unbound: [93551:0] notice: init module 1: iterator
Mar 15 21:04:10 unbound: [93551:0] notice: init module 0: validator
Mar 15 19:38:52 unbound: [77728:1] info: generate keytag query _ta-4f66. NULL IN
Mar 15 19:38:51 unbound: [77728:0] info: start of service (unbound 1.9.0).
Mar 15 19:38:51 unbound: [77728:0] notice: init module 1: iterator
Mar 15 19:38:51 unbound: [77728:0] notice: init module 0: validator
Mar 15 18:51:49 unbound: [5130:2] info: generate keytag query _ta-4f66. NULL IN
Mar 15 18:51:46 unbound: [5130:0] info: start of service (unbound 1.9.0).
Mar 15 18:51:46 unbound: [5130:0] notice: init module 1: iterator
Mar 15 18:51:46 unbound: [5130:0] notice: init module 0: validator
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: service stopped (unbound 1.9.0).
Mar 15 18:50:54 unbound: [84000:0] info: start of service (unbound 1.9.0).
Mar 15 18:50:54 unbound: [84000:0] notice: init module 1: iterator
Mar 15 18:50:54 unbound: [84000:0] notice: init module 0: validator
Mar 15 18:50:54 unbound: [84000:0] notice: Restart of unbound 1.9.0.
Mar 15 18:50:54 unbound: [84000:0] info: 0.131072 0.262144 5
Mar 15 18:50:54 unbound: [84000:0] info: lower(secs) upper(secs) recursions
Mar 15 18:50:54 unbound: [84000:0] info: [25%]=0.16384 median[50%]=0.196608 [75%]=0.229376
Mar 15 18:50:54 unbound: [84000:0] info: histogram of recursion processing times
Mar 15 18:50:54 unbound: [84000:0] info: average recursion processing time 0.152972 sec
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 3: 5 queries, 0 answers from cache, 5 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: 0.262144 0.524288 5
Mar 15 18:50:54 unbound: [84000:0] info: 0.131072 0.262144 6
Mar 15 18:50:54 unbound: [84000:0] info: lower(secs) upper(secs) recursions
Mar 15 18:50:54 unbound: [84000:0] info: [25%]=0.191147 median[50%]=0.251221 [75%]=0.380109
Mar 15 18:50:54 unbound: [84000:0] info: histogram of recursion processing times
Mar 15 18:50:54 unbound: [84000:0] info: average recursion processing time 0.236744 sec
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0
Mar 15 18:50:54 unbound: [84000:0] info: server stats for thread 2: 11 queries, 0 answers from cache, 11 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Mar 15 18:50:54 unbound: [84000:0] info: 1.000000 2.000000 1
Mar 15 18:50:54 unbound: [84000:0] info: 0.524288 1.000000 2

[chemlud]

PS: After my last post I found that I had configured only ONE DNS server (Digitalcourage) via TLS, add two more and up to now no more crashes....

Is there an easy way to setup a service watchdog for unbound? I think I asked this in the past, I'm getting old...

[chemlud]

But when starting to update the only client connected, I get within seconds:

Code Select Expand

Mar 16 14:46:00 kernel: -> pid: 53949 ppid: 1 p_pax: 0xa50<SEGVGUARD,ASLR,NOSHLIBRANDOM,NODISALLOWMAP32BIT>
Mar 16 14:46:00 kernel: [HBSD SEGVGUARD] [unbound (53949)] Suspension expired.
Mar 16 14:46:00 kernel: pid 53949 (unbound), uid 59: exited on signal 11


...after restarting unbound is stable enough to complete updates, waiting

[chemlud]

Did a Wireshark on the WAN interface of the OPNsense, last package received before unbound passed away was:

Code Select Expand

11652 2019-03-16 16:04:00.652225560 WAN_OPNsense 46.182.19.48 TCP 60 23837 ? 853 [RST] Seq=424 Win=0 Len=0
....

11672 2019-03-16 16:04:00.838704263 46.182.19.48 WAN_OPNsense TCP 66 853 ? 41185 [RST, ACK] Seq=1 Ack=2 Win=29056 Len=0 TSval=1447257805 TSecr=80176261

If I look upstream, I see the OPNsense sending RST packages to the DNS server every 20-30 packages, after Client Hello, Server Hello, a little TLSv1.2 traffic and and some TCP packages sent back and forth, the there is

"Encrypted Alert" from then OPNsense and FIN/ACK

then


"Encrypted Alert" from then DNS server and FIN/ACK

after that the OPNsense sends the RST package...

Of any help? More info needed?

[chemlud]

..started a pcap on the sense (WAN), to see what the alert is (or will the sense itself not be able to decrypt the package?)

[chemlud]

No, pcap on OPNsense doesn't give any clue on the "Encrypted Alert", this time the conversation on port 853 ended with

Code Select Expand

6835 2019-03-16 17:30:00.381892 89.233.43.71 WAN_OPNsense TLSv1.2 73 Alert (Level: Fatal, Description: Illegal Parameter)

..afterwards only FIN and FIN,ACK and unbound dies....

[chemlud]

Tried to find unbound 1.8.1 somewhere in the repos of opnsense, to no avail. Can anybody guide me how to transplant unbound 1.8.1 from another opnsense? Which files to copy over how and how to install?

[franco]

# opnsense-code ports tools
# cd /usr/ports/dns/unbound
# git checkout 18.7.6
# make package deinstall install

It is relatively easy to navigate the ports tree if you know the OPNsense version equivalent of what you're looking for. ;)


Cheers,
Franco