not sending quad9 cert to syslog (and may be more)

[kulikov-a]

Describe the bug
Hi! with verbosity: 4, tls-cert-bundle: set and forward-addr: 9.9.9.9@853#dns.quad9.net an entry with a quad9 certificate does not appear in the syslog (other certificates such as dns.google appear as expected).
if I change the settings to use-syslog: no with logfile: then the entry in the file appears as expected.

this may be related to another problem: restart of the syslog after the unbound start (restart, not relod) with the specified settings (verb4, quad9 DoT upstream with TLS verify), the unbound stops responding to requests and does not respond to unbound-control connections. only kill -KILL helps
last record in log will be like "debug: comm point listen_for_rw 19 0"

thanks in advance!

To reproduce
Steps to reproduce the behavior:

1. Change verbosity: to 4
2. Add forward-addr: 9.9.9.9@853 with tls-cert-bundle: directive
3. try to resolve some names

Expected behavior
send upstream cert to syslog if verb 4 set, dont hang on syslogd/syslog-ng restart

System:

• Unbound version: 1.13.1
• OS: OPNsense 21.7.1-amd64 FreeBSD 12.1-RELEASE-p19-HBSD OpenSSL 1.1.1k 25 Mar 2021
• unbound -V output:
  Version 1.13.1

Configure line: --with-ssl=/usr/local --with-libexpat=/usr/local --disable-dnscrypt --disable-dnstap --with-libnghttp2 --enable-ecdsa --disable-event-api --enable-gost --with-libevent --with-pyunbound=yes --with-pythonmodule=yes LDFLAGS=-L/usr/local/lib ac_cv_path_SWIG=/usr/local/bin/swig --disable-subnet --disable-tfo-client --disable-tfo-server --with-pthreads --prefix=/usr/local --localstatedir=/var --mandir=/usr/local/man --infodir=/usr/local/share/info/ --build=amd64-portbld-freebsd12.1
Linked libs: libevent 2.1.12-stable (it uses kqueue), OpenSSL 1.1.1k 25 Mar 2021
Linked modules: dns64 python respip validator iterator

BSD licensed, see LICENSE in source package for details.
Report bugs to unbound-bugs@nlnetlabs.nl or https://github.com/NLnetLabs/unbound/issues

Additional information
Add any other information that you may have gathered about the issue here.

[wcawijngaards]

The code path that prints the information is the same for syslog and to logfile. If it does not appear in the syslog, something must have happened to the syslog call. Either syslog has filtered it, syslogs frequently filter, on like message type, info, debug, error, and sender, and I do not know the configuration to fix, you have to figure that out with your syslog. Syslog may also filter the message because it is big, I do not know, but it could, eg. reject messages of more than a couple lines, and the certificate printout is a whole page of text. Some syslogs also remove newlines and maybe tabs, so maybe it is there but a bit messy.

Unbound simply calls the syslog call. It does not do other things. If that makes the application hang, I can also not really do anything about that? I think the issue is in syslog. Or the syslog() call code. Could you maybe use log to file? Some syslog tools, like the freebsd one I saw once, can use outside logfiles. Then configure it to send the signal for unbound to release the old logfile and reopen it when syslog wants to rotate the files.

[kulikov-a]

@wcawijngaards hi! thanks for quick response!
I did some tests and there is a feeling that this is a limitation of the libc syslog() call itself:
I wrote a py-script that reads the output of a X509_print_ex function in

unbound/util/net_help.c

Line 867 in d0cc58b

log_cert(unsigned level, const char* str, void* cert)

from a file and sends it to syslog (py syslog.syslog). so it sends the dns.google cert without any problems and does not send the quad9 cert.
I checked if the syslog-ng receives the message using truss. and no, in the case of a quad9 cert, the message does not come.
and the reason is the size of the X509_print_ex output for the quad9 cert. it is larger than a google cert. if i remove part of the quad9 output (anywhere) - the output is sent to the syslog.
so may be it might make sense to shorten the X509_print_ex output a little by removing "double spaces" from the X509_print_ex output? in the case of my script, it helped, because there are a lot of double spaces in the X509_print_ex output (indents which are then removed anyway by syslogd/syslog-ng). in this case, the message length has been reduced by more than 1000 characters and syslog() call worked fine
Thanks!

ps. I really still can't understand why syslogd/syslog-ng restarting locks the unbound on the next syslog() call with a long message (yet another syslog() issue?)

[wcawijngaards]

Okay, so I made it so that it collapses the double spaces and double tabs from the output. That hopefully makes it work for you.

syslog hang, I have no idea why, perhaps in the socket communication that may be underlying the syslog interface to the syslog services.

[kulikov-a]

@wcawijngaards Thanks a lot!!