Unbound SEGV val_has_signed_nsecs

[tdownie]

Describe the bug
Unbound crashed with SEGV, generated a coredump and restarted

Feb 14 01:56:56 <HOSTNAME> systemd[1]: unbound.service: Main process exited, code=killed, status=11/SEGV
Feb 14 01:56:56 <HOSTNAME> systemd[1]: unbound.service: Failed with result 'signal'.
Feb 14 01:56:56 <HOSTNAME> systemd[1]: unbound.service: Consumed 1w 2d 8h 41min 41.855s CPU time.
Feb 14 01:56:56 <HOSTNAME> systemd[1]: unbound.service: Scheduled restart job, restart counter is at 1.
Feb 14 01:56:56 <HOSTNAME> systemd[1]: Stopped Unbound DNS server.
Feb 14 01:56:56 <HOSTNAME> systemd[1]: unbound.service: Consumed 1w 2d 8h 41min 41.855s CPU time.
Feb 14 01:56:56 <HOSTNAME> systemd[1]: Starting Unbound DNS server...
Feb 14 01:56:56 <HOSTNAME> systemd[1643278]: unbound.service: Executable /usr/lib/unbound/package-helper missing, skipping: No such file or directory
Feb 14 01:56:56 <HOSTNAME> systemd[1643279]: unbound.service: Executable /usr/lib/unbound/package-helper missing, skipping: No such file or directory
Feb 14 01:56:57 <HOSTNAME> unbound[1643280]: [1643280:0] info: start of service (unbound 1.19.3).
Feb 14 01:56:57 <HOSTNAME> systemd[1]: Started Unbound DNS server.

Coredump seems to show the seg fault occurred in a dnssec related function: val_has_signed_nsecs

Reading symbols from /usr/sbin/unbound...
[New LWP 5487]
[New LWP 5488]
[New LWP 5485]
[New LWP 5486]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/unbound -d'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000055ae82a0dd90 in val_has_signed_nsecs (reason=0x7fae33c90840, rep=0x7fad91d6a5f0) at validator/val_utils.c:1204
1204	validator/val_utils.c: No such file or directory.
[Current thread is 1 (Thread 0x7fae33c91640 (LWP 5487))]

System:

• Unbound version: 1.19.3
• OS: Ubuntu 22.04.5 LTS
• unbound -V output:

Version 1.19.3

Configure line: --build=x86_64-linux-gnu --prefix=/usr --includedir=/usr/include --mandir=/usr/share/man --infodir=/usr/share/info --sysconfdir=/etc --localstatedir=/var --libdir=/usr/lib/x86_64-linux-gnu --libexecdir=/usr/lib/x86_64-linux-gnu --disable-rpath --with-pidfile=/run/unbound.pid --with-rootkey-file=/var/lib/unbound/root.key --with-libevent --with-ssl --enable-subnet --enable-systemd --with-chroot-dir= --libdir=/usr/lib
Linked libs: libevent 2.1.12-stable (it uses epoll), OpenSSL 3.0.2 15 Mar 2022
Linked modules: dns64 subnetcache respip validator iterator

Additional information
Full GDB output from coredump:

Reading symbols from /usr/sbin/unbound...
[New LWP 5487]
[New LWP 5488]
[New LWP 5485]
[New LWP 5486]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/unbound -d'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000055ae82a0dd90 in val_has_signed_nsecs (reason=0x7fae33c90840, rep=0x7fad91d6a5f0) at validator/val_utils.c:1204
1204	validator/val_utils.c: No such file or directory.
[Current thread is 1 (Thread 0x7fae33c91640 (LWP 5487))]
Warning: 'set logging on', an alias for the command 'set logging enabled', is deprecated.
Use 'set logging enabled on'.


Thread 4 (Thread 0x7fae34492640 (LWP 5486)):
#0  0x00007fae348dde2e in epoll_wait () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fae34f1609c in ?? () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#2  0x00007fae34f0d5d1 in event_base_loop () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#3  0x000055ae82a63d5d in ub_event_base_dispatch (base=<optimized out>) at util/ub_event.c:280
#4  comm_base_dispatch.isra.0 (b=<optimized out>, b=<optimized out>) at util/netevent.c:282
#5  0x000055ae829a9944 in worker_work (worker=0x55aea21f7ca0, worker=0x55aea21f7ca0) at daemon/worker.c:2330
#6  thread_start (arg=0x55aea21f7ca0) at daemon/daemon.c:632
#7  0x00007fae3484cac3 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x00007fae348de850 in ?? () from /lib/x86_64-linux-gnu/libc.so.6

Thread 3 (Thread 0x7fae345287c0 (LWP 5485)):
#0  0x00007fae348dde2e in epoll_wait () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fae34f1609c in ?? () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#2  0x00007fae34f0d5d1 in event_base_loop () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#3  0x000055ae82a63d5d in ub_event_base_dispatch (base=<optimized out>) at util/ub_event.c:280
#4  comm_base_dispatch.isra.0 (b=<optimized out>, b=<optimized out>) at util/netevent.c:282
#5  0x000055ae829ae85c in worker_work (worker=<optimized out>, worker=<optimized out>) at daemon/worker.c:2332
#6  daemon_fork (daemon=<optimized out>) at daemon/daemon.c:795
#7  0x000055ae829ba656 in run_daemon (cfgfile=0x55ae82a7a279 "/etc/unbound/unbound.conf", cmdline_verbose=0, debug_mode=1, need_pidfile=1) at daemon/unbound.c:736
#8  0x000055ae829a7505 in main (argc=<optimized out>, argv=0x7ffc109b0138) at daemon/unbound.c:838

Thread 2 (Thread 0x7fae33490640 (LWP 5488)):
#0  0x00007fae34b8e3c5 in OPENSSL_LH_doall_arg () from /lib/x86_64-linux-gnu/libcrypto.so.3
#1  0x00007fae34b970cb in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.3
#2  0x00007fae34b87005 in EVP_PKEY_set_type_by_keymgmt () from /lib/x86_64-linux-gnu/libcrypto.so.3
#3  0x00007fae34b7f5aa in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.3
#4  0x00007fae34b873cd in EVP_PKEY_fromdata () from /lib/x86_64-linux-gnu/libcrypto.so.3
#5  0x000055ae82a44597 in sldns_ecdsa2pkey_raw (key=<optimized out>, keylen=64, algo=<optimized out>) at sldns/keyraw.c:609
#6  0x000055ae82a1c54f in setup_key_digest (keylen=64, key=0x7fad9bfa5dd4 "\246L\251\203M\251\240\251Z\220ɢp\261\260x\377>|2\205['\224\271\205吟\252\205\221\360\254vj\373\024RxI\276\377\257-\333\316\332b}-\237\362\021ó\333\036]<rq\372", <incomplete sequence \350>, digest_type=<synthetic pointer>, evp_key=<synthetic pointer>, algo=<optimized out>) at validator/val_secalgo.c:629
#7  verify_canonrrset (reason=0x7fae3348f3e0, keylen=64, key=0x7fad9bfa5dd4 "\246L\251\203M\251\240\251Z\220ɢp\261\260x\377>|2\205['\224\271\205吟\252\205\221\360\254vj\373\024RxI\276\377\257-\333\316\332b}-\237\362\021ó\333\036]<rq\372", <incomplete sequence \350>, sigblock_len=<optimized out>, sigblock=0x7fad9a4ca115 "Ƿ\327\354V\255\232#\201 -Q\214%tg\275\350\225\360\335\346K{o\241v\025s@\261\210ͰʑI\305~\367\337Tl\272\373j/\237l\n\r\340\233\374\335{\267\306\352\341\002ſ\003", algo=<optimized out>, buf=0x7fae15d7e310) at validator/val_secalgo.c:750
#8  dnskey_verify_rrset_sig (region=<optimized out>, buf=<optimized out>, ve=ve@entry=0x55aea21e2210, now=now@entry=1739498210, rrset=rrset@entry=0x7fad9a4c9d88, dnskey=dnskey@entry=0x7fae3348f280, dnskey_idx=1, sig_idx=0, sortree=0x7fae3348f0e8, buf_canon=0x7fae3348f0e4, reason=0x7fae3348f3e0, reason_bogus=0x7fae3348f3d4, section=LDNS_SECTION_AUTHORITY, qstate=0x7fad9bfa4030) at validator/val_sigcrypt.c:1677
#9  0x000055ae82a1d16f in dnskeyset_verify_rrset_sig (numverified=0x7fae3348f420, qstate=0x7fad9bfa4030, section=LDNS_SECTION_AUTHORITY, reason_bogus=0x7fae3348f3d4, reason=0x7fae3348f3e0, sortree=0x7fae3348f0e8, sig_idx=0, dnskey=0x7fae3348f280, rrset=0x7fad9a4c9d88, now=1739498210, ve=0x55aea21e2210, env=0x55aea21fbfa8) at validator/val_sigcrypt.c:588
#10 dnskeyset_verify_rrset (env=0x55aea21fbfa8, ve=0x55aea21e2210, rrset=0x7fad9a4c9d88, dnskey=0x7fae3348f280, sigalg=0x0, reason=0x7fae3348f3e0, reason_bogus=0x7fae3348f3d4, section=LDNS_SECTION_AUTHORITY, qstate=0x7fad9bfa4030, verified=0x7fae3348f420) at validator/val_sigcrypt.c:657
#11 0x000055ae82a1fd5e in val_verify_rrset (verified=0x7fae3348f420, qstate=0x7fad9bfa4030, section=LDNS_SECTION_AUTHORITY, reason_bogus=0x7fae3348f3d4, reason=0x7fae3348f3e0, sigalg=<optimized out>, keys=0x7fae3348f280, rrset=0x7fad9a4c9d88, ve=0x55aea21e2210, env=0x55aea21fbfa8) at validator/val_utils.c:368
#12 val_verify_rrset_entry (env=0x55aea21fbfa8, ve=0x55aea21e2210, rrset=0x7fad9a4c9d88, kkey=<optimized out>, reason=0x7fae3348f3e0, reason_bogus=0x7fae3348f3d4, section=LDNS_SECTION_AUTHORITY, qstate=0x7fad9bfa4030, verified=0x7fae3348f420) at validator/val_utils.c:417
#13 0x000055ae82a0e6a8 in list_is_secure (qstate=0x7fad9bfa4030, reason_bogus=0x7fae3348f3d4, reason=0x7fae3348f3e0, kkey=0x7fad9bfa5c48, num=3, list=0x7fad9babc208, ve=0x55aea21e2210, env=0x55aea21fbfa8) at validator/val_nsec3.c:1462
#14 nsec3_prove_nods (ct=0x7fad9bfa53f8, qstate=0x7fad9bfa4030, reason_bogus=0x7fae3348f3d4, reason=0x7fae3348f3e0, kkey=0x7fad9bfa5c48, qinfo=0x7fad9bab8320, num=3, list=0x7fad9babc208, ve=0x55aea21e2210, env=0x55aea21fbfa8) at validator/val_nsec3.c:1494
#15 ds_response_to_ke (ke=<synthetic pointer>, qinfo=0x7fad9bab8320, msg=<optimized out>, rcode=<optimized out>, id=<optimized out>, vq=<optimized out>, qstate=<optimized out>) at validator/validator.c:2896
#16 process_ds_response (qstate=<optimized out>, vq=<optimized out>, id=<optimized out>, rcode=<optimized out>, msg=<optimized out>, qinfo=0x7fad9bab8320, origin=0x7fad9a4ca498, suspend=0x7fae3348f5b8) at validator/validator.c:3027
#17 0x000055ae82a1999d in val_inform_super (qstate=0x7fad9bab8320, id=0, super=0x7fad9bfa4030) at validator/validator.c:3296
#18 0x000055ae829e790b in mesh_walk_supers (mesh=mesh@entry=0x7fae15d6da60, mstate=mstate@entry=0x7fad9bab82d0) at services/mesh.c:1575
#19 0x000055ae829ee2ba in mesh_continue (ev=<synthetic pointer>, s=<optimized out>, mstate=0x7fad9bab82d0, mesh=0x7fae15d6da60) at services/mesh.c:1822
#20 mesh_run (mesh=0x7fae15d6da60, mstate=0x7fad9bab82d0, ev=<optimized out>, e=0x0) at services/mesh.c:1882
#21 0x000055ae829b63f7 in mesh_report_reply (what=0, reply=0x7fae3348fa70, e=0x7fad9babc158, mesh=<optimized out>) at services/mesh.c:822
#22 worker_handle_service_reply (c=0x7fae15c5f270, arg=0x7fad9babc158, error=0, reply_info=0x7fae3348fa70) at daemon/worker.c:268
#23 0x000055ae82a42f2f in serviced_callbacks (sq=<optimized out>, error=0, c=0x7fae15c5f270, rep=<optimized out>) at services/outside_network.c:3051
#24 0x000055ae82a43da0 in serviced_udp_callback (c=0x7fae15c5f270, arg=0x7fadf90b4400, error=<optimized out>, rep=0x7fae3348fa70) at services/outside_network.c:3392
#25 0x000055ae82a40c9c in outnet_udp_cb (c=<optimized out>, arg=0x7fae14c51f70, error=<optimized out>, reply_info=0x7fae3348fa70) at services/outside_network.c:1537
#26 0x000055ae82a38049 in comm_point_udp_callback (fd=1191, event=<optimized out>, arg=<optimized out>) at util/netevent.c:1145
#27 0x00007fae34f0bf58 in ?? () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#28 0x00007fae34f0d8a7 in event_base_loop () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#29 0x000055ae82a63d5d in ub_event_base_dispatch (base=<optimized out>) at util/ub_event.c:280
#30 comm_base_dispatch.isra.0 (b=<optimized out>, b=<optimized out>) at util/netevent.c:282
#31 0x000055ae829a9944 in worker_work (worker=0x55aea21faa80, worker=0x55aea21faa80) at daemon/worker.c:2330
#32 thread_start (arg=0x55aea21faa80) at daemon/daemon.c:632
#33 0x00007fae3484cac3 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#34 0x00007fae348de850 in ?? () from /lib/x86_64-linux-gnu/libc.so.6

Thread 1 (Thread 0x7fae33c91640 (LWP 5487)):
#0  0x000055ae82a0dd90 in val_has_signed_nsecs (reason=0x7fae33c90840, rep=0x7fad91d6a5f0) at validator/val_utils.c:1204
#1  ds_response_to_ke (ke=<synthetic pointer>, qinfo=0x7fad91d6a570, msg=0x7fad91d6a570, rcode=0, id=-1848203920, vq=0x7fad92e25478, qstate=0x7fad93cbd350) at validator/validator.c:2847
#2  process_ds_response (qstate=qstate@entry=0x7fad93cbd350, vq=vq@entry=0x7fad92e25478, id=id@entry=0, rcode=rcode@entry=0, msg=0x7fad91d6a570, qinfo=0x7fad91d6a570, origin=0x0, suspend=0x7fae33c90a40) at validator/validator.c:3027
#3  0x000055ae82a0f086 in processFindKey (id=0, vq=0x7fad92e25478, qstate=0x7fad93cbd350) at validator/validator.c:2065
#4  val_handle (qstate=<optimized out>, vq=<optimized out>, ve=0x55aea21e2210, id=0) at validator/validator.c:2564
#5  0x000055ae829ede42 in mesh_run (mesh=0x7fae1dd6da60, mstate=0x7fad93cbd300, ev=<optimized out>, e=<optimized out>) at services/mesh.c:1872
#6  0x00007fae34f0be68 in ?? () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#7  0x00007fae34f0d8a7 in event_base_loop () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#8  0x000055ae82a63d5d in ub_event_base_dispatch (base=<optimized out>) at util/ub_event.c:280
#9  comm_base_dispatch.isra.0 (b=<optimized out>, b=<optimized out>) at util/netevent.c:282
#10 0x000055ae829a9944 in worker_work (worker=0x55aea21f9390, worker=0x55aea21f9390) at daemon/worker.c:2330
#11 thread_start (arg=0x55aea21f9390) at daemon/daemon.c:632
#12 0x00007fae3484cac3 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#13 0x00007fae348de850 in ?? () from /lib/x86_64-linux-gnu/libc.so.6

Please let me know what additional information I could provide that would be helpful!

[tdownie]

Had some help looking at the corefile. It seems there's an invalid pointer dereferenced:

(gdb) bt
#0  0x000055ae82a0dd90 in val_has_signed_nsecs (reason=0x7fae33c90840, rep=0x7fad91d6a5f0) at validator/val_utils.c:1204
#1  ds_response_to_ke (ke=<synthetic pointer>, qinfo=0x7fad91d6a570, msg=0x7fad91d6a570, rcode=0, id=-1848203920, vq=0x7fad92e25478, qstate=0x7fad93cbd350)
    at validator/validator.c:2847
#2  process_ds_response (qstate=qstate@entry=0x7fad93cbd350, vq=vq@entry=0x7fad92e25478, id=id@entry=0, rcode=rcode@entry=0, msg=0x7fad91d6a570, qinfo=0x7fad91d6a570, origin=0x0,
    suspend=0x7fae33c90a40) at validator/validator.c:3027
#3  0x000055ae82a0f086 in processFindKey (id=0, vq=0x7fad92e25478, qstate=0x7fad93cbd350) at validator/validator.c:2065
#4  val_handle (qstate=<optimized out>, vq=<optimized out>, ve=0x55aea21e2210, id=0) at validator/validator.c:2564
#5  0x000055ae829ede42 in mesh_run (mesh=0x7fae1dd6da60, mstate=0x7fad93cbd300, ev=<optimized out>, e=<optimized out>) at services/mesh.c:1872
#6  0x00007fae34f0be68 in ?? () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#7  0x00007fae34f0d8a7 in event_base_loop () from /lib/x86_64-linux-gnu/libevent-2.1.so.7
#8  0x000055ae82a63d5d in ub_event_base_dispatch (base=<optimized out>) at util/ub_event.c:280
#9  comm_base_dispatch.isra.0 (b=<optimized out>, b=<optimized out>) at util/netevent.c:282
#10 0x000055ae829a9944 in worker_work (worker=0x55aea21f9390, worker=0x55aea21f9390) at daemon/worker.c:2330
#11 thread_start (arg=0x55aea21f9390) at daemon/daemon.c:632
#12 0x00007fae3484cac3 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#13 0x00007fae348de850 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) p i
$1 = 0
(gdb) p rep
$2 = (struct reply_info *) 0x7fad91d6a5f0
(gdb) p *rep
$3 = {flags = 32896, authoritative = 0 '\000', qdcount = 1 '\001', padding = 0, ttl = 4, prefetch_ttl = 4, serve_expired_ttl = 4, security = sec_status_indeterminate,
  reason_bogus = LDNS_EDE_NONE, reason_bogus_str = 0x0, an_numrrsets = 0, ns_numrrsets = 1, ar_numrrsets = 0, rrset_count = 1, rrsets = 0x7fad93bd2f48, ref = {{
      key = 0x7fad93bd2f50, id = 0}}}
(gdb) p rep->rrsets
$4 = (struct ub_packed_rrset_key **) 0x7fad93bd2f48
(gdb) p rep->rrsets[i]
$5 = (struct ub_packed_rrset_key *) 0x10000000000e3
(gdb) p rep->rrsets[i]->rk
Cannot access memory at address 0x1000000000153

The code dies on line 1204, since rep->rrsets[i] is an invalid pointer.

int val_has_signed_nsecs(struct reply_info* rep, char** reason)
{
	size_t i, num_nsec = 0, num_nsec3 = 0;
	struct packed_rrset_data* d;
	for(i=rep->an_numrrsets; i<rep->an_numrrsets+rep->ns_numrrsets; i++) {
		if(rep->rrsets[i]->rk.type == htons(LDNS_RR_TYPE_NSEC)) 
			num_nsec++;
		else if(rep->rrsets[i]->rk.type == htons(LDNS_RR_TYPE_NSEC3))
			num_nsec3++;
		else continue;
		d = (struct packed_rrset_data*)rep->rrsets[i]->entry.data;
		if(d && d->rrsig_count != 0) {
			return 1;
		}
	}
	if(num_nsec == 0 && num_nsec3 == 0)
		*reason = "no DNSSEC records";
	else if(num_nsec != 0)
		*reason = "no signatures over NSECs";
	else	*reason = "no signatures over NSEC3s";
	return 0;
}

[wcawijngaards]

This seems to be a validation effort, on a DS response. The DS responses is returned from cache, it is a negative cache response from the negative cache. The response contains a single RRset in the authority section, that should have been an NSEC or NSEC3 record, but that causes the wrong rrset pointer dereference. The code path that creates this response does not have a flaw, for having the counter at one rrset, but then the rrset pointer is a garbage value.

The not so useful idea I can have about what is wrong is that the compiler and in particular its optimization option is perhaps aggressively removed the assignment of this value in some case. That would mean a recompile without optimization or a different compiler version would fix it. But it seems unlikely as I figure it would be very obviously wrong for every other lookup or so. So this seems too unlikely.

More likely a bug in unbound of some sort, but I can only speculate where or how. Is there a way to reproduce the failure?

[tdownie]

I haven't figured out how to reproduce it yet but will try to find more time to test it.