From: Otto Moerbeek <otto.moerbeek@open-xchange.com>
Date: Wed, 11 Jan 2023 14:25:27 +0000 (+0100)
Subject: Plumbing to let validate.cc and aggressive-nsec.cc use the recursor trace logging
X-Git-Tag: dnsdist-1.8.0-rc1~83^2~9
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=10971f7891a3f7db9d05c97454a1d196ce915bc6;p=thirdparty%2Fpdns.git

Plumbing to let validate.cc and aggressive-nsec.cc use the recursor trace logging

Until now the logging of the DNSSEC code used it's own logging, which has
the consequence that prefixed, tracing and indenditng all worked differently
compared to the regular (trace) logging in rec.

So provide a construct to unify them without exposing syncres
internals to the validation code.
---

diff --git a/pdns/logger.hh b/pdns/logger.hh
index dc86efbcd7..491d95a373 100644
--- a/pdns/logger.hh
+++ b/pdns/logger.hh
@@ -166,3 +166,10 @@ Logger& getLogger();
 #else
 #define DLOG(x) ((void)0)
 #endif
+
+struct LogVariant {
+  string prefix;
+  std::variant<Logger*, ostringstream*> v;
+};
+
+using OptLog = std::optional<LogVariant>;
diff --git a/pdns/recursordist/aggressive_nsec.cc b/pdns/recursordist/aggressive_nsec.cc
index c0b1d6e182..1b18dc4b67 100644
--- a/pdns/recursordist/aggressive_nsec.cc
+++ b/pdns/recursordist/aggressive_nsec.cc
@@ -467,12 +467,17 @@ static void addRecordToRRSet(time_t now, const DNSName& owner, const QType& type
   }
 }
 
-#define LOG(x)                     \
-  if (g_dnssecLOG) {               \
-    g_log << Logger::Warning << x; \
+#define LOG(x)                                                          \
+  if (log) {                                                            \
+    if (std::holds_alternative<Logger*>(log->v)) {                      \
+      *std::get<Logger*>(log->v) << Logger::Warning << log->prefix << x; \
+    }                                                                   \
+    else if (std::holds_alternative<ostringstream*>(log->v)) {          \
+      *std::get<ostringstream*>(log->v) << x;                          \
+    }                                                                   \
   }
 
-bool AggressiveNSECCache::synthesizeFromNSEC3Wildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nextCloser, const DNSName& wildcardName)
+bool AggressiveNSECCache::synthesizeFromNSEC3Wildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nextCloser, const DNSName& wildcardName, OptLog& log)
 {
   vState cachedState;
 
@@ -494,7 +499,7 @@ bool AggressiveNSECCache::synthesizeFromNSEC3Wildcard(time_t now, const DNSName&
   return true;
 }
 
-bool AggressiveNSECCache::synthesizeFromNSECWildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nsec, const DNSName& wildcardName)
+bool AggressiveNSECCache::synthesizeFromNSECWildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nsec, const DNSName& wildcardName, OptLog& log)
 {
   vState cachedState;
 
@@ -514,7 +519,7 @@ bool AggressiveNSECCache::synthesizeFromNSECWildcard(time_t now, const DNSName&
   return true;
 }
 
-bool AggressiveNSECCache::getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded<AggressiveNSECCache::ZoneEntry>>& zoneEntry, std::vector<DNSRecord>& soaSet, std::vector<std::shared_ptr<RRSIGRecordContent>>& soaSignatures, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC)
+bool AggressiveNSECCache::getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded<AggressiveNSECCache::ZoneEntry>>& zoneEntry, std::vector<DNSRecord>& soaSet, std::vector<std::shared_ptr<RRSIGRecordContent>>& soaSignatures, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, OptLog& log)
 {
   DNSName zone;
   std::string salt;
@@ -694,7 +699,7 @@ bool AggressiveNSECCache::getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded
 
     if (!isTypeDenied(nsec3, type)) {
       LOG(" but the requested type (" << type.toString() << ") does exist" << endl);
-      return synthesizeFromNSEC3Wildcard(now, name, type, ret, res, doDNSSEC, nextCloserEntry, wildcard);
+      return synthesizeFromNSEC3Wildcard(now, name, type, ret, res, doDNSSEC, nextCloserEntry, wildcard, log);
     }
 
     res = RCode::NoError;
@@ -739,7 +744,7 @@ bool AggressiveNSECCache::getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded
   return true;
 }
 
-bool AggressiveNSECCache::getDenial(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, const ComboAddress& who, const boost::optional<std::string>& routingTag, bool doDNSSEC)
+bool AggressiveNSECCache::getDenial(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, const ComboAddress& who, const boost::optional<std::string>& routingTag, bool doDNSSEC, OptLog log)
 {
   std::shared_ptr<LockGuarded<ZoneEntry>> zoneEntry;
   if (type == QType::DS) {
@@ -779,7 +784,7 @@ bool AggressiveNSECCache::getDenial(time_t now, const DNSName& name, const QType
   }
 
   if (nsec3) {
-    return getNSEC3Denial(now, zoneEntry, soaSet, soaSignatures, name, type, ret, res, doDNSSEC);
+    return getNSEC3Denial(now, zoneEntry, soaSet, soaSignatures, name, type, ret, res, doDNSSEC, log);
   }
 
   ZoneEntry::CacheEntry entry;
@@ -800,7 +805,7 @@ bool AggressiveNSECCache::getDenial(time_t now, const DNSName& name, const QType
 
   LOG(": found a possible NSEC at " << entry.d_owner << " ");
   // note that matchesNSEC() takes care of ruling out ancestor NSECs for us
-  auto denial = matchesNSEC(name, type.getCode(), entry.d_owner, content, entry.d_signatures);
+  auto denial = matchesNSEC(name, type.getCode(), entry.d_owner, content, entry.d_signatures, log);
   if (denial == dState::NODENIAL || denial == dState::INCONCLUSIVE) {
     LOG(" but it does no cover us" << endl);
     return false;
@@ -825,12 +830,12 @@ bool AggressiveNSECCache::getDenial(time_t now, const DNSName& name, const QType
 
     auto nsecContent = std::dynamic_pointer_cast<NSECRecordContent>(wcEntry.d_record);
 
-    denial = matchesNSEC(wc, type.getCode(), wcEntry.d_owner, nsecContent, wcEntry.d_signatures);
+    denial = matchesNSEC(wc, type.getCode(), wcEntry.d_owner, nsecContent, wcEntry.d_signatures, log);
     if (denial == dState::NODENIAL || denial == dState::INCONCLUSIVE) {
 
       if (wcEntry.d_owner == wc) {
         LOG(" proving that the wildcard does exist" << endl);
-        return synthesizeFromNSECWildcard(now, name, type, ret, res, doDNSSEC, entry, wc);
+        return synthesizeFromNSECWildcard(now, name, type, ret, res, doDNSSEC, entry, wc, log);
       }
 
       LOG(" but it does no cover us" << endl);
diff --git a/pdns/recursordist/aggressive_nsec.hh b/pdns/recursordist/aggressive_nsec.hh
index eb9d2bfa01..f8276e0848 100644
--- a/pdns/recursordist/aggressive_nsec.hh
+++ b/pdns/recursordist/aggressive_nsec.hh
@@ -35,6 +35,7 @@ using namespace ::boost::multi_index;
 #include "dnsrecords.hh"
 #include "lock.hh"
 #include "stat_t.hh"
+#include "logger.hh"
 
 class AggressiveNSECCache
 {
@@ -45,7 +46,7 @@ public:
   }
 
   void insertNSEC(const DNSName& zone, const DNSName& owner, const DNSRecord& record, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures, bool nsec3);
-  bool getDenial(time_t, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, const ComboAddress& who, const boost::optional<std::string>& routingTag, bool doDNSSEC);
+  bool getDenial(time_t, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, const ComboAddress& who, const boost::optional<std::string>& routingTag, bool doDNSSEC, OptLog log = std::nullopt);
 
   void removeZoneInfo(const DNSName& zone, bool subzones);
 
@@ -132,9 +133,9 @@ private:
   std::shared_ptr<LockGuarded<ZoneEntry>> getBestZone(const DNSName& zone);
   bool getNSECBefore(time_t now, std::shared_ptr<LockGuarded<ZoneEntry>>& zoneEntry, const DNSName& name, ZoneEntry::CacheEntry& entry);
   bool getNSEC3(time_t now, std::shared_ptr<LockGuarded<ZoneEntry>>& zoneEntry, const DNSName& name, ZoneEntry::CacheEntry& entry);
-  bool getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded<ZoneEntry>>& zoneEntry, std::vector<DNSRecord>& soaSet, std::vector<std::shared_ptr<RRSIGRecordContent>>& soaSignatures, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC);
-  bool synthesizeFromNSEC3Wildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nextCloser, const DNSName& wildcardName);
-  bool synthesizeFromNSECWildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nsec, const DNSName& wildcardName);
+  bool getNSEC3Denial(time_t now, std::shared_ptr<LockGuarded<ZoneEntry>>& zoneEntry, std::vector<DNSRecord>& soaSet, std::vector<std::shared_ptr<RRSIGRecordContent>>& soaSignatures, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, OptLog&);
+  bool synthesizeFromNSEC3Wildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nextCloser, const DNSName& wildcardName, OptLog&);
+  bool synthesizeFromNSECWildcard(time_t now, const DNSName& name, const QType& type, std::vector<DNSRecord>& ret, int& res, bool doDNSSEC, ZoneEntry::CacheEntry& nsec, const DNSName& wildcardName, OptLog&);
 
   /* slowly updates d_entriesCount */
   void updateEntriesCount(SuffixMatchTree<std::shared_ptr<LockGuarded<ZoneEntry>>>& zones);
diff --git a/pdns/recursordist/rec-zonetocache.cc b/pdns/recursordist/rec-zonetocache.cc
index a83dc43da8..1177f66ebf 100644
--- a/pdns/recursordist/rec-zonetocache.cc
+++ b/pdns/recursordist/rec-zonetocache.cc
@@ -250,7 +250,7 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
   sr.setDNSSECValidationRequested(true);
 
   dsmap_t dsmap; // Actually a set
-  vState dsState = sr.getDSRecords(d_zone, dsmap, false, 0);
+  vState dsState = sr.getDSRecords(d_zone, dsmap, false, 0, "");
   if (dsState != vState::Secure) {
     return dsState;
   }
@@ -266,7 +266,7 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
   }
 
   skeyset_t validKeys;
-  vState dnsKeyState = validateDNSKeysAgainstDS(d_now, d_zone, dsmap, dnsKeys, records, zonemd.getRRSIGs(), validKeys);
+  vState dnsKeyState = validateDNSKeysAgainstDS(d_now, d_zone, dsmap, dnsKeys, records, zonemd.getRRSIGs(), validKeys, std::nullopt);
   if (dnsKeyState != vState::Secure) {
     return dnsKeyState;
   }
@@ -288,7 +288,7 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
 
     if (nsecs.records.size() > 0 && nsecs.signatures.size() > 0) {
       // Valdidate the NSEC
-      nsecValidationStatus = validateWithKeySet(d_now, d_zone, nsecs.records, nsecs.signatures, validKeys);
+      nsecValidationStatus = validateWithKeySet(d_now, d_zone, nsecs.records, nsecs.signatures, validKeys, std::nullopt);
       csp.emplace(std::make_pair(d_zone, QType::NSEC), nsecs);
     }
     else if (nsec3s.records.size() > 0 && nsec3s.signatures.size() > 0) {
@@ -297,13 +297,13 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
       for (const auto& rec : zonemd.getNSEC3Params()) {
         records.emplace(rec);
       }
-      nsecValidationStatus = validateWithKeySet(d_now, d_zone, records, zonemd.getRRSIGs(), validKeys);
+      nsecValidationStatus = validateWithKeySet(d_now, d_zone, records, zonemd.getRRSIGs(), validKeys, std::nullopt);
       if (nsecValidationStatus != vState::Secure) {
         d_log->info("NSEC3PARAMS records did not validate");
         return nsecValidationStatus;
       }
       // Valdidate the NSEC3
-      nsecValidationStatus = validateWithKeySet(d_now, zonemd.getNSEC3Label(), nsec3s.records, nsec3s.signatures, validKeys);
+      nsecValidationStatus = validateWithKeySet(d_now, zonemd.getNSEC3Label(), nsec3s.records, nsec3s.signatures, validKeys, std::nullopt);
       csp.emplace(std::make_pair(zonemd.getNSEC3Label(), QType::NSEC3), nsec3s);
     }
     else {
@@ -316,7 +316,7 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
       return nsecValidationStatus;
     }
 
-    auto denial = getDenial(csp, d_zone, QType::ZONEMD, false, false, true);
+    auto denial = getDenial(csp, d_zone, QType::ZONEMD, false, false, std::nullopt, true);
     if (denial == dState::NXQTYPE) {
       d_log->info("Validated denial of absence of ZONEMD record");
       return vState::Secure;
@@ -330,7 +330,7 @@ vState ZoneData::dnssecValidate(pdns::ZoneMD& zonemd, size_t& zonemdCount) const
   for (const auto& rec : zonemdRecords) {
     records.emplace(rec);
   }
-  return validateWithKeySet(d_now, d_zone, records, zonemd.getRRSIGs(), validKeys);
+  return validateWithKeySet(d_now, d_zone, records, zonemd.getRRSIGs(), validKeys, std::nullopt);
 }
 
 void ZoneData::ZoneToCache(const RecZoneToCache::Config& config)
diff --git a/pdns/recursordist/syncres.cc b/pdns/recursordist/syncres.cc
index 2b46e54af0..e9d5b4e59e 100644
--- a/pdns/recursordist/syncres.cc
+++ b/pdns/recursordist/syncres.cc
@@ -469,14 +469,26 @@ bool SyncRes::s_save_parent_ns_set;
 unsigned int SyncRes::s_max_busy_dot_probes;
 bool SyncRes::s_addExtendedResolutionDNSErrors;
 
-#define LOG(x)                     \
-  if (d_lm == Log) {               \
-    g_log << Logger::Warning << x; \
-  }                                \
-  else if (d_lm == Store) {        \
-    d_trace << x;                  \
+#define LOG(x)                                  \
+  if (d_lm == Log) {                            \
+    g_log << Logger::Warning << x;              \
+  }                                             \
+  else if (d_lm == Store) {                     \
+    d_trace << x;                               \
   }
 
+OptLog SyncRes::LogObject(const string& prefix)
+{
+    OptLog ret;
+    if (d_lm == Log) {
+      ret = {prefix, &g_log};
+    }
+    else if(d_lm == Store) {
+      ret = {prefix, &d_trace};
+    }
+    return ret;
+}
+
 // A helper function to print a double with specific printf format.
 // Not using boost::format since it is not thread safe while calling
 // into locale handling code according to tsan.
@@ -506,7 +518,6 @@ static inline void accountAuthLatency(uint64_t usec, int family)
 
 SyncRes::SyncRes(const struct timeval& now) :
   d_authzonequeries(0), d_outqueries(0), d_tcpoutqueries(0), d_dotoutqueries(0), d_throttledqueries(0), d_timeouts(0), d_unreachables(0), d_totUsec(0), d_now(now), d_cacheonly(false), d_doDNSSEC(false), d_doEDNS0(false), d_qNameMinimization(s_qnameminimization), d_lm(s_lm)
-
 {
 }
 
@@ -1622,7 +1633,7 @@ int SyncRes::doResolve(const DNSName& qname, const QType qtype, vector<DNSRecord
     }
   }
 
-  initZoneCutsFromTA(qname);
+  initZoneCutsFromTA(qname, prefix);
 
   // In the auth or recursive forward case, it does not make sense to do qname-minimization
   if (!getQNameMinimization() || isRecursiveForwardOrAuth(qname)) {
@@ -2697,7 +2708,7 @@ static void addTTLModifiedRecords(vector<DNSRecord>& records, const uint32_t ttl
   }
 }
 
-void SyncRes::computeNegCacheValidationStatus(const NegCache::NegCacheEntry& ne, const DNSName& qname, const QType qtype, const int res, vState& state, unsigned int depth)
+void SyncRes::computeNegCacheValidationStatus(const NegCache::NegCacheEntry& ne, const DNSName& qname, const QType qtype, const int res, vState& state, unsigned int depth, const string& prefix)
 {
   tcache_t tcache;
   reapRecordsFromNegCacheEntryForValidation(tcache, ne.authoritySOA.records);
@@ -2733,7 +2744,7 @@ void SyncRes::computeNegCacheValidationStatus(const NegCache::NegCacheEntry& ne,
   if (state == vState::Secure) {
     vState neValidationState = ne.d_validationState;
     dState expectedState = res == RCode::NXDomain ? dState::NXDOMAIN : dState::NXQTYPE;
-    dState denialState = getDenialValidationState(ne, expectedState, false);
+    dState denialState = getDenialValidationState(ne, expectedState, false, prefix);
     updateDenialValidationState(neValidationState, ne.d_name, state, denialState, expectedState, qtype == QType::DS, depth);
   }
   if (state != vState::Indeterminate) {
@@ -2841,7 +2852,7 @@ bool SyncRes::doCacheCheck(const DNSName& qname, const DNSName& authname, bool w
 
     if (!wasAuthZone && shouldValidate() && context.state == vState::Indeterminate) {
       LOG(prefix << qname << ": got vState::Indeterminate state for records retrieved from the negative cache, validating.." << endl);
-      computeNegCacheValidationStatus(ne, qname, qtype, res, context.state, depth);
+      computeNegCacheValidationStatus(ne, qname, qtype, res, context.state, depth, prefix);
 
       if (context.state != cachedState && vStateIsBogus(context.state)) {
         sttl = std::min(sttl, s_maxbogusttl);
@@ -2984,7 +2995,7 @@ bool SyncRes::doCacheCheck(const DNSName& qname, const DNSName& authname, bool w
 
   /* let's check if we have a NSEC covering that record */
   if (g_aggressiveNSECCache && !wasForwardedOrAuthZone) {
-    if (g_aggressiveNSECCache->getDenial(d_now.tv_sec, qname, qtype, ret, res, d_cacheRemote, d_routingTag, d_doDNSSEC)) {
+    if (g_aggressiveNSECCache->getDenial(d_now.tv_sec, qname, qtype, ret, res, d_cacheRemote, d_routingTag, d_doDNSSEC, LogObject(prefix))) {
       context.state = vState::Secure;
       if (s_addExtendedResolutionDNSErrors) {
         context.extendedError = EDNSExtendedError{0, "Result synthesized from aggressive NSEC cache (RFC8198)"};
@@ -3531,12 +3542,12 @@ vState SyncRes::getTA(const DNSName& zone, dsmap_t& ds)
   return vState::Indeterminate;
 }
 
-static size_t countSupportedDS(const dsmap_t& dsmap)
+size_t SyncRes::countSupportedDS(const dsmap_t& dsmap, const string& prefix)
 {
   size_t count = 0;
 
   for (const auto& ds : dsmap) {
-    if (isSupportedDS(ds)) {
+    if (isSupportedDS(ds, LogObject(prefix))) {
       count++;
     }
   }
@@ -3544,7 +3555,7 @@ static size_t countSupportedDS(const dsmap_t& dsmap)
   return count;
 }
 
-void SyncRes::initZoneCutsFromTA(const DNSName& from)
+void SyncRes::initZoneCutsFromTA(const DNSName& from, const string& prefix)
 {
   DNSName zone(from);
   do {
@@ -3552,7 +3563,7 @@ void SyncRes::initZoneCutsFromTA(const DNSName& from)
     vState result = getTA(zone, ds);
     if (result != vState::Indeterminate) {
       if (result == vState::TA) {
-        if (countSupportedDS(ds) == 0) {
+        if (countSupportedDS(ds, prefix) == 0) {
           ds.clear();
           result = vState::Insecure;
         }
@@ -3569,7 +3580,7 @@ void SyncRes::initZoneCutsFromTA(const DNSName& from)
   } while (zone.chopOff());
 }
 
-vState SyncRes::getDSRecords(const DNSName& zone, dsmap_t& ds, bool taOnly, unsigned int depth, bool bogusOnNXD, bool* foundCut)
+vState SyncRes::getDSRecords(const DNSName& zone, dsmap_t& ds, bool taOnly, unsigned int depth, const string& prefix, bool bogusOnNXD, bool* foundCut)
 {
   vState result = getTA(zone, ds);
 
@@ -3579,7 +3590,7 @@ vState SyncRes::getDSRecords(const DNSName& zone, dsmap_t& ds, bool taOnly, unsi
     }
 
     if (result == vState::TA) {
-      if (countSupportedDS(ds) == 0) {
+      if (countSupportedDS(ds, prefix) == 0) {
         ds.clear();
         result = vState::Insecure;
       }
@@ -3616,7 +3627,7 @@ vState SyncRes::getDSRecords(const DNSName& zone, dsmap_t& ds, bool taOnly, unsi
     for (const auto& record : dsrecords) {
       if (record.d_type == QType::DS) {
         const auto dscontent = getRR<DSRecordContent>(record);
-        if (dscontent && isSupportedDS(*dscontent)) {
+        if (dscontent && isSupportedDS(*dscontent, LogObject(prefix))) {
           // Make GOST a lower prio than SHA256
           if (dscontent->d_digesttype == DNSSECKeeper::DIGEST_GOST && bestDigestType == DNSSECKeeper::DIGEST_SHA256) {
             continue;
@@ -3741,7 +3752,7 @@ vState SyncRes::getValidationStatus(const DNSName& name, bool wouldBeValid, bool
 
       bool foundCut = false;
       dsmap_t results;
-      vState dsState = getDSRecords(ds, results, false, depth, false, &foundCut);
+      vState dsState = getDSRecords(ds, results, false, depth, d_prefix, false, &foundCut);
 
       if (foundCut) {
         LOG(d_prefix << ": - Found cut at " << ds << endl);
@@ -3789,7 +3800,7 @@ vState SyncRes::validateDNSKeys(const DNSName& zone, const std::vector<DNSRecord
   DNSName signer = getSigner(signatures);
 
   if (!signer.empty() && zone.isPartOf(signer)) {
-    vState state = getDSRecords(signer, ds, false, depth);
+    vState state = getDSRecords(signer, ds, false, depth, d_prefix);
 
     if (state != vState::Secure) {
       return state;
@@ -3824,7 +3835,7 @@ vState SyncRes::validateDNSKeys(const DNSName& zone, const std::vector<DNSRecord
 
   LOG(d_prefix << ": trying to validate " << std::to_string(tentativeKeys.size()) << " DNSKEYs with " << std::to_string(ds.size()) << " DS" << endl);
   skeyset_t validatedKeys;
-  auto state = validateDNSKeysAgainstDS(d_now.tv_sec, zone, ds, tentativeKeys, toSign, signatures, validatedKeys);
+  auto state = validateDNSKeysAgainstDS(d_now.tv_sec, zone, ds, tentativeKeys, toSign, signatures, validatedKeys, LogObject(d_prefix));
 
   LOG(d_prefix << ": we now have " << std::to_string(validatedKeys.size()) << " DNSKEYs" << endl);
 
@@ -3935,7 +3946,7 @@ vState SyncRes::validateRecordsWithSigs(unsigned int depth, const DNSName& qname
              In that case let's see if the DS does exist, and if it does let's go Bogus
           */
           dsmap_t results;
-          vState dsState = getDSRecords(signer, results, false, depth, true);
+          vState dsState = getDSRecords(signer, results, false, depth, d_prefix, true);
           if (vStateIsBogus(dsState) || dsState == vState::Insecure) {
             state = dsState;
             if (vStateIsBogus(dsState)) {
@@ -3990,7 +4001,7 @@ vState SyncRes::validateRecordsWithSigs(unsigned int depth, const DNSName& qname
   }
 
   LOG(d_prefix << "Going to validate " << recordcontents.size() << " record contents with " << signatures.size() << " sigs and " << keys.size() << " keys for " << name << "|" << type.toString() << endl);
-  vState state = validateWithKeySet(d_now.tv_sec, name, recordcontents, signatures, keys, false);
+  vState state = validateWithKeySet(d_now.tv_sec, name, recordcontents, signatures, keys, LogObject(d_prefix), false);
   if (state == vState::Secure) {
     LOG(d_prefix << "Secure!" << endl);
     return vState::Secure;
@@ -4691,10 +4702,10 @@ void SyncRes::updateDenialValidationState(vState& neValidationState, const DNSNa
   updateValidationState(state, neValidationState);
 }
 
-dState SyncRes::getDenialValidationState(const NegCache::NegCacheEntry& ne, const dState expectedState, bool referralToUnsigned)
+dState SyncRes::getDenialValidationState(const NegCache::NegCacheEntry& ne, const dState expectedState, bool referralToUnsigned, const string& prefix)
 {
   cspmap_t csp = harvestCSPFromNE(ne);
-  return getDenial(csp, ne.d_name, ne.d_qtype.getCode(), referralToUnsigned, expectedState == dState::NXQTYPE);
+  return getDenial(csp, ne.d_name, ne.d_qtype.getCode(), referralToUnsigned, expectedState == dState::NXQTYPE, LogObject(prefix));
 }
 
 bool SyncRes::processRecords(const std::string& prefix, const DNSName& qname, const QType qtype, const DNSName& auth, LWResult& lwr, const bool sendRDQuery, vector<DNSRecord>& ret, set<DNSName>& nsset, DNSName& newtarget, DNSName& newauth, bool& realreferral, bool& negindic, vState& state, const bool needWildcardProof, const bool gatherWildcardProof, const unsigned int wildcardLabelsCount, int& rcode, bool& negIndicHasSignatures, unsigned int depth)
@@ -4751,7 +4762,7 @@ bool SyncRes::processRecords(const std::string& prefix, const DNSName& qname, co
            exist, ie the owner of the SOA */
         auto recordState = getValidationStatus(rec.d_name, !ne.authoritySOA.signatures.empty() || !ne.DNSSECRecords.signatures.empty(), false, depth);
         if (recordState == vState::Secure) {
-          dState denialState = getDenialValidationState(ne, dState::NXDOMAIN, false);
+          dState denialState = getDenialValidationState(ne, dState::NXDOMAIN, false, prefix);
           updateDenialValidationState(ne.d_validationState, ne.d_name, state, denialState, dState::NXDOMAIN, false, depth);
         }
         else {
@@ -4853,7 +4864,7 @@ bool SyncRes::processRecords(const std::string& prefix, const DNSName& qname, co
                as described in section 5.3.4 of RFC 4035 and 5.3 of RFC 7129.
             */
             cspmap_t csp = harvestCSPFromNE(ne);
-            dState res = getDenial(csp, qname, ne.d_qtype.getCode(), false, false, false, wildcardLabelsCount);
+            dState res = getDenial(csp, qname, ne.d_qtype.getCode(), false, false, LogObject(prefix), false, wildcardLabelsCount);
             if (res != dState::NXDOMAIN) {
               vState st = vState::BogusInvalidDenial;
               if (res == dState::INSECURE || res == dState::OPTOUT) {
@@ -4930,7 +4941,7 @@ bool SyncRes::processRecords(const std::string& prefix, const DNSName& qname, co
           ne.d_qtype = QType::DS;
           rec.d_ttl = min(s_maxnegttl, rec.d_ttl);
 
-          dState denialState = getDenialValidationState(ne, dState::NXQTYPE, true);
+          dState denialState = getDenialValidationState(ne, dState::NXQTYPE, true, prefix);
 
           if (denialState == dState::NXQTYPE || denialState == dState::OPTOUT || denialState == dState::INSECURE) {
             ne.d_ttd = lowestTTL + d_now.tv_sec;
@@ -4978,7 +4989,7 @@ bool SyncRes::processRecords(const std::string& prefix, const DNSName& qname, co
         else {
           auto recordState = getValidationStatus(qname, !ne.authoritySOA.signatures.empty() || !ne.DNSSECRecords.signatures.empty(), qtype == QType::DS, depth);
           if (recordState == vState::Secure) {
-            dState denialState = getDenialValidationState(ne, dState::NXQTYPE, false);
+            dState denialState = getDenialValidationState(ne, dState::NXQTYPE, false, prefix);
             updateDenialValidationState(ne.d_validationState, ne.d_name, state, denialState, dState::NXQTYPE, qtype == QType::DS, depth);
           }
           else {
@@ -5885,6 +5896,7 @@ int directResolve(const DNSName& qname, const QType qtype, const QClass qclass,
 int SyncRes::getRootNS(struct timeval now, asyncresolve_t asyncCallback, unsigned int depth, Logr::log_t log)
 {
   SyncRes sr(now);
+  sr.d_prefix = "[getRootNS]";
   sr.setDoEDNS0(true);
   sr.setUpdatingRootNS();
   sr.setDoDNSSEC(g_dnssecmode != DNSSECMode::Off);
diff --git a/pdns/recursordist/syncres.hh b/pdns/recursordist/syncres.hh
index 1fa9ff63e0..919d4f4d47 100644
--- a/pdns/recursordist/syncres.hh
+++ b/pdns/recursordist/syncres.hh
@@ -107,7 +107,7 @@ public:
     vState state{vState::Indeterminate};
   };
 
-  vState getDSRecords(const DNSName& zone, dsmap_t& ds, bool onlyTA, unsigned int depth, bool bogusOnNXD = true, bool* foundCut = nullptr);
+  vState getDSRecords(const DNSName& zone, dsmap_t& ds, bool onlyTA, unsigned int depth, const string& prefix, bool bogusOnNXD = true, bool* foundCut = nullptr);
 
   class AuthDomain
   {
@@ -165,6 +165,7 @@ public:
   {
     s_lm = lm;
   }
+  OptLog LogObject(const string& prefix);
 
   static uint64_t doEDNSDump(int fd);
   static uint64_t doDumpNSSpeeds(int fd);
@@ -633,13 +634,14 @@ private:
   vState validateRecordsWithSigs(unsigned int depth, const DNSName& qname, const QType qtype, const DNSName& name, const QType type, const std::vector<DNSRecord>& records, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures);
   vState validateDNSKeys(const DNSName& zone, const std::vector<DNSRecord>& dnskeys, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures, unsigned int depth);
   vState getDNSKeys(const DNSName& signer, skeyset_t& keys, bool& servFailOccurred, unsigned int depth);
-  dState getDenialValidationState(const NegCache::NegCacheEntry& ne, const dState expectedState, bool referralToUnsigned);
+  dState getDenialValidationState(const NegCache::NegCacheEntry& ne, const dState expectedState, bool referralToUnsigned, const string& prefix);
   void updateDenialValidationState(vState& neValidationState, const DNSName& neName, vState& state, const dState denialState, const dState expectedState, bool isDS, unsigned int depth);
-  void computeNegCacheValidationStatus(const NegCache::NegCacheEntry& ne, const DNSName& qname, QType qtype, const int res, vState& state, unsigned int depth);
+  void computeNegCacheValidationStatus(const NegCache::NegCacheEntry& ne, const DNSName& qname, QType qtype, const int res, vState& state, unsigned int depth, const string& prefix);
   vState getTA(const DNSName& zone, dsmap_t& ds);
   vState getValidationStatus(const DNSName& subdomain, bool wouldBeValid, bool typeIsDS, unsigned int depth);
   void updateValidationStatusInCache(const DNSName& qname, QType qt, bool aa, vState newState) const;
-  void initZoneCutsFromTA(const DNSName& from);
+  void initZoneCutsFromTA(const DNSName& from, const string& prefix);
+  size_t countSupportedDS(const dsmap_t& dsmap, const string& prefix);
 
   void handleNewTarget(const std::string& prefix, const DNSName& qname, const DNSName& newtarget, QType qtype, std::vector<DNSRecord>& ret, int& rcode, int depth, const std::vector<DNSRecord>& recordsFromAnswer, vState& state);
 
diff --git a/pdns/recursordist/test-syncres_cc4.cc b/pdns/recursordist/test-syncres_cc4.cc
index 23358d9bc8..175a9598c1 100644
--- a/pdns/recursordist/test-syncres_cc4.cc
+++ b/pdns/recursordist/test-syncres_cc4.cc
@@ -460,7 +460,7 @@ BOOST_AUTO_TEST_CASE(test_dnssec_rrsig)
   std::vector<std::shared_ptr<RRSIGRecordContent>> sigs;
   sigs.push_back(std::make_shared<RRSIGRecordContent>(rrc));
 
-  BOOST_CHECK(validateWithKeySet(now, qname, recordcontents, sigs, keyset) == vState::Secure);
+  BOOST_CHECK(validateWithKeySet(now, qname, recordcontents, sigs, keyset, std::nullopt) == vState::Secure);
 }
 
 BOOST_AUTO_TEST_CASE(test_dnssec_root_validation_csk)
diff --git a/pdns/recursordist/test-syncres_cc8.cc b/pdns/recursordist/test-syncres_cc8.cc
index a9bdd1a939..8c3eb4b924 100644
--- a/pdns/recursordist/test-syncres_cc8.cc
+++ b/pdns/recursordist/test-syncres_cc8.cc
@@ -284,10 +284,10 @@ BOOST_AUTO_TEST_CASE(test_nsec_ds_denial_from_child)
   denialMap[std::pair(DNSName("example.org."), QType::NSEC)] = pair;
 
   /* check that this NSEC from the child zone can deny a AAAA at the apex */
-  BOOST_CHECK_EQUAL(getDenial(denialMap, DNSName("example.org."), QType::AAAA, false, true, true), dState::NXQTYPE);
+  BOOST_CHECK_EQUAL(getDenial(denialMap, DNSName("example.org."), QType::AAAA, false, true, std::nullopt, true), dState::NXQTYPE);
 
   /* but not that the DS does not exist, since we need the parent for that */
-  BOOST_CHECK_EQUAL(getDenial(denialMap, DNSName("example.org."), QType::DS, false, true, true), dState::NODENIAL);
+  BOOST_CHECK_EQUAL(getDenial(denialMap, DNSName("example.org."), QType::DS, false, true, std::nullopt, true), dState::NODENIAL);
 }
 
 BOOST_AUTO_TEST_CASE(test_nsec_insecure_delegation_denial)
@@ -555,7 +555,7 @@ BOOST_AUTO_TEST_CASE(test_nsec_expanded_wildcard_proof)
 
   /* This is an expanded wildcard proof, meaning that it does prove that the exact name
      does not exist so the wildcard can apply */
-  dState denialState = getDenial(denialMap, DNSName("a.example.org."), QType(0).getCode(), false, false, false, /* normally retrieved from the RRSIG's d_labels */ 2);
+  dState denialState = getDenial(denialMap, DNSName("a.example.org."), QType(0).getCode(), false, false, std::nullopt, false, /* normally retrieved from the RRSIG's d_labels */ 2);
   BOOST_CHECK_EQUAL(denialState, dState::NXDOMAIN);
 }
 
diff --git a/pdns/recursordist/test-syncres_cc9.cc b/pdns/recursordist/test-syncres_cc9.cc
index 57f4b40a4a..a16607bc9c 100644
--- a/pdns/recursordist/test-syncres_cc9.cc
+++ b/pdns/recursordist/test-syncres_cc9.cc
@@ -764,7 +764,7 @@ BOOST_AUTO_TEST_CASE(test_getDSRecords_multialgo)
   });
 
   dsmap_t ds;
-  auto state = sr->getDSRecords(target, ds, false, 0, false);
+  auto state = sr->getDSRecords(target, ds, false, 0, "", false);
   BOOST_CHECK_EQUAL(state, vState::Secure);
   BOOST_REQUIRE_EQUAL(ds.size(), 1U);
   for (const auto& i : ds) {
@@ -817,7 +817,7 @@ BOOST_AUTO_TEST_CASE(test_getDSRecords_multialgo_all_sha)
   });
 
   dsmap_t ds;
-  auto state = sr->getDSRecords(target, ds, false, 0, false);
+  auto state = sr->getDSRecords(target, ds, false, 0, "", false);
   BOOST_CHECK_EQUAL(state, vState::Secure);
   BOOST_REQUIRE_EQUAL(ds.size(), 2U);
   for (const auto& i : ds) {
@@ -870,7 +870,7 @@ BOOST_AUTO_TEST_CASE(test_getDSRecords_multialgo_two_highest)
   });
 
   dsmap_t ds;
-  auto state = sr->getDSRecords(target, ds, false, 0, false);
+  auto state = sr->getDSRecords(target, ds, false, 0, "", false);
   BOOST_CHECK_EQUAL(state, vState::Secure);
   BOOST_REQUIRE_EQUAL(ds.size(), 2U);
   for (const auto& i : ds) {
diff --git a/pdns/validate.cc b/pdns/validate.cc
index 2dfd0ae94c..922cd77ce1 100644
--- a/pdns/validate.cc
+++ b/pdns/validate.cc
@@ -9,7 +9,19 @@ bool g_dnssecLOG{false};
 time_t g_signatureInceptionSkew{0};
 uint16_t g_maxNSEC3Iterations{0};
 
+#ifndef RECURSOR
 #define LOG(x) if(g_dnssecLOG) { g_log <<Logger::Warning << x; }
+#else
+#define LOG(x)                                                          \
+  if (log) {                                                            \
+    if (std::holds_alternative<Logger*>(log->v)) {                      \
+      *std::get<Logger*>(log->v) << Logger::Warning << log->prefix << x; \
+    }                                                                   \
+    else if (std::holds_alternative<ostringstream*>(log->v)) {          \
+      *std::get<ostringstream*>(log->v) << x;                           \
+    }                                                                   \
+  }
+#endif
 
 static bool isAZoneKey(const DNSKEYRecordContent& key)
 {
@@ -32,7 +44,7 @@ static bool isRevokedKey(const DNSKEYRecordContent& key)
   return (key.d_flags & 128) != 0;
 }
 
-static vector<shared_ptr<DNSKEYRecordContent > > getByTag(const skeyset_t& keys, uint16_t tag, uint8_t algorithm)
+static vector<shared_ptr<DNSKEYRecordContent > > getByTag(const skeyset_t& keys, uint16_t tag, uint8_t algorithm, OptLog& log)
 {
   vector<shared_ptr<DNSKEYRecordContent>> ret;
 
@@ -244,7 +256,7 @@ bool isNSEC3AncestorDelegation(const DNSName& signer, const DNSName& owner, cons
     signer.countLabels() < owner.countLabels();
 }
 
-static bool provesNoDataWildCard(const DNSName& qname, const uint16_t qtype, const DNSName& closestEncloser, const cspmap_t& validrrsets)
+static bool provesNoDataWildCard(const DNSName& qname, const uint16_t qtype, const DNSName& closestEncloser, const cspmap_t& validrrsets, OptLog& log)
 {
   const DNSName wildcard = g_wildcarddnsname + closestEncloser;
   LOG("Trying to prove that there is no data in wildcard for "<<qname<<"/"<<QType(qtype)<<endl);
@@ -291,7 +303,7 @@ DNSName getClosestEncloserFromNSEC(const DNSName& name, const DNSName& owner, co
   This function checks whether the non-existence of a wildcard covering qname|qtype
   is proven by the NSEC records in validrrsets.
 */
-static bool provesNoWildCard(const DNSName& qname, const uint16_t qtype, const DNSName& closestEncloser, const cspmap_t & validrrsets)
+static bool provesNoWildCard(const DNSName& qname, const uint16_t qtype, const DNSName& closestEncloser, const cspmap_t & validrrsets, OptLog& log)
 {
   LOG("Trying to prove that there is no wildcard for "<<qname<<"/"<<QType(qtype)<<endl);
   const DNSName wildcard = g_wildcarddnsname + closestEncloser;
@@ -339,7 +351,7 @@ static bool provesNoWildCard(const DNSName& qname, const uint16_t qtype, const D
   If `wildcardExists` is not NULL, if will be set to true if a wildcard exists
   for this qname but doesn't have this qtype.
 */
-static bool provesNSEC3NoWildCard(const DNSName& closestEncloser, uint16_t const qtype, const cspmap_t& validrrsets, bool* wildcardExists, nsec3HashesCache& cache)
+static bool provesNSEC3NoWildCard(const DNSName& closestEncloser, uint16_t const qtype, const cspmap_t& validrrsets, bool* wildcardExists, nsec3HashesCache& cache, OptLog& log)
 {
   auto wildcard = g_wildcarddnsname + closestEncloser;
   LOG("Trying to prove that there is no wildcard for "<<wildcard<<"/"<<QType(qtype)<<endl);
@@ -404,7 +416,7 @@ static bool provesNSEC3NoWildCard(const DNSName& closestEncloser, uint16_t const
   return false;
 }
 
-dState matchesNSEC(const DNSName& name, uint16_t qtype, const DNSName& nsecOwner, const std::shared_ptr<NSECRecordContent>& nsec, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures)
+dState matchesNSEC(const DNSName& name, uint16_t qtype, const DNSName& nsecOwner, const std::shared_ptr<NSECRecordContent>& nsec, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures, OptLog log)
 {
   const DNSName signer = getSigner(signatures);
   if (!name.isPartOf(signer) || !nsecOwner.isPartOf(signer)) {
@@ -482,7 +494,7 @@ dState matchesNSEC(const DNSName& name, uint16_t qtype, const DNSName& nsecOwner
   name does not exist.
 */
 
-dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16_t qtype, bool referralToUnsigned, bool wantsNoDataProof, bool needWildcardProof, unsigned int wildcardLabelsCount)
+dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16_t qtype, bool referralToUnsigned, bool wantsNoDataProof, OptLog log, bool needWildcardProof, unsigned int wildcardLabelsCount)
 {
   nsec3HashesCache cache;
   bool nsec3Seen = false;
@@ -575,7 +587,7 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
           }
 
           DNSName closestEncloser = getClosestEncloserFromNSEC(qname, owner, nsec->d_next);
-          if (provesNoWildCard(qname, qtype, closestEncloser, validrrsets)) {
+          if (provesNoWildCard(qname, qtype, closestEncloser, validrrsets, log)) {
             return dState::NXQTYPE;
           }
 
@@ -624,13 +636,13 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
           DNSName closestEncloser = getClosestEncloserFromNSEC(qname, owner, nsec->d_next);
           if (wantsNoDataProof) {
             LOG("looking for NODATA proof"<<endl);
-            if (provesNoDataWildCard(qname, qtype, closestEncloser, validrrsets)) {
+            if (provesNoDataWildCard(qname, qtype, closestEncloser, validrrsets, log)) {
               return dState::NXQTYPE;
             }
           }
           else {
             LOG("looking for NO wildcard proof"<<endl);
-            if (provesNoWildCard(qname, qtype, closestEncloser, validrrsets)) {
+            if (provesNoWildCard(qname, qtype, closestEncloser, validrrsets, log)) {
               return dState::NXDOMAIN;
             }
           }
@@ -876,7 +888,7 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
   if (nextCloserFound) {
     bool wildcardExists = false;
     /* RFC 7129 section-5.6 */
-    if (needWildcardProof && !provesNSEC3NoWildCard(closestEncloser, qtype, validrrsets, &wildcardExists, cache)) {
+    if (needWildcardProof && !provesNSEC3NoWildCard(closestEncloser, qtype, validrrsets, &wildcardExists, cache, log)) {
       if (!isOptOut) {
         LOG("But the existence of a wildcard is not denied for "<<qname<<"/"<<QType(qtype)<<endl);
         return dState::NODENIAL;
@@ -945,7 +957,7 @@ bool isRRSIGIncepted(const time_t now, const shared_ptr<RRSIGRecordContent>& sig
   return sig->d_siginception - g_signatureInceptionSkew <= now;
 }
 
-static bool checkSignatureWithKey(time_t now, const shared_ptr<RRSIGRecordContent> sig, const shared_ptr<DNSKEYRecordContent> key, const std::string& msg, vState& ede)
+static bool checkSignatureWithKey(time_t now, const shared_ptr<RRSIGRecordContent> sig, const shared_ptr<DNSKEYRecordContent> key, const std::string& msg, vState& ede, OptLog& log)
 {
   bool result = false;
   try {
@@ -973,7 +985,7 @@ static bool checkSignatureWithKey(time_t now, const shared_ptr<RRSIGRecordConten
   return result;
 }
 
-vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& signatures, const skeyset_t& keys, bool validateAllSigs)
+vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& signatures, const skeyset_t& keys, OptLog log, bool validateAllSigs)
 {
   bool foundKey = false;
   bool isValid = false;
@@ -987,7 +999,7 @@ vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t
       continue;
     }
 
-    auto keysMatchingTag = getByTag(keys, signature->d_tag, signature->d_algorithm);
+    auto keysMatchingTag = getByTag(keys, signature->d_tag, signature->d_algorithm, log);
 
     if (keysMatchingTag.empty()) {
       LOG("No key provided for "<<signature->d_tag<<" and algorithm "<<std::to_string(signature->d_algorithm)<<endl;);
@@ -997,7 +1009,7 @@ vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t
     string msg = getMessageForRRSET(name, *signature, toSign, true);
     for (const auto& key : keysMatchingTag) {
       vState ede;
-      bool signIsValid = checkSignatureWithKey(now, signature, key, msg, ede);
+      bool signIsValid = checkSignatureWithKey(now, signature, key, msg, ede, log);
       foundKey = true;
 
       if (signIsValid) {
@@ -1040,7 +1052,7 @@ vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t
   return vState::BogusNoValidRRSIG;
 }
 
-void validateWithKeySet(const cspmap_t& rrsets, cspmap_t& validated, const skeyset_t& keys)
+void validateWithKeySet(const cspmap_t& rrsets, cspmap_t& validated, const skeyset_t& keys, OptLog& log)
 {
   validated.clear();
   /*  cerr<<"Validating an rrset with following keys: "<<endl;
@@ -1051,7 +1063,7 @@ void validateWithKeySet(const cspmap_t& rrsets, cspmap_t& validated, const skeys
   time_t now = time(nullptr);
   for(auto i=rrsets.cbegin(); i!=rrsets.cend(); i++) {
     LOG("validating "<<(i->first.first)<<"/"<<DNSRecordContent::NumberToType(i->first.second)<<" with "<<i->second.signatures.size()<<" sigs"<<endl);
-    if (validateWithKeySet(now, i->first.first, i->second.records, i->second.signatures, keys, true) == vState::Secure) {
+    if (validateWithKeySet(now, i->first.first, i->second.records, i->second.signatures, keys, log, true) == vState::Secure) {
       validated[i->first] = i->second;
     }
   }
@@ -1107,7 +1119,7 @@ bool haveNegativeTrustAnchor(const map<DNSName,std::string>& negAnchors, const D
   return true;
 }
 
-vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t& dsmap, const skeyset_t& tkeys, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& sigs, skeyset_t& validkeys)
+vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t& dsmap, const skeyset_t& tkeys, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& sigs, skeyset_t& validkeys, OptLog log)
 {
   /*
    * Check all DNSKEY records against all DS records and place all DNSKEY records
@@ -1115,7 +1127,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
    */
   for (const auto& dsrc : dsmap)
   {
-    auto r = getByTag(tkeys, dsrc.d_tag, dsrc.d_algorithm);
+    auto r = getByTag(tkeys, dsrc.d_tag, dsrc.d_algorithm, log);
     // cerr<<"looking at DS with tag "<<dsrc.d_tag<<", algo "<<DNSSECKeeper::algorithm2name(dsrc.d_algorithm)<<", digest "<<std::to_string(dsrc.d_digesttype)<<" for "<<zone<<", got "<<r.size()<<" DNSKEYs for tag"<<endl;
 
     for (const auto& drc : r)
@@ -1159,7 +1171,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
     for (const auto& sig : sigs)
     {
       //        cerr<<"got sig for keytag "<<i->d_tag<<" matching "<<getByTag(tkeys, i->d_tag).size()<<" keys of which "<<getByTag(validkeys, i->d_tag).size()<<" valid"<<endl;
-      auto bytag = getByTag(validkeys, sig->d_tag, sig->d_algorithm);
+      auto bytag = getByTag(validkeys, sig->d_tag, sig->d_algorithm, log);
 
       if (bytag.empty()) {
         continue;
@@ -1168,7 +1180,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
       string msg = getMessageForRRSET(zone, *sig, toSign);
       for (const auto& key : bytag) {
         //          cerr<<"validating : ";
-        bool signIsValid = checkSignatureWithKey(now, sig, key, msg, ede);
+        bool signIsValid = checkSignatureWithKey(now, sig, key, msg, ede, log);
 
         if (signIsValid)
         {
@@ -1243,7 +1255,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
   return vState::Secure;
 }
 
-vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset)
+vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset, OptLog& log)
 {
   auto luaLocal = g_luaconfs.getLocal();
   const auto anchors = luaLocal->dsAnchors;
@@ -1339,7 +1351,7 @@ vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset)
      * Check all DNSKEY records against all DS records and place all DNSKEY records
      * that have DS records (that we support the algo for) in the tentative key storage
      */
-    auto state = validateDNSKeysAgainstDS(time(nullptr), *zoneCutIter, dsmap, tkeys, toSign, sigs, validkeys);
+    auto state = validateDNSKeysAgainstDS(time(nullptr), *zoneCutIter, dsmap, tkeys, toSign, sigs, validkeys, log);
 
     if (validkeys.empty())
     {
@@ -1366,14 +1378,14 @@ vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset)
     cspmap_t cspmap=harvestCSPFromRecs(recs);
 
     cspmap_t validrrsets;
-    validateWithKeySet(cspmap, validrrsets, validkeys);
+    validateWithKeySet(cspmap, validrrsets, validkeys, log);
 
     LOG("got "<<cspmap.count(pair(*(zoneCutIter+1),QType::DS))<<" records for DS query of which "<<validrrsets.count(pair(*(zoneCutIter+1),QType::DS))<<" valid "<<endl);
 
     auto r = validrrsets.equal_range(pair(*(zoneCutIter+1), QType::DS));
     if(r.first == r.second) {
       LOG("No DS for "<<*(zoneCutIter+1)<<", now look for a secure denial"<<endl);
-      dState res = getDenial(validrrsets, *(zoneCutIter+1), QType::DS, true, true);
+      dState res = getDenial(validrrsets, *(zoneCutIter+1), QType::DS, true, true, log);
       if (res == dState::INSECURE || res == dState::NXDOMAIN)
         return vState::BogusInvalidDenial;
       if (res == dState::NXQTYPE || res == dState::OPTOUT)
@@ -1397,7 +1409,7 @@ vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset)
   return vState::BogusUnableToGetDNSKEYs;
 }
 
-bool isSupportedDS(const DSRecordContent& ds)
+bool isSupportedDS(const DSRecordContent& ds, OptLog log)
 {
   if (!DNSCryptoKeyEngine::isAlgorithmSupported(ds.d_algorithm)) {
     LOG("Discarding DS "<<ds.d_tag<<" because we don't support algorithm number "<<std::to_string(ds.d_algorithm)<<endl);
diff --git a/pdns/validate.hh b/pdns/validate.hh
index ec11f0b27b..017be3a935 100644
--- a/pdns/validate.hh
+++ b/pdns/validate.hh
@@ -27,7 +27,8 @@
 #include "namespaces.hh"
 #include "dnsrecords.hh"
 #include "dnssecinfra.hh"
- 
+#include "logger.hh"
+
 extern bool g_dnssecLOG;
 extern time_t g_signatureInceptionSkew;
 extern uint16_t g_maxNSEC3Iterations;
@@ -73,18 +74,18 @@ struct sharedDNSKeyRecordContentCompare
 typedef set<shared_ptr<DNSKEYRecordContent>, sharedDNSKeyRecordContentCompare > skeyset_t;
 
 
-vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t& records, const vector<shared_ptr<RRSIGRecordContent> >& signatures, const skeyset_t& keys, bool validateAllSigs=true);
+vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t& records, const vector<shared_ptr<RRSIGRecordContent> >& signatures, const skeyset_t& keys, OptLog log, bool validateAllSigs=true);
 bool isCoveredByNSEC(const DNSName& name, const DNSName& begin, const DNSName& next);
 bool isCoveredByNSEC3Hash(const std::string& h, const std::string& beginHash, const std::string& nextHash);
 bool isCoveredByNSEC3Hash(const DNSName& h, const DNSName& beginHash, const DNSName& nextHash);
-void validateWithKeySet(const cspmap_t& rrsets, cspmap_t& validated, const skeyset_t& keys);
+void validateWithKeySet(const cspmap_t& rrsets, cspmap_t& validated, const skeyset_t& keys, OptLog& log);
 cspmap_t harvestCSPFromRecs(const vector<DNSRecord>& recs);
 vState getKeysFor(DNSRecordOracle& dro, const DNSName& zone, skeyset_t& keyset);
 bool getTrustAnchor(const map<DNSName,dsmap_t>& anchors, const DNSName& zone, dsmap_t &res);
 bool haveNegativeTrustAnchor(const map<DNSName,std::string>& negAnchors, const DNSName& zone, std::string& reason);
-vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t& dsmap, const skeyset_t& tkeys, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& sigs, skeyset_t& validkeys);
-dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16_t qtype, bool referralToUnsigned, bool wantsNoDataProof, bool needsWildcardProof=true, unsigned int wildcardLabelsCount=0);
-bool isSupportedDS(const DSRecordContent& ds);
+vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t& dsmap, const skeyset_t& tkeys, const sortedRecords_t& toSign, const vector<shared_ptr<RRSIGRecordContent> >& sigs, skeyset_t& validkeys, OptLog);
+dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16_t qtype, bool referralToUnsigned, bool wantsNoDataProof, OptLog log = std::nullopt, bool needsWildcardProof=true, unsigned int wildcardLabelsCount=0);
+bool isSupportedDS(const DSRecordContent& ds, OptLog);
 DNSName getSigner(const std::vector<std::shared_ptr<RRSIGRecordContent> >& signatures);
 bool denialProvesNoDelegation(const DNSName& zone, const std::vector<DNSRecord>& dsrecords);
 bool isRRSIGNotExpired(const time_t now, const std::shared_ptr<RRSIGRecordContent>& sig);
@@ -93,7 +94,7 @@ bool isWildcardExpanded(unsigned int labelCount, const std::shared_ptr<RRSIGReco
 bool isWildcardExpandedOntoItself(const DNSName& owner, unsigned int labelCount, const std::shared_ptr<RRSIGRecordContent>& sign);
 void updateDNSSECValidationState(vState& state, const vState stateUpdate);
 
-dState matchesNSEC(const DNSName& name, uint16_t qtype, const DNSName& nsecOwner, const std::shared_ptr<NSECRecordContent>& nsec, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures);
+dState matchesNSEC(const DNSName& name, uint16_t qtype, const DNSName& nsecOwner, const std::shared_ptr<NSECRecordContent>& nsec, const std::vector<std::shared_ptr<RRSIGRecordContent>>& signatures, OptLog);
 
 bool isNSEC3AncestorDelegation(const DNSName& signer, const DNSName& owner, const std::shared_ptr<NSEC3RecordContent>& nsec3);
 DNSName getNSECOwnerName(const DNSName& initialOwner, const std::vector<std::shared_ptr<RRSIGRecordContent> >& signatures);