From a508b6a6e444a2a96fd6f8a5b485f1d635d0310c Mon Sep 17 00:00:00 2001
From: Remi Gacogne <remi.gacogne@powerdns.com>
Date: Mon, 25 May 2020 11:33:19 +0200
Subject: [PATCH] rec: Defer the NOD lookup until after the response has been
 sent

If the NOD lookup is slow, for example because the destination
authoritative server is down, doing the NOD lookup before the response
has been sent increases the latency a lot.
This commit moves the actual NOD lookup after the response has been
sent, so we can still use the existing mthread (we might actually need
to do a proper DNS resolution to find the target authoritative server)
without keeping the client waiting.

(cherry picked from commit 3bd27e4a01a3614aba3c0cf425e4ab9490318dd4)
---
 pdns/pdns_recursor.cc | 35 +++++++++++++++++++++++------------
 1 file changed, 23 insertions(+), 12 deletions(-)

diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc
index 18f4e5efd0..eb95325613 100644
--- a/pdns/pdns_recursor.cc
+++ b/pdns/pdns_recursor.cc
@@ -1056,8 +1056,6 @@ static bool checkFrameStreamExport(LocalStateHolder<LuaConfigItems>& luaconfsLoc
 #ifdef NOD_ENABLED
 static bool nodCheckNewDomain(const DNSName& dname)
 {
-  static const QType qt(QType::A);
-  static const uint16_t qc(QClass::IN);
   bool ret = false;
   // First check the (sub)domain isn't whitelisted for NOD purposes
   if (!g_nodDomainWL.check(dname)) {
@@ -1067,19 +1065,24 @@ static bool nodCheckNewDomain(const DNSName& dname)
         // This should probably log to a dedicated log file
         g_log<<Logger::Notice<<"Newly observed domain nod="<<dname.toLogString()<<endl;
       }
-      if (!(g_nodLookupDomain.isRoot())) {
-        // Send a DNS A query to <domain>.g_nodLookupDomain
-        DNSName qname = dname;
-        vector<DNSRecord> dummy;
-        qname += g_nodLookupDomain;
-        directResolve(qname, qt, qc, dummy);
-      }
       ret = true;
     }
   }
   return ret;
 }
 
+static void sendNODLookup(const DNSName& dname)
+{
+  if (!(g_nodLookupDomain.isRoot())) {
+    // Send a DNS A query to <domain>.g_nodLookupDomain
+    static const QType qt(QType::A);
+    static const uint16_t qc(QClass::IN);
+    DNSName qname = dname + g_nodLookupDomain;
+    vector<DNSRecord> dummy;
+    directResolve(qname, qt, qc, dummy);
+  }
+}
+
 static bool udrCheckUniqueDNSRecord(const DNSName& dname, uint16_t qtype, const DNSRecord& record)
 {
   bool ret = false;
@@ -1654,8 +1657,9 @@ static void startDoResolve(void *p)
 #ifdef NOD_ENABLED
     bool nod = false;
     if (g_nodEnabled) {
-      if (nodCheckNewDomain(dc->d_mdp.d_qname))
+      if (nodCheckNewDomain(dc->d_mdp.d_qname)) {
         nod = true;
+      }
     }
 #endif /* NOD_ENABLED */
 #ifdef HAVE_PROTOBUF
@@ -1805,8 +1809,9 @@ static void startDoResolve(void *p)
         }
       }
     }
+
     float spent=makeFloat(sr.getNow()-dc->d_now);
-    if(!g_quiet) {
+    if (!g_quiet) {
       g_log<<Logger::Error<<t_id<<" ["<<MT->getTid()<<"/"<<MT->numProcesses()<<"] answer to "<<(dc->d_mdp.d_header.rd?"":"non-rd ")<<"question '"<<dc->d_mdp.d_qname<<"|"<<DNSRecordContent::NumberToType(dc->d_mdp.d_qtype);
       g_log<<"': "<<ntohs(pw.getHeader()->ancount)<<" answers, "<<ntohs(pw.getHeader()->arcount)<<" additional, took "<<sr.d_outqueries<<" packets, "<<
 	sr.d_totUsec/1000.0<<" netw ms, "<< spent*1000.0<<" tot ms, "<<
@@ -1817,7 +1822,6 @@ static void startDoResolve(void *p)
       }
 	
       g_log<<endl;
-
     }
 
     if (sr.d_outqueries || sr.d_authzonequeries) {
@@ -1864,6 +1868,13 @@ static void startDoResolve(void *p)
       newLat=ourtime*1000; // usec
       g_stats.avgLatencyOursUsec=(1-1.0/g_latencyStatSize)*g_stats.avgLatencyOursUsec + (float)newLat/g_latencyStatSize;
     }
+
+#ifdef NOD_ENABLED
+    if (nod) {
+      sendNODLookup(dc->d_mdp.d_qname);
+    }
+#endif /* NOD_ENABLED */
+
     //    cout<<dc->d_mdp.d_qname<<"\t"<<MT->getUsec()<<"\t"<<sr.d_outqueries<<endl;
   }
   catch(PDNSException &ae) {
-- 
2.47.2