From: Otto Moerbeek <otto.moerbeek@open-xchange.com>
Date: Fri, 23 Feb 2024 12:24:25 +0000 (+0100)
Subject: rec: log if a dnssec related limit was hit (if log_bogus is set)
X-Git-Tag: rec-5.0.3^2
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=26bb66635b87c33a065bd2bbe8c3d060cadcff92;p=thirdparty%2Fpdns.git

rec: log if a dnssec related limit was hit (if log_bogus is set)

(cherry picked from commit 9d4a01ffa2b724907e07db423da048f68f15eca2)
---

diff --git a/pdns/recursordist/pdns_recursor.cc b/pdns/recursordist/pdns_recursor.cc
index f5978c7fed..200635c1c0 100644
--- a/pdns/recursordist/pdns_recursor.cc
+++ b/pdns/recursordist/pdns_recursor.cc
@@ -569,10 +569,10 @@ static PolicyResult handlePolicyHit(const DNSFilterEngine::Policy& appliedPolicy
           break;
         }
         catch (const pdns::validation::TooManySEC3IterationsException& e) {
-          if (g_logCommonErrors) {
+          if (g_logCommonErrors || (g_dnssecLogBogus && resolver.getDNSSECLimitHit())) {
             SLOG(g_log << Logger::Notice << "Sending SERVFAIL to " << comboWriter->getRemote() << " during resolve of the custom filter policy '" << appliedPolicy.getName() << "' while resolving '" << comboWriter->d_mdp.d_qname << "' because: " << e.what() << endl,
                  resolver.d_slog->error(Logr::Notice, e.what(), "Sending SERVFAIL during resolve of the custom filter policy",
-                                        "policyName", Logging::Loggable(appliedPolicy.getName()), "exception", Logging::Loggable("TooManySEC3IterationsException")));
+                                        "policyName", Logging::Loggable(appliedPolicy.getName()), "exception", Logging::Loggable("TooManySEC3IterationsException"), "dnsseclimithit", Logging::Loggable(resolver.getDNSSECLimitHit())));
           }
           res = RCode::ServFail;
           break;
@@ -1282,7 +1282,7 @@ void startDoResolve(void* arg) // NOLINT(readability-function-cognitive-complexi
       catch (const pdns::validation::TooManySEC3IterationsException& e) {
         if (g_logCommonErrors) {
           SLOG(g_log << Logger::Notice << "Sending SERVFAIL to " << comboWriter->getRemote() << " during resolve of '" << comboWriter->d_mdp.d_qname << "' because: " << e.what() << endl,
-               resolver.d_slog->error(Logr::Notice, e.what(), "Sending SERVFAIL during resolve"));
+               resolver.d_slog->error(Logr::Notice, e.what(), "Sending SERVFAIL during resolve", "dnsseclimithit", Logging::Loggable(true)));
         }
         res = RCode::ServFail;
       }
@@ -1403,6 +1403,9 @@ void startDoResolve(void* arg) // NOLINT(readability-function-cognitive-complexi
           if (resolver.doLog() || vStateIsBogus(state)) {
             // Only create logging object if needed below, beware if you change the logging logic!
             log = resolver.d_slog->withValues("vstate", Logging::Loggable(state));
+            if (resolver.getDNSSECLimitHit()) {
+              log = log->withValues("dnsseclimithit", Logging::Loggable(true));
+            }
             auto xdnssec = g_xdnssec.getLocal();
             if (xdnssec->check(comboWriter->d_mdp.d_qname)) {
               log = log->withValues("in-x-dnssec-names", Logging::Loggable(1));
@@ -1466,9 +1469,9 @@ void startDoResolve(void* arg) // NOLINT(readability-function-cognitive-complexi
           goto sendit; // NOLINT(cppcoreguidelines-avoid-goto)
         }
         catch (const pdns::validation::TooManySEC3IterationsException& e) {
-          if (g_logCommonErrors) {
+          if (g_logCommonErrors || (g_dnssecLogBogus && resolver.getDNSSECLimitHit())) {
             SLOG(g_log << Logger::Notice << "Sending SERVFAIL to " << comboWriter->getRemote() << " during validation of '" << comboWriter->d_mdp.d_qname << "|" << QType(comboWriter->d_mdp.d_qtype) << "' because: " << e.what() << endl,
-                 resolver.d_slog->error(Logr::Notice, e.what(), "Sending SERVFAIL during validation", "exception", Logging::Loggable("TooManySEC3IterationsException")));
+                 resolver.d_slog->error(Logr::Notice, e.what(), "Sending SERVFAIL during validation", "exception", Logging::Loggable("TooManySEC3IterationsException"), "dnsseclimithit", Logging::Loggable(resolver.getDNSSECLimitHit())));
           }
           goto sendit; // NOLINT(cppcoreguidelines-avoid-goto)
         }
diff --git a/pdns/recursordist/syncres.hh b/pdns/recursordist/syncres.hh
index b77fc24c3e..4298b8b3bd 100644
--- a/pdns/recursordist/syncres.hh
+++ b/pdns/recursordist/syncres.hh
@@ -465,6 +465,11 @@ public:
     return d_queryValidationState;
   }
 
+  [[nodiscard]] bool getDNSSECLimitHit() const
+  {
+    return d_validationContext.d_limitHit;
+  }
+
   void setQueryReceivedOverTCP(bool tcp)
   {
     d_queryReceivedOverTCP = tcp;
diff --git a/pdns/validate.cc b/pdns/validate.cc
index 16d144e643..6833ab9baa 100644
--- a/pdns/validate.cc
+++ b/pdns/validate.cc
@@ -176,6 +176,7 @@ bool denialProvesNoDelegation(const DNSName& zone, const std::vector<DNSRecord>&
       }
 
       if (g_maxNSEC3sPerRecordToConsider > 0 && nsec3sConsidered >= g_maxNSEC3sPerRecordToConsider) {
+        context.d_limitHit = true;
         return false;
       }
       nsec3sConsidered++;
@@ -704,6 +705,7 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
 
         if (g_maxNSEC3sPerRecordToConsider > 0 && nsec3sConsidered >= g_maxNSEC3sPerRecordToConsider) {
           VLOG(log, qname << ": Too many NSEC3s for this record"<<endl);
+          context.d_limitHit = true;          
           return dState::NODENIAL;
         }
         nsec3sConsidered++;
@@ -805,6 +807,7 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
 
             if (g_maxNSEC3sPerRecordToConsider > 0 && nsec3sConsidered >= g_maxNSEC3sPerRecordToConsider) {
               VLOG(log, qname << ": Too many NSEC3s for this record"<<endl);
+              context.d_limitHit = true;
               return dState::NODENIAL;
             }
             nsec3sConsidered++;
@@ -891,6 +894,7 @@ dState getDenial(const cspmap_t &validrrsets, const DNSName& qname, const uint16
 
             if (g_maxNSEC3sPerRecordToConsider > 0 && nsec3sConsidered >= g_maxNSEC3sPerRecordToConsider) {
               VLOG(log, qname << ": Too many NSEC3s for this record"<<endl);
+              context.d_limitHit = true;
               return dState::NODENIAL;
             }
             nsec3sConsidered++;
@@ -1031,6 +1035,7 @@ vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t
     if (g_maxRRSIGsPerRecordToConsider > 0 && signaturesConsidered >= g_maxRRSIGsPerRecordToConsider) {
       VLOG(log, name<<": We have already considered "<<std::to_string(signaturesConsidered)<<" RRSIG"<<addS(signaturesConsidered)<<" for this record, stopping now"<<endl;);
       // possibly going Bogus, the RRSIGs have not been validated so Insecure would be wrong
+      context.d_limitHit = true;
       break;
     }
     signaturesConsidered++;
@@ -1049,6 +1054,9 @@ vState validateWithKeySet(time_t now, const DNSName& name, const sortedRecords_t
     for (const auto& key : keysMatchingTag) {
       if (g_maxDNSKEYsToConsider > 0 && dnskeysConsidered >= g_maxDNSKEYsToConsider) {
         VLOG(log, name << ": We have already considered "<<std::to_string(dnskeysConsidered)<<" DNSKEY"<<addS(dnskeysConsidered)<<" for tag "<<std::to_string(signature->d_tag)<<" and algorithm "<<std::to_string(signature->d_algorithm)<<", not considering the remaining ones for this signature"<<endl;);
+        if (!isValid) {
+          context.d_limitHit = true;
+        }
         return isValid ? vState::Secure : vState::BogusNoValidRRSIG;
       }
       dnskeysConsidered++;
@@ -1175,6 +1183,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
         // we need to break because we can have a partially validated set
         // where the KSK signs the ZSK(s), and even if we don't
         // we are going to try to get the correct EDE status (revoked, expired, ...)
+        context.d_limitHit = true;
         break;
       }
       dnskeysConsidered++;
@@ -1227,6 +1236,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
       if (g_maxRRSIGsPerRecordToConsider > 0 && signaturesConsidered >= g_maxRRSIGsPerRecordToConsider) {
         VLOG(log, zone << ": We have already considered "<<std::to_string(signaturesConsidered)<<" RRSIG"<<addS(signaturesConsidered)<<" for this record, stopping now"<<endl;);
         // possibly going Bogus, the RRSIGs have not been validated so Insecure would be wrong
+        context.d_limitHit = true;
         return vState::BogusNoValidDNSKEY;
       }
 
@@ -1235,6 +1245,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
       for (const auto& key : bytag) {
         if (g_maxDNSKEYsToConsider > 0 && dnskeysConsidered >= g_maxDNSKEYsToConsider) {
           VLOG(log, zone << ": We have already considered "<<std::to_string(dnskeysConsidered)<<" DNSKEY"<<addS(dnskeysConsidered)<<" for tag "<<std::to_string(sig->d_tag)<<" and algorithm "<<std::to_string(sig->d_algorithm)<<", not considering the remaining ones for this signature"<<endl;);
+          context.d_limitHit = true;
           return vState::BogusNoValidDNSKEY;
         }
         dnskeysConsidered++;
@@ -1242,6 +1253,7 @@ vState validateDNSKeysAgainstDS(time_t now, const DNSName& zone, const dsmap_t&
         if (g_maxRRSIGsPerRecordToConsider > 0 && signaturesConsidered >= g_maxRRSIGsPerRecordToConsider) {
           VLOG(log, zone << ": We have already considered "<<std::to_string(signaturesConsidered)<<" RRSIG"<<addS(signaturesConsidered)<<" for this record, stopping now"<<endl;);
           // possibly going Bogus, the RRSIGs have not been validated so Insecure would be wrong
+          context.d_limitHit = true;
           return vState::BogusNoValidDNSKEY;
         }
         //          cerr<<"validating : ";
diff --git a/pdns/validate.hh b/pdns/validate.hh
index 7d844bf11c..034839fca0 100644
--- a/pdns/validate.hh
+++ b/pdns/validate.hh
@@ -90,6 +90,7 @@ struct ValidationContext
   Nsec3HashesCache d_nsec3Cache;
   unsigned int d_validationsCounter{0};
   unsigned int d_nsec3IterationsRemainingQuota{0};
+  bool d_limitHit{false};
 };
 
 class TooManySEC3IterationsException : public std::runtime_error