Loads of logs: "validation failure: key for validation <domain>. is marked as invalid because of a previous" for non-DNSSEC signed zone

[pettai]

Describe the bug
Loads of log output about validation failures for a non-DNSSEC signed zone, probably due to that RPZ blocks.

Aug 27 06:50:52 resolver unbound: [1387:7] info: validation failure <jsrcp.com. MX IN>: key for validation jsrcp.com. is marked as invalid because of a previous
Aug 27 06:50:52 resolver unbound: [1387:2] info: validation failure <jsrcp.com. A IN>: key for validation jsrcp.com. is marked as invalid because of a previous
Aug 27 06:50:52 resolver unbound: [1387:a] info: rpz: applied [badrep.host] jsrcp.com. rpz-nxdomain  jsrcp.com. DNSKEY IN
Aug 27 06:50:52 resolver unbound: [1387:a] info: rpz: applied [badrep.host] jsrcp.com. rpz-nxdomain  jsrcp.com. NS IN
Aug 27 06:50:52 resolver unbound: [1387:f] info: validation failure <jsrcp.com. A IN>: key for validation jsrcp.com. is marked as invalid because of a previous

To reproduce
Steps to reproduce the behavior:

1. Add RPZ zone that blocks the domain
2. Try to resolve the domain

Expected behavior

I suggest a few different things:

1. Stop validation attempts if RPZ is at work (if it's blocked does Unbound need to do additional work?)
2. Prune the log output regarding the validation failures if RPZ kicks in and change stuff
3. Fix the log message so it's more clear what it refers to
   validation failure <jsrcp.com. A IN>: key for validation jsrcp.com. is marked as invalid because of a previous seems incomplete, can it be more clear what it refers to?

System:

• Unbound version: 1.21.0
• OS: Ubuntu 20.04
• unbound -V output:

Version 1.21.0

Configure line: --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --disable-silent-rules --libdir=${prefix}/lib/x86_64-linux-gnu --libexecdir=${prefix}/lib/x86_64-linux-gnu --disable-maintainer-mode --disable-dependency-tracking --disable-rpath --with-pidfile=/run/unbound.pid --with-rootkey-file=/var/lib/unbound/root.key --with-libevent --with-libhiredis --with-libnghttp2 --with-pythonmodule --enable-cachedb --enable-subnet --enable-dnstap --enable-systemd --with-chroot-dir= --with-dnstap-socket-path=/run/dnstap.sock --libdir=/usr/lib
Linked libs: libevent 2.1.11-stable (it uses epoll), OpenSSL 1.1.1f  31 Mar 2020
Linked modules: dns64 python cachedb subnetcache respip validator iterator

Additional information
None ATM

[wcawijngaards]

Usually the query would not have validation, because it would be blocked straight away. In what way does the query become a recursion with validation, perhaps after a CNAME there, from a non blocked query name or something like that? But the error message looks wrong, even though I think the validator is doing what should be done, since the data is invalid. Having lots of error messages for a blocked domain is not needed either.

[pettai]

The domain lookup doesn't come from a CNAME-lookup in my example above, the source is of the lookup is an sender's email-address. (which then generate a lot of other queries though... (MX, TXT, etc.))

[wcawijngaards]

I do not see how that would start the validator, mostly that would be blocked by the RPZ straight away. Not that the RPZ and validator interaction cannot be improved. Somehow the query moved to the recursion stage, got validation, and the validator gets RPZ blocked, perhaps with the newer fixed for RPZ that stop it after CNAMEs I thought.

[pettai]

RPZ zone data look like:

jsrcp.com.badrep.host	300	IN	CNAME	.
*.jsrcp.com.badrep.host	300	IN	CNAME	.

unbound.conf:

module-config: "respip validator iterator"

[wcawijngaards]

The fix that is posted fixes a number of issues, in particular where the RPZ blocks DS and DNSKEY lookups. In these cases, the result is no longer validated by the validator. Much like 'domain-insecure' was used. Because the chain of trust is removed with RPZ. That should make the validation failures disappear, and also make it possible to then return RPZ content without the validator rejecting it. This did not exactly create the error messages shown in the logs that have been sent, but similar. Also I am unsure how queries got to the validation stage, for the issue logs. Hopefully it fixes the issue here.