From: Otto Moerbeek <otto.moerbeek@open-xchange.com>
Date: Mon, 17 Aug 2020 12:44:42 +0000 (+0200)
Subject: Define a log string method for a Policy and use it in appropriate places
X-Git-Tag: rec-4.4.0-beta1^2~2
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=2a72f0ed9b2b196e66868a6b8be1f0665fda2b94;p=thirdparty%2Fpdns.git

Define a log string method for a Policy and use it in appropriate places
to log what is going on wrt RPZ processing.
---

diff --git a/pdns/filterpo.cc b/pdns/filterpo.cc
index e444ba58f0..6de5c9bdac 100644
--- a/pdns/filterpo.cc
+++ b/pdns/filterpo.cc
@@ -27,13 +27,17 @@
 #include "namespaces.hh"
 #include "dnsrecords.hh"
 
-static const string rpzDropName("rpz-drop."),
+// Names below are RPZ Actions and end with a dot (execpt "Local Data")
+static const std::string rpzDropName("rpz-drop."),
   rpzTruncateName("rpz-tcp-only."),
   rpzNoActionName("rpz-passthru."),
-  rpzClientIPName("rpz-client-ip"),
-  rpzIPName("rpz-ip."),
-  rpzNSDnameName("rpz-nsdname."),
-  rpzNSIPName("rpz-nsip.");
+  rpzCustomName("Local Data");
+
+// Names below are (part) of RPZ Trigger names and do NOT end with a dot
+static const std::string rpzClientIPName("rpz-client-ip"),
+  rpzIPName("rpz-ip"),
+  rpzNSDnameName("rpz-nsdname"),
+  rpzNSIPName("rpz-nsip");
 
 DNSFilterEngine::DNSFilterEngine()
 {
@@ -103,7 +107,7 @@ bool DNSFilterEngine::Zone::findNamedPolicy(const std::unordered_map<DNSName, DN
     if(iter != polmap.end()) {
       pol=iter->second;
       pol.d_trigger = g_wildcarddnsname+s;
-      pol.d_hit = qname.toString();
+      pol.d_hit = qname.toStringNoDot();
       return true;
     }
   }
@@ -120,7 +124,7 @@ bool DNSFilterEngine::Zone::findExactNamedPolicy(const std::unordered_map<DNSNam
   if (it != polmap.end()) {
     pol = it->second;
     pol.d_trigger = qname;
-    pol.d_hit = qname.toString();
+    pol.d_hit = qname.toStringNoDot();
     return true;
   }
 
@@ -176,8 +180,8 @@ bool DNSFilterEngine::getProcessingPolicy(const DNSName& qname, const std::unord
     if (z->findExactNSPolicy(qname, pol)) {
       // cerr<<"Had a hit on the nameserver ("<<qname<<") used to process the query"<<endl;
       pol.d_trigger = qname;
-      pol.d_trigger.appendRawLabel("rpz-nsdname");
-      pol.d_hit = qname.toString();
+      pol.d_trigger.appendRawLabel(rpzNSDnameName);
+      pol.d_hit = qname.toStringNoDot();
       return true;
     }
 
@@ -186,7 +190,7 @@ bool DNSFilterEngine::getProcessingPolicy(const DNSName& qname, const std::unord
         // cerr<<"Had a hit on the nameserver ("<<qname<<") used to process the query"<<endl;
         pol.d_trigger = wc;
         pol.d_trigger.appendRawLabel(rpzNSDnameName);
-        pol.d_hit = qname.toString();
+        pol.d_hit = qname.toStringNoDot();
         return true;
       }
     }
@@ -291,7 +295,7 @@ bool DNSFilterEngine::getQueryPolicy(const DNSName& qname, const std::unordered_
     if (z->findExactQNamePolicy(qname, pol)) {
       // cerr<<"Had a hit on the name of the query"<<endl;
       pol.d_trigger = qname;
-      pol.d_hit = qname.toString();
+      pol.d_hit = qname.toStringNoDot();
       return true;
     }
 
@@ -299,7 +303,7 @@ bool DNSFilterEngine::getQueryPolicy(const DNSName& qname, const std::unordered_
       if (z->findExactQNamePolicy(wc, pol)) {
         // cerr<<"Had a hit on the name of the query"<<endl;
         pol.d_trigger = wc;
-        pol.d_hit = qname.toString();
+        pol.d_hit = qname.toStringNoDot();
         return true;
       }
     }
@@ -545,6 +549,10 @@ bool DNSFilterEngine::Zone::rmNSIPTrigger(const Netmask& nm, const Policy& pol)
   return rmNetmaskTrigger(d_propolNSAddr, nm, pol);
 }
 
+std::string DNSFilterEngine::Policy::getLogString() const {
+  return ": RPZ Hit; PolicyName=" + getName() + "; Trigger=" + d_trigger.toLogString() + "; Hit=" + d_hit + "; Type=" + getTypeToString(d_type) + "; Kind=" + getKindToString(d_kind);
+}
+
 DNSRecord DNSFilterEngine::Policy::getRecordFromCustom(const DNSName& qname, const std::shared_ptr<DNSRecordContent>& custom) const
 {
   DNSRecord dr;
@@ -622,6 +630,8 @@ std::string DNSFilterEngine::getKindToString(DNSFilterEngine::PolicyKind kind)
     return g_wildcarddnsname.toString();
   case DNSFilterEngine::PolicyKind::Truncate:
     return rpzTruncateName;
+  case DNSFilterEngine::PolicyKind::Custom:
+    return rpzCustomName;
   default:
     throw std::runtime_error("Unexpected DNSFilterEngine::Policy kind");
   }
diff --git a/pdns/filterpo.hh b/pdns/filterpo.hh
index b2cd18361b..bc91ed9e4b 100644
--- a/pdns/filterpo.hh
+++ b/pdns/filterpo.hh
@@ -152,6 +152,7 @@ public:
       return (d_type != DNSFilterEngine::PolicyType::None && d_kind != DNSFilterEngine::PolicyKind::NoAction);
     }
 
+    std::string getLogString() const;
     std::vector<DNSRecord> getCustomRecords(const DNSName& qname, uint16_t qtype) const;
     std::vector<DNSRecord> getRecords(const DNSName& qname) const;
 
diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc
index 282d47a84a..aaec67a0c0 100644
--- a/pdns/pdns_recursor.cc
+++ b/pdns/pdns_recursor.cc
@@ -1569,6 +1569,10 @@ static void startDoResolve(void *p)
           goto haveAnswer;
         }
         else if (policyResult == PolicyResult::Drop) {
+          if (sr.doLog()) {
+            g_log << Logger::Warning << dc->d_mdp.d_qname << "|" << QType(dc->d_mdp.d_qtype).getName() << appliedPolicy.getLogString() << endl;
+          }
+          g_stats.policyDrops++;
           return;
         }
       }
@@ -1617,6 +1621,9 @@ static void startDoResolve(void *p)
         }
       }
     }
+    if (sr.doLog() &&  appliedPolicy.d_type != DNSFilterEngine::PolicyType::None) {
+      g_log << Logger::Warning << dc->d_mdp.d_qname << "|" << QType(dc->d_mdp.d_qtype).getName() << appliedPolicy.getLogString() << endl;
+    }
 
     if(res == -1) {
       pw.getHeader()->rcode=RCode::ServFail;