Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

unbound.service: Main process exited, code=killed, status=11/SEGV #925

Closed
jpgpi250 opened this issue Aug 19, 2023 · 7 comments
Closed

unbound.service: Main process exited, code=killed, status=11/SEGV #925

jpgpi250 opened this issue Aug 19, 2023 · 7 comments

Comments

@jpgpi250
Copy link

Describe the bug
unbound doesn't start
sudo service unbound status returns:
ExecStart=/usr/sbin/unbound -d -v (code=killed, signal=SEGV)

To reproduce
compile master from github (cloned today (19/08/23)
sudo ./configure --prefix=/usr --sysconfdir=/etc --disable-static --enable-tfo-client --enable-tfo-server --with-libevent --with-libhiredis --enable-cachedb --with-pidfile=/run/unbound.pid
sudo make
sudo make install

System:
@wcawijngaards
Copy link
Member

Could you perhaps run valgrind /usr/sbin/unbound -dd -vvvv from the root commandline? That should use valgrind as a debugger, set -dd to log the output to the console, and -vvvv to increase verbosity, it could print detail logs and also the debugger output from valgrind. It is also possible to use gdb to make a stack trace, if you like.

@jpgpi250
Copy link
Author

don't have valgrind on the system.
ran "sudo gdb /usr/sbin/unbound"
result:

GNU gdb (Debian 10.1-1.7) 10.1.90.20210103-git
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "aarch64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/unbound...
(gdb) run
Starting program: /usr/sbin/unbound
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
strcmp () at ../sysdeps/aarch64/strcmp.S:64
64      ../sysdeps/aarch64/strcmp.S: No such file or directory.
(gdb) quit
A debugging session is active.

        Inferior 1 [process 932485] will be killed.

Quit anyway? (y or n) y

@wcawijngaards
Copy link
Member

wcawijngaards commented Aug 21, 2023 •
edited

Could you run sudo gdb --args /usr/sbin/unbound -dd -vvvv and then run and then bt to print a stack trace? The run can also be without the arguments as the posted output already has, but the stack trace would be useful. Perhaps there is also a configuration file element that is particularly interesting, if it is failing in that portion, eg. some type of config file syntax.

@jpgpi250
Copy link
Author

as requested, "sudo gdb --args /usr/sbin/unbound -dd -vvvv" , "run", "bt"

GNU gdb (Debian 10.1-1.7) 10.1.90.20210103-git
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "aarch64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/unbound...
(gdb) run
Starting program: /usr/sbin/unbound -dd -vvvv
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1".
[1692609002] unbound[944007:0] notice: Start of unbound 1.17.2.
Aug 21 11:10:02 unbound[944007:0] debug: increased limit(open files) from 2048 to 32998
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 192.168.2.47 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 127.10.10.2 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating udp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp6 socket fdaa:bbcc:ddee:2::5552 5552
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp6 socket ::1 8953
Aug 21 11:10:02 unbound[944007:0] debug: creating tcp4 socket 127.0.0.1 8953
Aug 21 11:10:02 unbound[944007:0] debug: setup SSL certificates
Aug 21 11:10:02 unbound[944007:0] debug: chdir to /etc/unbound
Aug 21 11:10:02 unbound[944007:0] debug: chroot to /etc/unbound
Aug 21 11:10:02 unbound[944007:0] debug: drop user privileges, run as unbound
Aug 21 11:10:02 unbound[944007:0] debug: switching log to stderr
Aug 21 11:10:02 unbound[944007:0] debug: module config: "respip validator cachedb iterator"
Aug 21 11:10:02 unbound[944007:0] notice: init module 0: respip
Aug 21 11:10:02 unbound[944007:0] notice: init module 1: validator
Aug 21 11:10:02 unbound[944007:0] debug: reading autotrust anchor file /root.key
Aug 21 11:10:02 unbound[944007:0] info: trust point . : 1
Aug 21 11:10:02 unbound[944007:0] info: assembled 0 DS and 1 DNSKEYs
Aug 21 11:10:02 unbound[944007:0] info: DNSKEY:: .      86400   IN      DNSKEY  257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ;{id = 20326 (ksk), size = 2048b}

Aug 21 11:10:02 unbound[944007:0] info: file /root.key
Aug 21 11:10:02 unbound[944007:0] info: last_queried: 1692605062 Mon Aug 21 10:04:22 2023
Aug 21 11:10:02 unbound[944007:0] info: last_success: 1692605062 Mon Aug 21 10:04:22 2023
Aug 21 11:10:02 unbound[944007:0] info: next_probe_time: 1692690467 Tue Aug 22 09:47:47 2023
Aug 21 11:10:02 unbound[944007:0] info: query_interval: 86399
Aug 21 11:10:02 unbound[944007:0] info: retry_time: 17279
Aug 21 11:10:02 unbound[944007:0] info: query_failed: 0
Aug 21 11:10:02 unbound[944007:0] info: [  VALID  ] .   86400   IN      DNSKEY  257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ;{id = 20326 (ksk), size = 2048b} ;;state:2 ;;pending_count:0 last:Sun Jul 16 09:19:42 2023
Aug 21 11:10:02 unbound[944007:0] debug: validator nsec3cfg keysz 1024 mxiter 150
Aug 21 11:10:02 unbound[944007:0] debug: validator nsec3cfg keysz 2048 mxiter 150
Aug 21 11:10:02 unbound[944007:0] debug: validator nsec3cfg keysz 4096 mxiter 150
Aug 21 11:10:02 unbound[944007:0] notice: init module 2: cachedb

Program received signal SIGSEGV, Segmentation fault.
strcmp () at ../sysdeps/aarch64/strcmp.S:64
64      ../sysdeps/aarch64/strcmp.S: No such file or directory.
(gdb) bt
#0  strcmp () at ../sysdeps/aarch64/strcmp.S:64
#1  0x00000055555bbb2c in cachedb_find_backend (str=0x80 <error: Cannot access memory at address 0x80>) at cachedb/cachedb.c:215
#2  cachedb_apply_cfg (cfg=<optimized out>, cfg=<optimized out>, cachedb_env=0x555574c570) at cachedb/cachedb.c:229
#3  cachedb_init (env=0x555568f560, id=<optimized out>) at cachedb/cachedb.c:249
#4  0x000000555555e820 in modstack_setup (module_conf=<optimized out>, env=0x555568f560, stack=0x555566c388) at services/modstack.c:241
#5  modstack_setup (env=0x555568f560, module_conf=<optimized out>, stack=0x555566c388) at services/modstack.c:226
#6  daemon_setup_modules (daemon=daemon@entry=0x555566c2a0) at daemon/daemon.c:453
#7  0x0000005555561908 in daemon_fork (daemon=0x555566c2a0) at daemon/daemon.c:732
#8  0x000000555555b354 in run_daemon (need_pidfile=1, debug_mode=2, cmdline_verbose=4, cfgfile=0x555561005c "/unbound.conf") at daemon/unbound.c:736
#9  main (argc=<optimized out>, argv=<optimized out>) at daemon/unbound.c:838
(gdb) quit
A debugging session is active.

        Inferior 1 [process 944007] will be killed.

Quit anyway? (y or n) y

@wcawijngaards
Copy link
Member

That is really useful, thanks! So cachedb/cachedb.c:215 it is.

wcawijngaards added a commit that referenced this issue Aug 21, 2023
@wcawijngaards
- Fix for #925: unbound.service: Main process exited, code=killed,
3160d6a 
  status=11/SEGV. Fixes cachedb configuration handling.
@wcawijngaards
Copy link
Member

The committed fix helps the stack trace that was reported from crashing, based on NULL pointers and would allow an empty backend to turn off the cachedb. However, the 0x80 pointer in the stack trace is not something that seems possible. Is it possible to perform a clean recompile to make sure, eg, sudo make clean followed by sudo make? Perhaps it is only dependencies.

@jpgpi250
Copy link
Author

  • sudo git pull origin master
  • sudo ./configure --prefix=/usr --sysconfdir=/etc --disable-static --enable-tfo-client --enable-tfo-server --with-libevent --with-libhiredis --enable-cachedb --with-pidfile=/run/unbound.pid
  • sudo make clean
  • sudo make
  • sudo make install
  • sudo service unbound start
  • sudo service unbound status
● unbound.service - Validating, recursive, and caching DNS resolver
     Loaded: loaded (/lib/systemd/system/unbound.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2023-08-21 11:47:16 CEST; 4s ago
       Docs: man:unbound(8)
    Process: 959481 ExecStartPre=/etc/unbound/resolvconf.sh (code=exited, status=0/SUCCESS)
    Process: 959482 ExecStartPre=/etc/unbound/ipv6up.sh (code=exited, status=0/SUCCESS)
    Process: 959486 ExecStartPre=/usr/sbin/unbound-anchor -a /etc/unbound/root.key -v (code=exited, status=0/SUCCESS)
   Main PID: 959487 (unbound)
      Tasks: 4 (limit: 779)
        CPU: 1.771s
     CGroup: /system.slice/unbound.service
             └─959487 /usr/sbin/unbound -d -v

Aug 21 11:47:15 raspberrypi systemd[1]: Starting Validating, recursive, and caching DNS resolver...
Aug 21 11:47:16 raspberrypi unbound-anchor[959486]: /etc/unbound/root.key has content
Aug 21 11:47:16 raspberrypi unbound-anchor[959486]: success: the anchor is ok
Aug 21 11:47:16 raspberrypi systemd[1]: Started Validating, recursive, and caching DNS resolver.
Aug 21 11:47:16 raspberrypi unbound[959487]: [1692611236] unbound[959487:0] notice: Start of unbound 1.17.2.

fixed!, thanks for your time, effort and very quick response, much appreciated.

jedisct1 added a commit to jedisct1/unbound that referenced this issue Sep 4, 2023
@jedisct1
Merge remote-tracking branch 'nlnet/master'
204d3d8 
* nlnet/master: (44 commits)
  - Fix NLnetLabs#927: unbound 1.18.0 make test error. Fix make test without SHA1.
  - Fix autoconf 2.69 warnings in configure.
  - Fix for WKS call to getservbyname that creates allocation on exit   in unit test by testing numbers first and testing from the services   list later.
  Tag 1.18.0rc1 became the 1.18.0 release on 30 aug 2023, with the fix from 25 aug, fix compile on NetBSD included. The repository continues with version 1.18.1.
  - Fix for version generation race condition that ignored changes.
  - Fix compile error on NetBSD in util/netevent.h.
  - Tag for 1.18.0rc1 release.
  - Set version number to 1.18.0.
  - Fix unit test for unbound-control to work when threads are disabled,   and fix cache dump check.
  - Fix NLnetLabs#923: processQueryResponse() THROWAWAY should be mindful of   fail_reply.
  - Fix for NLnetLabs#925: unbound.service: Main process exited, code=killed,   status=11/SEGV. Fixes cachedb configuration handling.
  - Fix windows ci workflow to install bison and flex.
  Further debug for windows ci workflow.
  - Debug Windows ci workflow.
  - Fix stat_values test to work with dig that enables DNS cookies.
  - Fix uninitialized memory passed in padding bytes of cmsg to sendmsg.
  Changelog for commit. - Fix for iter_dec_attempts that could cause a hang, part of   capsforid and qname minimisation, depending on the settings.
  - Fix for iter_dec_attempts that could cause a hang, part of   capsforid and qname minimisation, depending on the settings.
  - Fix ip_ratelimit test to work with dig that enables DNS cookies.
  - Fix regional_alloc_init for potential unaligned source of the copy.
  ...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@wcawijngaards @jpgpi250