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.

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

doq bug #1185

Open
liang-hiwin opened this issue Nov 15, 2024 · 28 comments · May be fixed by #1187
Open

doq bug #1185

liang-hiwin opened this issue Nov 15, 2024 · 28 comments · May be fixed by #1187

Comments

@liang-hiwin
Copy link

unbound -V
Version 1.22.0

Configure line: --enable-subnet --with-libevent --without-pthreads --without-solaris-threads --with-ssl --enable-dnscrypt --with-libhiredis --enable-cachedb --enable-tfo-client --enable-tfo-server --enable-ipset --with-ssl=/usr/local/openssl-3.0.15-quic1 --with-libngtcp2=/usr/local/ngtcp2-1.8.1 LDFLAGS=-Wl,-rpath -Wl,/usr/local/ngtcp2-1.8.1/lib --prefix=/usr/local
Linked libs: libevent 2.1.12-stable (it uses epoll), OpenSSL 3.0.15+quic 3 Sep 2024
Linked modules: dns64 cachedb subnetcache ipset respip validator iterator
DNSCrypt feature available
TCP Fastopen feature available

#######################################################

./unbound -c /usr/local/etc/unbound/unbound.conf -dd -vvvv
[1731685084] unbound[3135312:0] notice: Start of unbound 1.22.0.
[1731685084] unbound[3135312:0] debug: creating udp4 socket 127.0.0.1 5353
[1731685084] unbound[3135312:0] debug: creating tcp4 socket 127.0.0.1 5353
[1731685084] unbound[3135312:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1731685084] unbound[3135312:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1731685084] unbound[3135312:0] debug: setup TCP for SSL service
[1731685084] unbound[3135312:0] debug: creating udp4 socket 127.0.0.1 5353
[1731685084] unbound[3135312:0] debug: creating tcp4 socket 127.0.0.1 5353
[1731685084] unbound[3135312:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1731685084] unbound[3135312:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1731685084] unbound[3135312:0] debug: setup TCP for SSL service
[1731685084] unbound[3135312:0] debug: module config: "subnetcache validator iterator"
[1731685084] unbound[3135312:0] debug: chdir to /usr/local/etc/unbound
[1731685084] unbound[3135312:0] debug: chroot to /usr/local/etc/unbound
[1731685084] unbound[3135312:0] debug: drop user privileges, run as root
[1731685084] unbound[3135312:0] debug: switching log to stderr
[1731685084] unbound[3135312:0] debug: Forward zone server list:
[1731685084] unbound[3135312:0] info: DelegationPoint<.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
[1731685084] unbound[3135312:0] debug:    ip4 127.0.0.1 port 35354 (len 16)
[1731685084] unbound[3135312:0] debug: no config, using builtin root hints.
[1731685084] unbound[3135312:0] notice: init module 0: subnetcache
[1731685084] unbound[3135312:0] warning: subnetcache: serve-expired is set but not working for data originating from the subnet module cache.
[1731685084] unbound[3135312:0] warning: subnetcache: prefetch is set but not working for data originating from the subnet module cache.
[1731685084] unbound[3135312:0] debug: send-client-subnet: ::0/0
[1731685084] unbound[3135312:0] debug: send-client-subnet: 0.0.0.0/0
[1731685084] unbound[3135312:0] debug: subnetcache: option registered (8)
[1731685084] unbound[3135312:0] notice: init module 1: validator
[1731685084] unbound[3135312:0] debug: validator nsec3cfg keysz 1024 mxiter 150
[1731685084] unbound[3135312:0] debug: validator nsec3cfg keysz 2048 mxiter 150
[1731685084] unbound[3135312:0] debug: validator nsec3cfg keysz 4096 mxiter 150
[1731685084] unbound[3135312:0] notice: init module 2: iterator
[1731685084] unbound[3135312:0] debug: target fetch policy for level 0 is 3
[1731685084] unbound[3135312:0] debug: target fetch policy for level 1 is 2
[1731685084] unbound[3135312:0] debug: target fetch policy for level 2 is 1
[1731685084] unbound[3135312:0] debug: target fetch policy for level 3 is 0
[1731685084] unbound[3135312:0] debug: target fetch policy for level 4 is 0
[1731685084] unbound[3135312:0] debug: EDNS known options:
[1731685084] unbound[3135312:0] debug:   Code:    Bypass_cache_stage: Aggregate_mesh:
[1731685084] unbound[3135312:0] debug:   edns-cli YES                 NO
[1731685084] unbound[3135312:0] debug: total of 59447 outgoing ports available
[1731685084] unbound[3135312:0] debug: start threads
[1731685084] unbound[3135312:0] debug: libevent 2.1.12-stable uses epoll method.
[1731685084] unbound[3135313:1] debug: libevent 2.1.12-stable uses epoll method.
[1731685084] unbound[3135313:1] error: doq: error for cert file: /etc/nginx/conf.d/crt.crt
[1731685084] unbound[3135313:1] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1731685084] unbound[3135313:1] error: and additionally crypto error:10080002:BIO routines::system lib
[1731685084] unbound[3135313:1] error: and additionally crypto error:0A080002:SSL routines::system lib
[1731685084] unbound[3135313:1] error: could not create doq comm_point
[1731685084] unbound[3135313:1] debug: comm_point_close of 9: event_del
[1731685084] unbound[3135313:1] debug: close fd 9
[1731685084] unbound[3135313:1] error: can't create commpoint
[1731685084] unbound[3135313:1] debug: comm_point_close of 10: event_del
[1731685084] unbound[3135312:0] error: doq: error for cert file: /etc/nginx/conf.d/crt.crt
[1731685084] unbound[3135312:0] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1731685084] unbound[3135312:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1731685084] unbound[3135312:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1731685084] unbound[3135312:0] error: could not create doq comm_point
[1731685084] unbound[3135312:0] debug: comm_point_close of 5: event_del
[1731685084] unbound[3135312:0] debug: close fd 5
[1731685084] unbound[3135312:0] error: can't create commpoint
[1731685084] unbound[3135312:0] debug: comm_point_close of 6: event_del
[1731685084] unbound[3135313:1] error: could not create listening sockets
[1731685084] unbound[3135313:7259b60] fatal error: Could not initialize thread
[1731685084] unbound[3135312:0] error: could not create listening sockets
[1731685084] unbound[3135312:0] fatal error: Could not initialize main thread

@wcawijngaards
Copy link
Member

Unbound has a chroot feature, and it is enabled by default. In the log it also has logged that it chrooted, to /usr/local/etc/unbound. The file not found failures are for files not in the chroot directory. If those files are copied into the chroot it could work. Chroot can also be disabled, with the "" value. In the documentation,
https://unbound.docs.nlnetlabs.nl/en/latest/manpages/unbound.conf.html#unbound-conf-chroot .

For the rest it looks okay. It is starting doq service on 854.

@liang-hiwin
Copy link
Author

Unbound has a chroot feature, and it is enabled by default. In the log it also has logged that it chrooted, to /usr/local/etc/unbound. The file not found failures are for files not in the chroot directory. If those files are copied into the chroot it could work. Chroot can also be disabled, with the "" value. In the documentation, https://unbound.docs.nlnetlabs.nl/en/latest/manpages/unbound.conf.html#unbound-conf-chroot .

For the rest it looks okay. It is starting doq service on 854.

I copied the certificate file to the /usr/local/etc/unbound folder and the problem persisted

@gthess
Copy link
Member

gthess commented Nov 18, 2024

Unbound will still look for the whole path inside the chroot. You now have two different options. You either:

  • change the configuration option to tls-service-pem: "/crt.crt" for example, or
  • use the chroot path in the configuration option, then Unbound would understand that it is inside the chroot, like tls-service-pem: "/usr/local/etc/unbound/crt.crt".

Both options have the same effect; Unbound will expect to find the crt.crt file in the root directory inside the chroot.
If you still face issues, posting your configuration file may shed some more light.

@liang-hiwin
Copy link
Author

liang-hiwin commented Nov 19, 2024

Unbound will still look for the whole path inside the chroot. You now have two different options. You either:

  • change the configuration option to tls-service-pem: "/crt.crt" for example, or
  • use the chroot path in the configuration option, then Unbound would understand that it is inside the chroot, like tls-service-pem: "/usr/local/etc/unbound/crt.crt".

Both options have the same effect; Unbound will expect to find the crt.crt file in the root directory inside the chroot. If you still face issues, posting y

After testing the two methods you gave with DOQ enabled, the bug still exists. But it is normal to turn on DOT alone.

./unbound -c /usr/local/etc/unbound/unbound.conf -dd -vvvv
[1732013571] unbound[3764293:0] notice: Start of unbound 1.22.0.
[1732013571] unbound[3764293:0] debug: creating udp4 socket 127.0.0.1 5353
[1732013571] unbound[3764293:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732013571] unbound[3764293:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1732013571] unbound[3764293:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732013571] unbound[3764293:0] debug: setup TCP for SSL service
[1732013571] unbound[3764293:0] debug: creating udp4 socket 127.0.0.1 5353
[1732013571] unbound[3764293:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732013571] unbound[3764293:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1732013571] unbound[3764293:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732013571] unbound[3764293:0] debug: setup TCP for SSL service
[1732013571] unbound[3764293:0] debug: module config: "subnetcache iterator"
[1732013571] unbound[3764293:0] debug: chdir to /usr/local/etc/unbound
[1732013571] unbound[3764293:0] debug: chroot to /usr/local/etc/unbound
[1732013571] unbound[3764293:0] debug: drop user privileges, run as root
[1732013571] unbound[3764293:0] debug: switching log to stderr
[1732013571] unbound[3764293:0] debug: Forward zone server list:
[1732013571] unbound[3764293:0] info: DelegationPoint<.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
[1732013571] unbound[3764293:0] debug:    ip4 127.0.0.1 port 35354 (len 16)
[1732013571] unbound[3764293:0] debug: no config, using builtin root hints.
[1732013571] unbound[3764293:0] notice: init module 0: subnetcache
[1732013571] unbound[3764293:0] warning: subnetcache: serve-expired is set but not working for data originating from the subnet module cache.
[1732013571] unbound[3764293:0] warning: subnetcache: prefetch is set but not working for data originating from the subnet module cache.
[1732013571] unbound[3764293:0] debug: send-client-subnet: ::0/0
[1732013571] unbound[3764293:0] debug: send-client-subnet: 0.0.0.0/0
[1732013571] unbound[3764293:0] debug: subnetcache: option registered (8)
[1732013571] unbound[3764293:0] notice: init module 1: iterator
[1732013571] unbound[3764293:0] debug: target fetch policy for level 0 is 3
[1732013571] unbound[3764293:0] debug: target fetch policy for level 1 is 2
[1732013571] unbound[3764293:0] debug: target fetch policy for level 2 is 1
[1732013571] unbound[3764293:0] debug: target fetch policy for level 3 is 0
[1732013571] unbound[3764293:0] debug: target fetch policy for level 4 is 0
[1732013571] unbound[3764293:0] debug: EDNS known options:
[1732013571] unbound[3764293:0] debug:   Code:    Bypass_cache_stage: Aggregate_mesh:
[1732013571] unbound[3764293:0] debug:   edns-cli YES                 NO
[1732013571] unbound[3764293:0] debug: total of 59447 outgoing ports available
[1732013571] unbound[3764293:0] debug: start threads
[1732013571] unbound[3764293:0] debug: libevent 2.1.12-stable uses epoll method.
[1732013571] unbound[3764294:1] debug: libevent 2.1.12-stable uses epoll method.
[1732013571] unbound[3764293:0] error: doq: error for cert file: /usr/local/etc/unbound/crt.crt
[1732013571] unbound[3764293:0] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732013571] unbound[3764293:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732013571] unbound[3764293:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732013571] unbound[3764293:0] error: could not create doq comm_point
[1732013571] unbound[3764293:0] debug: close fd 5
[1732013571] unbound[3764293:0] error: can't create commpoint
[1732013571] unbound[3764294:1] error: doq: error for cert file: /usr/local/etc/unbound/crt.crt
[1732013571] unbound[3764294:1] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732013571] unbound[3764294:1] error: and additionally crypto error:10080002:BIO routines::system lib
[1732013571] unbound[3764294:1] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732013571] unbound[3764294:1] error: could not create doq comm_point
[1732013571] unbound[3764294:1] debug: close fd 9
[1732013571] unbound[3764293:0] error: could not create listening sockets
[1732013571] unbound[3764293:0] fatal error: Could not initialize main thread
[1732013571] unbound[3764294:1] error: can't create commpoint
root@debian12:/usr/local/sbin# [1732013571] unbound[3764294:1] error: could not create listening sockets
[1732013571] unbound[3764294:42656b50] fatal error: Could not initialize thread

image

@liang-hiwin
Copy link
Author

liang-hiwin commented Nov 19, 2024

But it is normal to turn on DOT alone.

./unbound -c /usr/local/etc/unbound/unbound.conf -dd -vvvv
[1732013695] unbound[3764964:0] notice: Start of unbound 1.22.0.
[1732013695] unbound[3764964:0] debug: creating udp4 socket 127.0.0.1 5353
[1732013695] unbound[3764964:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732013695] unbound[3764964:0] debug: creating udp4 socket 0.0.0.0 854
[1732013695] unbound[3764964:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732013695] unbound[3764964:0] debug: setup TCP for SSL service
[1732013695] unbound[3764964:0] debug: creating udp4 socket 127.0.0.1 5353
[1732013695] unbound[3764964:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732013695] unbound[3764964:0] debug: creating udp4 socket 0.0.0.0 854
[1732013695] unbound[3764964:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732013695] unbound[3764964:0] debug: setup TCP for SSL service
[1732013695] unbound[3764964:0] debug: module config: "subnetcache iterator"
[1732013695] unbound[3764964:0] debug: chdir to /usr/local/etc/unbound
[1732013695] unbound[3764964:0] debug: chroot to /usr/local/etc/unbound
[1732013695] unbound[3764964:0] debug: drop user privileges, run as root
[1732013695] unbound[3764964:0] debug: switching log to stderr
[1732013695] unbound[3764964:0] debug: Forward zone server list:
[1732013695] unbound[3764964:0] info: DelegationPoint<.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
[1732013695] unbound[3764964:0] debug:    ip4 127.0.0.1 port 35354 (len 16)
[1732013695] unbound[3764964:0] debug: no config, using builtin root hints.
[1732013695] unbound[3764964:0] notice: init module 0: subnetcache
[1732013695] unbound[3764964:0] warning: subnetcache: serve-expired is set but not working for data originating from the subnet module cache.
[1732013695] unbound[3764964:0] warning: subnetcache: prefetch is set but not working for data originating from the subnet module cache.
[1732013695] unbound[3764964:0] debug: send-client-subnet: ::0/0
[1732013695] unbound[3764964:0] debug: send-client-subnet: 0.0.0.0/0
[1732013695] unbound[3764964:0] debug: subnetcache: option registered (8)
[1732013695] unbound[3764964:0] notice: init module 1: iterator
[1732013695] unbound[3764964:0] debug: target fetch policy for level 0 is 3
[1732013695] unbound[3764964:0] debug: target fetch policy for level 1 is 2
[1732013695] unbound[3764964:0] debug: target fetch policy for level 2 is 1
[1732013695] unbound[3764964:0] debug: target fetch policy for level 3 is 0
[1732013695] unbound[3764964:0] debug: target fetch policy for level 4 is 0
[1732013695] unbound[3764964:0] debug: EDNS known options:
[1732013695] unbound[3764964:0] debug:   Code:    Bypass_cache_stage: Aggregate_mesh:
[1732013695] unbound[3764964:0] debug:   edns-cli YES                 NO
[1732013695] unbound[3764964:0] debug: total of 59447 outgoing ports available
[1732013695] unbound[3764964:0] debug: start threads
[1732013695] unbound[3764964:0] debug: libevent 2.1.12-stable uses epoll method.
[1732013695] unbound[3764965:1] debug: libevent 2.1.12-stable uses epoll method.
[1732013695] unbound[3764964:0] debug: cache memory msg=33064 rrset=33064 infra=7952 val=0 subnet=41448
[1732013695] unbound[3764964:0] info: start of service (unbound 1.22.0).
[1732013695] unbound[3764965:1] debug: cache memory msg=33064 rrset=33064 infra=7952 val=0 subnet=41448

image

@gthess
Copy link
Member

gthess commented Nov 19, 2024

I see the issue.
TLS certificates and keys are read before the chroot. But the DoQ TLS context is created after the chroot. To work around the issue, you need to copy the certificates and keys inside the chroot directory and use relative names for the options:

tls-service-key: "key.key"
tls-service-pem: "crt.crt"

That will work for DoT which reads the files before the chroot, and also for DoQ which reads the files after the chroot.

I believe the correct solution to this is to create the DoQ TLS context also before the chroot is applied for consistency with the other TLS options.

@liang-hiwin
Copy link
Author

I see the issue. TLS certificates and keys are read before the chroot. But the DoQ TLS context is created after the chroot. To work around the issue, you need to copy the certificates and keys inside the chroot directory and use relative names for the options:

tls-service-key: "key.key"
tls-service-pem: "crt.crt"

That will work for DoT which reads the files before the chroot, and also for DoQ which reads the files after the chroot.

I believe the correct solution to this is to create the DoQ TLS context also before the chroot is applied for consistency with the other TLS options.

[1732020895] unbound[3786069:0] notice: Start of unbound 1.22.0.
[1732020895] unbound[3786069:0] debug: creating udp4 socket 127.0.0.1 5353
[1732020895] unbound[3786069:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732020895] unbound[3786069:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1732020895] unbound[3786069:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732020895] unbound[3786069:0] debug: setup TCP for SSL service
[1732020895] unbound[3786069:0] debug: creating udp4 socket 127.0.0.1 5353
[1732020895] unbound[3786069:0] debug: creating tcp4 socket 127.0.0.1 5353
[1732020895] unbound[3786069:0] debug: creating udp4 socket 0.0.0.0 854 doq
[1732020895] unbound[3786069:0] debug: creating tcp4 socket 0.0.0.0 854 tls
[1732020895] unbound[3786069:0] debug: setup TCP for SSL service
[1732020895] unbound[3786069:0] debug: module config: "subnetcache iterator"
[1732020895] unbound[3786069:0] error: error for cert file: crt.crt
[1732020895] unbound[3786069:0] error: error in SSL_CTX use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732020895] unbound[3786069:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732020895] unbound[3786069:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732020895] unbound[3786069:0] fatal error: could not set up listen SSL_CTX

@liang-hiwin
Copy link
Author

The only solution at the moment is to disable chroot, that is, add chroot:""

@gthess
Copy link
Member

gthess commented Nov 19, 2024

Did you copy the files in /usr/local/etc/unbound?

@liang-hiwin
Copy link
Author

liang-hiwin commented Nov 19, 2024

Did you copy the files in /usr/local/etc/unbound?

here,But the problem remains. dot is normal, but the problem is doq

image

@gthess
Copy link
Member

gthess commented Nov 19, 2024

I could reproduce the issue when hitting the chroot problem, but with the following minimal configuration it works for me here with and without chroot. The key.key and crt.crt files are in the chroot directory.

server:
	interface: 127.0.0.1@854
	interface: 0.0.0.0@854
	quic-port: 854
        tls-port: 854
	tls-service-key: key.key
	tls-service-pem: crt.crt

I see that you have a couple configuration files. Just to rule it out, can you make sure you are using the correct one?

@liang-hiwin
Copy link
Author

I could reproduce the issue when hitting the chroot problem, but with the following minimal configuration it works for me here with and without chroot. The key.key and crt.crt files are in the chroot directory.

server:
	interface: 127.0.0.1@854
	interface: 0.0.0.0@854
	quic-port: 854
        tls-port: 854
	tls-service-key: key.key
	tls-service-pem: crt.crt

I see that you have a couple configuration files. Just to rule it out, can you make sure you are using the correct one?

I run it according to the configuration you gave, but the problem still exists. I only have one configuration, and the file name with -t is used by me to test this problem separately, otherwise I will be disconnected from the Internet.

@gthess
Copy link
Member

gthess commented Nov 19, 2024

I am running out of ideas; not sure what is different in your case now.
How are the file permissions in the directory? Can you show the output of ls -al?

@liang-hiwin
Copy link
Author

I am running out of ideas; not sure what is different in your case now. How are the file permissions in the directory? Can you show the output of ls -al?

ls -al
total 36
drwxr-xr-x 2 root root 4096 Nov 19 20:53 .
drwxr-xr-x 3 root root 4096 Nov 15 22:10 ..
-rwxr-xr-x 1 root root 6333 Nov 16 18:57 crt.crt
-rw-r--r-- 1 root root   77 Nov 19 19:10 forward.conf
-rwxr-xr-x 1 root root 1703 Nov 16 18:57 key.key
-rw-r--r-- 1 root root 3402 Nov 19 19:00 unbound.conf
-rw-r--r-- 1 root root    8 Nov 19 21:02 unbound.pid
-rw-r--r-- 1 root root 3342 Nov 19 21:29 unbound-t.conf

@gthess
Copy link
Member

gthess commented Nov 19, 2024

I assume Unbound drops privileges and uses user unbound from the default option of username: unbound.
Then I expect the issue to now be "Permission denied" instead of the previous "No such file or directory".
In that case, issuing

sudo chown root:unbound key.key crt.crt

should solve it.

gthess added a commit that referenced this issue Nov 22, 2024
  privilege drop, just like the other SSL_CTX creations.
@liang-hiwin
Copy link
Author

I assume Unbound drops privileges and uses user unbound from the default option of username: unbound. Then I expect the issue to now be "Permission denied" instead of the previous "No such file or directory". In that case, issuing

sudo chown root:unbound key.key crt.crt

should solve it.

My unbound uses root privileges. I executed sudo chown root:root key.key crt.crt, but the same error message still appears.

@gthess
Copy link
Member

gthess commented Nov 22, 2024

Could you show the current error message?

@liang-hiwin
Copy link
Author

I added the unbound user but it still doesn't work. Here is the error:


root@debian12:/usr/local/sbin# ./unbound -c /usr/local/etc/unbound/unbound-t.conf -dd -vvvv
[1732279191] unbound[4104649:0] notice: Start of unbound 1.22.0.
[1732279191] unbound[4104649:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279191] unbound[4104649:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279191] unbound[4104649:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279191] unbound[4104649:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279191] unbound[4104649:0] debug: setup TCP for SSL service
[1732279191] unbound[4104649:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279191] unbound[4104649:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279191] unbound[4104649:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279191] unbound[4104649:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279191] unbound[4104649:0] debug: setup TCP for SSL service
[1732279191] unbound[4104649:0] debug: module config: "subnetcache iterator"
[1732279191] unbound[4104649:0] fatal error: user 'unbound' does not exist.
root@debian12:/usr/local/sbin# useradd -r unbound
root@debian12:/usr/local/sbin# ./unbound -c /usr/local/etc/unbound/unbound-t.conf -dd -vvvv
[1732279223] unbound[4105312:0] notice: Start of unbound 1.22.0.
[1732279223] unbound[4105312:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279223] unbound[4105312:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279223] unbound[4105312:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279223] unbound[4105312:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279223] unbound[4105312:0] debug: setup TCP for SSL service
[1732279223] unbound[4105312:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279223] unbound[4105312:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279223] unbound[4105312:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279223] unbound[4105312:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279223] unbound[4105312:0] debug: setup TCP for SSL service
[1732279223] unbound[4105312:0] debug: module config: "subnetcache iterator"
[1732279223] unbound[4105312:0] error: error for cert file: crt.crt
[1732279223] unbound[4105312:0] error: error in SSL_CTX use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732279223] unbound[4105312:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732279223] unbound[4105312:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732279223] unbound[4105312:0] fatal error: could not set up listen SSL_CTX

@liang-hiwin
Copy link
Author

root@debian12:/usr/local/sbin# ./unbound -c /usr/local/etc/unbound/unbound-t.conf -dd -vvvv
[1732279724] unbound[4108063:0] notice: Start of unbound 1.22.0.
[1732279724] unbound[4108063:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279724] unbound[4108063:0] debug: setup TCP for SSL service
[1732279724] unbound[4108063:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 0.0.0.0 855 tls
[1732279724] unbound[4108063:0] debug: setup TCP for SSL service
[1732279724] unbound[4108063:0] debug: module config: "subnetcache iterator"
[1732279724] unbound[4108063:0] debug: chdir to /usr/local/etc/unbound
[1732279724] unbound[4108063:0] debug: chroot to /usr/local/etc/unbound
[1732279724] unbound[4108063:0] debug: drop user privileges, run as unbound
[1732279724] unbound[4108063:0] debug: switching log to stderr
[1732279724] unbound[4108063:0] debug: Forward zone server list:
[1732279724] unbound[4108063:0] info: DelegationPoint<.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
[1732279724] unbound[4108063:0] debug:    ip4 127.0.0.1 port 11000 (len 16)
[1732279724] unbound[4108063:0] debug: no config, using builtin root hints.
[1732279724] unbound[4108063:0] notice: init module 0: subnetcache
[1732279724] unbound[4108063:0] warning: subnetcache: serve-expired is set but not working for data originating from the subnet module cache.
[1732279724] unbound[4108063:0] warning: subnetcache: prefetch is set but not working for data originating from the subnet module cache.
[1732279724] unbound[4108063:0] debug: send-client-subnet: ::0/0
[1732279724] unbound[4108063:0] debug: send-client-subnet: 0.0.0.0/0
[1732279724] unbound[4108063:0] debug: subnetcache: option registered (8)
[1732279724] unbound[4108063:0] notice: init module 1: iterator
[1732279724] unbound[4108063:0] debug: target fetch policy for level 0 is 3
[1732279724] unbound[4108063:0] debug: target fetch policy for level 1 is 2
[1732279724] unbound[4108063:0] debug: target fetch policy for level 2 is 1
[1732279724] unbound[4108063:0] debug: target fetch policy for level 3 is 0
[1732279724] unbound[4108063:0] debug: target fetch policy for level 4 is 0
[1732279724] unbound[4108063:0] debug: EDNS known options:
[1732279724] unbound[4108063:0] debug:   Code:    Bypass_cache_stage: Aggregate_mesh:
[1732279724] unbound[4108063:0] debug:   edns-cli YES                 NO
[1732279724] unbound[4108063:0] debug: total of 59447 outgoing ports available
[1732279724] unbound[4108063:0] debug: start threads
[1732279724] unbound[4108063:0] debug: libevent 2.1.12-stable uses epoll method.
[1732279724] unbound[4108064:1] debug: libevent 2.1.12-stable uses epoll method.
[1732279724] unbound[4108064:1] error: doq: error for cert file: /usr/local/etc/unbound/crt.crt
[1732279724] unbound[4108064:1] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732279724] unbound[4108064:1] error: and additionally crypto error:10080002:BIO routines::system lib
[1732279724] unbound[4108064:1] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732279724] unbound[4108064:1] error: could not create doq comm_point
[1732279724] unbound[4108064:1] debug: close fd 9
[1732279724] unbound[4108064:1] error: can't create commpoint
[1732279724] unbound[4108063:0] error: doq: error for cert file: /usr/local/etc/unbound/crt.crt
[1732279724] unbound[4108063:0] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732279724] unbound[4108063:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732279724] unbound[4108063:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732279724] unbound[4108063:0] error: could not create doq comm_point
[1732279724] unbound[4108063:0] debug: close fd 5
[1732279724] unbound[4108063:0] error: can't create commpoint
[1732279724] unbound[4108064:1] error: could not create listening sockets
[1732279724] unbound[4108064:f4a43b50] fatal error: Could not initialize thread
[1732279724] unbound[4108063:0] error: could not create listening sockets
[1732279724] unbound[4108063:0] fatal error: Could not initialize main thread

@gthess
Copy link
Member

gthess commented Nov 22, 2024

Unbound complains that user unbound does not exist because Unbound wants to drop privileges from root to unbound which is the default secure configuration.
If you don't want that you need to configure username: "" for Unbound to stay the same user as the one that invoked the command.

Apart from that can you also paste the output of the following commands?

cat /usr/local/etc/unbound/unbound-t.conf
ls -al /usr/local/etc/unbound

@liang-hiwin
Copy link
Author

Unbound complains that user unbound does not exist because Unbound wants to drop privileges from root to unbound which is the default secure configuration. If you don't want that you need to configure username: "" for Unbound to stay the same user as the one that invoked the command.

Apart from that can you also paste the output of the following commands?

cat /usr/local/etc/unbound/unbound-t.conf
ls -al /usr/local/etc/unbound
cat /usr/local/etc/unbound/unbound-t.conf
server:
    verbosity: 0
   #chroot:""
    interface: 127.0.0.1@53533
    interface: 0.0.0.0@855
   #interface: ::0@854
   #interface: ::0@5353

    tls-port: 855
    quic-size: 8m
    quic-port: 855
    tls-service-key: "/usr/local/etc/unbound/key.key"
    tls-service-pem: "/usr/local/etc/unbound/crt.crt"

    username: ""
    do-ip4: yes
    do-ip6: no
    do-udp: yes
    do-tcp: yes
    prefer-ip6: no

    num-threads: 2
    msg-cache-slabs: 2
    rrset-cache-slabs: 2
    key-cache-slabs: 2

    aggressive-nsec: yes
    hide-trustanchor: yes
    hide-version: yes
    hide-identity: yes
    harden-glue: yes

    unwanted-reply-threshold: 1000000
    rrset-roundrobin: yes
    qname-minimisation: yes
    minimal-responses: yes
    access-control: 0.0.0.0/0 allow

    max-ecs-tree-size-ipv4: 50000000
    max-ecs-tree-size-ipv6: 50000000
    do-not-query-localhost: no
    so-rcvbuf: 16m
    so-sndbuf: 16m
    so-reuseport: yes
    rrset-cache-size: 64m
    neg-cache-size: 32m
    msg-cache-size: 50m
    msg-buffer-size: 65552
    key-cache-size: 64m
    outgoing-range: 4096
    outgoing-port-permit: 32768
    num-queries-per-thread: 8192
    outgoing-num-tcp: 2048
    incoming-num-tcp: 4096
    jostle-timeout: 300
    cache-min-ttl: 60
    cache-max-ttl: 1800

   ###prefetches

    prefetch: yes
    prefetch-key: yes
    serve-expired: yes
        serve-expired-ttl: 600
        serve-expired-client-timeout: 60
        serve-expired-client-timeout: 1800

    harden-glue: yes
    harden-large-queries: yes
    harden-dnssec-stripped: yes
    harden-algo-downgrade: yes
    harden-short-bufsize: yes

    max-udp-size: 4096
    edns-buffer-size: 1232
    edns-tcp-keepalive: yes
    edns-tcp-keepalive-timeout: 120000


    client-subnet-zone: "."
    send-client-subnet: 0.0.0.0/0
    send-client-subnet: ::0/0
    max-client-subnet-ipv6: 56
    max-client-subnet-ipv4: 24
    client-subnet-always-forward: yes
    #module-config: "subnetcache validator cachedb iterator"
    #module-config: "subnetcache validator iterator"
    module-config: "subnetcache iterator"
    #root-hints: "/usr/local/etc/unbound/trust/root.hints"
    #auto-trust-anchor-file: "/usr/local/etc/unbound/trust/root.key"
    tls-cert-bundle: "/etc/ssl/certs/ca-certificates.crt"

   # fast server
    fast-server-num: 3
    fast-server-permil: 900

    include: "/usr/local/etc/unbound/forward.conf"

#cachedb:
   #backend: "redis"
   #redis-server-host: 127.0.0.1
   #redis-server-port: 6379
   #redis-server-path: "/usr/local/etc/unbound/keydb.sock"
   #redis-timeout: 5000
   #redis-expire-records: no

#server:
#    statistics-interval: 0
#    extended-statistics: yes
#    statistics-cumulative: no

#remote-control:
#control-enable: yes
#control-interface: 127.0.0.1
# control-port: 8953
# server-key-file: "/usr/local/etc/unbound/trust/unbound_server.key"
# server-cert-file: "/usr/local/etc/unbound/trust/unbound_server.pem"
# control-key-file: "/usr/local/etc/unbound/trust/unbound_control.key"
# control-cert-file: "/usr/local/etc/unbound/trust/unbound_control.pem"


root@debian12:/usr/local/sbin# ls -al /usr/local/etc/unbound
total 52
drwxr-xr-x 2 root root 4096 Nov 22 20:59 .
drwxr-xr-x 3 root root 4096 Nov 15 22:10 ..
-rwxr-xr-x 1 root root 6333 Nov 16 18:57 crt.crt
-rw-r--r-- 1 root root   78 Nov 19 21:53 forward.conf
-rwxr-xr-x 1 root root 1703 Nov 16 18:57 key.key
-rw-r--r-- 1 root root 3402 Nov 19 19:00 unbound.conf
-rw------- 1 root root 2484 Nov 22 20:59 unbound_control.key
-rw-r----- 1 root root 1501 Nov 22 20:59 unbound_control.pem
-rw-r--r-- 1 root root    8 Nov 22 21:01 unbound.pid
-rw------- 1 root root 2484 Nov 22 20:59 unbound_server.key
-rw-r----- 1 root root 1549 Nov 22 20:59 unbound_server.pem
-rw-r--r-- 1 root root 3388 Nov 22 21:01 unbound-t.conf

@liang-hiwin
Copy link
Author

I changed username: "" but still have the same problem

@gthess
Copy link
Member

gthess commented Nov 22, 2024

You need to configure:

    tls-service-key: "key.key"
    tls-service-pem: "crt.crt"

@liang-hiwin
Copy link
Author

liang-hiwin commented Nov 22, 2024

You need to configure:

    tls-service-key: "key.key"
    tls-service-pem: "crt.crt"

I have tested it. It does not work properly.

[1732281260] unbound[4117775:0] error: error for cert file: crt.crt
[1732281260] unbound[4117775:0] error: error in SSL_CTX use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732281260] unbound[4117775:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732281260] unbound[4117775:0] error: and additionally crypto error:0A080002:SSL routines::system lib
[1732281260] unbound[4117775:0] fatal error: could not set up listen SSL_CTX

@gthess
Copy link
Member

gthess commented Nov 22, 2024

I am really confused.
You share an output earlier that mentions (emphasis mine):

[1732279724] unbound[4108063:0] notice: Start of unbound 1.22.0.
[1732279724] unbound[4108063:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 0.0.0.0 855 tls
**[1732279724] unbound[4108063:0] debug: setup TCP for SSL service**
[1732279724] unbound[4108063:0] debug: creating udp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 127.0.0.1 53533
[1732279724] unbound[4108063:0] debug: creating udp4 socket 0.0.0.0 855 doq
[1732279724] unbound[4108063:0] debug: creating tcp4 socket 0.0.0.0 855 tls
**[1732279724] unbound[4108063:0] debug: setup TCP for SSL service**
[1732279724] unbound[4108063:0] debug: module config: "subnetcache iterator"
[1732279724] unbound[4108063:0] debug: chdir to /usr/local/etc/unbound
[1732279724] unbound[4108063:0] debug: chroot to /usr/local/etc/unbound
[1732279724] unbound[4108063:0] debug: drop user privileges, run as unbound
...
**[1732279724] unbound[4108064:1] error: doq: error for cert file: /usr/local/etc/unbound/crt.crt**
[1732279724] unbound[4108064:1] error: doq: error in SSL_CTX_use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732279724] unbound[4108064:1] error: and additionally crypto error:10080002:BIO routines::system lib
[1732279724] unbound[4108064:1] error: and additionally crypto error:0A080002:SSL routines::system lib
**[1732279724] unbound[4108064:1] error: could not create doq comm_point**

And your latest output mentions (emphasis mine):

**[1732281260] unbound[4117775:0] error: error for cert file: crt.crt**
[1732281260] unbound[4117775:0] error: error in SSL_CTX use_certificate_chain_file crypto error:80000002:system library::No such file or directory
[1732281260] unbound[4117775:0] error: and additionally crypto error:10080002:BIO routines::system lib
[1732281260] unbound[4117775:0] error: and additionally crypto error:0A080002:SSL routines::system lib
**[1732281260] unbound[4117775:0] fatal error: could not set up listen SSL_CTX**

The first output fails when it tries to create the DoQ ssl context. This happens after the chroot and privilege drop.

The second output fails when it tries to create the listening ssl context. This happens before the chroot and privilege drop.

Looking at the outputs, for the first one if you would replace the filename to just crt.crt it would have worked. For the second one I am not sure what is happening anymore.

Having both of those outputs does not make sense and it indicates that something is going wrong between invocations and the configuration. In the future could you please always paste the configuration you are using together with the whole log output?

@liang-hiwin
Copy link
Author

Unbound 抱怨用户unbound不存在,因为 Unbound 想要放弃权限,rootunbound是默认安全配置。如果您不想这样,您需要配置username: ""Unbound 以保持与调用命令的用户相同的用户。
除此之外,您还可以粘贴以下命令的输出吗?

cat /usr/local/etc/unbound/unbound-t.conf
ls -al /usr/local/etc/unbound
cat /usr/local/etc/unbound/unbound-t.conf
server:
    verbosity: 0
   #chroot:""
    interface: 127.0.0.1@53533
    interface: 0.0.0.0@855
   #interface: ::0@854
   #interface: ::0@5353

    tls-port: 855
    quic-size: 8m
    quic-port: 855
    tls-service-key: "/usr/local/etc/unbound/key.key"
    tls-service-pem: "/usr/local/etc/unbound/crt.crt"

    username: ""
    do-ip4: yes
    do-ip6: no
    do-udp: yes
    do-tcp: yes
    prefer-ip6: no

    num-threads: 2
    msg-cache-slabs: 2
    rrset-cache-slabs: 2
    key-cache-slabs: 2

    aggressive-nsec: yes
    hide-trustanchor: yes
    hide-version: yes
    hide-identity: yes
    harden-glue: yes

    unwanted-reply-threshold: 1000000
    rrset-roundrobin: yes
    qname-minimisation: yes
    minimal-responses: yes
    access-control: 0.0.0.0/0 allow

    max-ecs-tree-size-ipv4: 50000000
    max-ecs-tree-size-ipv6: 50000000
    do-not-query-localhost: no
    so-rcvbuf: 16m
    so-sndbuf: 16m
    so-reuseport: yes
    rrset-cache-size: 64m
    neg-cache-size: 32m
    msg-cache-size: 50m
    msg-buffer-size: 65552
    key-cache-size: 64m
    outgoing-range: 4096
    outgoing-port-permit: 32768
    num-queries-per-thread: 8192
    outgoing-num-tcp: 2048
    incoming-num-tcp: 4096
    jostle-timeout: 300
    cache-min-ttl: 60
    cache-max-ttl: 1800

   ###prefetches

    prefetch: yes
    prefetch-key: yes
    serve-expired: yes
        serve-expired-ttl: 600
        serve-expired-client-timeout: 60
        serve-expired-client-timeout: 1800

    harden-glue: yes
    harden-large-queries: yes
    harden-dnssec-stripped: yes
    harden-algo-downgrade: yes
    harden-short-bufsize: yes

    max-udp-size: 4096
    edns-buffer-size: 1232
    edns-tcp-keepalive: yes
    edns-tcp-keepalive-timeout: 120000


    client-subnet-zone: "."
    send-client-subnet: 0.0.0.0/0
    send-client-subnet: ::0/0
    max-client-subnet-ipv6: 56
    max-client-subnet-ipv4: 24
    client-subnet-always-forward: yes
    #module-config: "subnetcache validator cachedb iterator"
    #module-config: "subnetcache validator iterator"
    module-config: "subnetcache iterator"
    #root-hints: "/usr/local/etc/unbound/trust/root.hints"
    #auto-trust-anchor-file: "/usr/local/etc/unbound/trust/root.key"
    tls-cert-bundle: "/etc/ssl/certs/ca-certificates.crt"

   # fast server
    fast-server-num: 3
    fast-server-permil: 900

    include: "/usr/local/etc/unbound/forward.conf"

#cachedb:
   #backend: "redis"
   #redis-server-host: 127.0.0.1
   #redis-server-port: 6379
   #redis-server-path: "/usr/local/etc/unbound/keydb.sock"
   #redis-timeout: 5000
   #redis-expire-records: no

#server:
#    statistics-interval: 0
#    extended-statistics: yes
#    statistics-cumulative: no

#remote-control:
#control-enable: yes
#control-interface: 127.0.0.1
# control-port: 8953
# server-key-file: "/usr/local/etc/unbound/trust/unbound_server.key"
# server-cert-file: "/usr/local/etc/unbound/trust/unbound_server.pem"
# control-key-file: "/usr/local/etc/unbound/trust/unbound_control.key"
# control-cert-file: "/usr/local/etc/unbound/trust/unbound_control.pem"


root@debian12:/usr/local/sbin# ls -al /usr/local/etc/unbound
total 52
drwxr-xr-x 2 root root 4096 Nov 22 20:59 .
drwxr-xr-x 3 root root 4096 Nov 15 22:10 ..
-rwxr-xr-x 1 root root 6333 Nov 16 18:57 crt.crt
-rw-r--r-- 1 root root   78 Nov 19 21:53 forward.conf
-rwxr-xr-x 1 root root 1703 Nov 16 18:57 key.key
-rw-r--r-- 1 root root 3402 Nov 19 19:00 unbound.conf
-rw------- 1 root root 2484 Nov 22 20:59 unbound_control.key
-rw-r----- 1 root root 1501 Nov 22 20:59 unbound_control.pem
-rw-r--r-- 1 root root    8 Nov 22 21:01 unbound.pid
-rw------- 1 root root 2484 Nov 22 20:59 unbound_server.key
-rw-r----- 1 root root 1549 Nov 22 20:59 unbound_server.pem
-rw-r--r-- 1 root root 3388 Nov 22 21:01 unbound-t.conf

This is my configuration. I just changed a few ports and certificate paths. If you don’t believe me, you can compile a test yourself.

@liang-hiwin
Copy link
Author

Testing this doq bug will cause my dns to be completely interrupted, so I copied a separate copy for testing. During the test, I also modified some configurations but could not solve the problem. The only way to solve this problem is to disable chroot:""

@gthess
Copy link
Member

gthess commented Nov 22, 2024

It's not that I don't believe you, it's just that with all the changes in the configuration file I want to be certain how Unbound complains for a given configuration :)

With the above configuration you pasted, changing the filenames to just key.key and crt.crt (so that they are relative paths to the current directory) works with both chroot enabled and disabled. I just tried it locally.

I am not sure why Unbound reports that the files are not there.
Is that an off-the-self default debian 12 installation?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants