From: Kees Monshouwer <mind04@monshouwer.org>
Date: Thu, 10 Feb 2022 22:36:47 +0000 (+0100)
Subject: auth: add cache and backend latency metrics
X-Git-Tag: rec-4.7.0-beta1~66^2~1
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=386c5b136c62427e53ab74ed7dbed5a3aea20606;p=thirdparty%2Fpdns.git

auth: add cache and backend latency metrics
---

diff --git a/pdns/common_startup.cc b/pdns/common_startup.cc
index 39dab49160..8ff7bcb215 100644
--- a/pdns/common_startup.cc
+++ b/pdns/common_startup.cc
@@ -60,7 +60,7 @@ std::unique_ptr<DNSProxy> DP{nullptr};
 std::unique_ptr<DynListener> dl{nullptr};
 CommunicatorClass Communicator;
 shared_ptr<UDPNameserver> N;
-double avg_latency{0.0};
+double avg_latency{0.0}, receive_latency{0.0}, cache_latency{0.0}, backend_latency{0.0}, send_latency{0.0};
 unique_ptr<TCPNameserver> TN;
 static vector<DNSDistributor*> g_distributors;
 vector<std::shared_ptr<UDPNameserver> > g_udpReceivers;
@@ -315,6 +315,26 @@ static uint64_t getLatency(const std::string& str)
   return round(avg_latency);
 }
 
+static uint64_t getReceiveLatency(const std::string& str)
+{
+  return round(receive_latency);
+}
+
+static uint64_t getCacheLatency(const std::string& str)
+{
+  return round(cache_latency);
+}
+
+static uint64_t getBackendLatency(const std::string& str)
+{
+  return round(backend_latency);
+}
+
+static uint64_t getSendLatency(const std::string& str)
+{
+  return round(send_latency);
+}
+
 void declareStats()
 {
   S.declare("udp-queries","Number of UDP queries received");
@@ -395,6 +415,10 @@ void declareStats()
   S.declare("servfail-packets","Number of times a server-failed packet was sent out");
   S.declare("unauth-packets", "Number of times a zone we are not auth for was queried");
   S.declare("latency","Average number of microseconds needed to answer a question", getLatency, StatType::gauge);
+  S.declare("receive-latency", "Average number of microseconds needed to receive a query", getReceiveLatency, StatType::gauge);
+  S.declare("cache-latency", "Average number of microseconds needed for a packet cache lookup", getCacheLatency, StatType::gauge);
+  S.declare("backend-latency", "Average number of microseconds needed for a backend lookup", getBackendLatency, StatType::gauge);
+  S.declare("send-latency", "Average number of microseconds needed to send the answer", getSendLatency, StatType::gauge);
   S.declare("timedout-packets","Number of packets which weren't answered within timeout set");
   S.declare("security-status", "Security status based on regular polling", StatType::gauge);
   S.declare(
@@ -417,16 +441,22 @@ int isGuarded(char **argv)
   return !!p;
 }
 
-static void sendout(std::unique_ptr<DNSPacket>& a)
+static void sendout(std::unique_ptr<DNSPacket>& a, int start)
 {
   if(!a)
     return;
 
   try {
+    int diff = a->d_dt.udiffNoReset();
+    backend_latency = 0.999 * backend_latency + 0.001 * std::max(diff - start, 0);
+    start = diff;
+
     N->send(*a);
 
-    int diff=a->d_dt.udiff();
-    avg_latency=0.999*avg_latency+0.001*diff;
+    diff = a->d_dt.udiff();
+    send_latency = 0.999 * send_latency + 0.001 * std::max(diff - start, 0);
+
+    avg_latency = 0.999 * avg_latency + 0.001 * std::max(diff, 0);
   }
   catch (const std::exception& e) {
     g_log<<Logger::Error<<"Caught unhandled exception while sending a response: "<<e.what()<<endl;
@@ -453,7 +483,7 @@ try
   AtomicCounter &numreceived6=*S.getPointer("udp6-queries");
   AtomicCounter &overloadDrops=*S.getPointer("overload-drops");
 
-  int diff;
+  int diff, start;
   bool logDNSQueries = ::arg().mustDo("log-dns-queries");
   shared_ptr<UDPNameserver> NS;
   std::string buffer;
@@ -482,6 +512,9 @@ try
         continue;                    // packet was broken, try again
       }
 
+      diff = question.d_dt.udiffNoReset();
+      receive_latency = 0.999 * receive_latency + 0.001 * std::max(diff, 0);
+
       numreceived++;
 
       if(question.d_remote.getSocklen()==sizeof(sockaddr_in))
@@ -508,6 +541,7 @@ try
       }
 
       if(PC.enabled() && (question.d.opcode != Opcode::Notify && question.d.opcode != Opcode::Update) && question.couldBeCached()) {
+        start = diff;
         bool haveSomething=PC.get(question, cached); // does the PacketCache recognize this question?
         if (haveSomething) {
           if(logDNSQueries)
@@ -519,11 +553,20 @@ try
           cached.d.rd=question.d.rd; // copy in recursion desired bit
           cached.d.id=question.d.id;
           cached.commitD(); // commit d to the packet                        inlined
+
+          diff = question.d_dt.udiffNoReset();
+          cache_latency = 0.999 * cache_latency + 0.001 * std::max(diff - start, 0);
+          start = diff;
+
           NS->send(cached); // answer it then                              inlined
+
           diff=question.d_dt.udiff();
-          avg_latency=0.999*avg_latency+0.001*diff; // 'EWMA'
+          send_latency = 0.999 * send_latency + 0.001 * std::max(diff - start, 0);
+          avg_latency = 0.999 * avg_latency + 0.001 * std::max(diff, 0); // 'EWMA'
           continue;
         }
+        diff = question.d_dt.udiffNoReset();
+        cache_latency = 0.999 * cache_latency + 0.001 * std::max(diff - start, 0);
       }
 
       if(distributor->isOverloaded()) {
diff --git a/pdns/distributor.hh b/pdns/distributor.hh
index a54b7099a9..c3fce94cd5 100644
--- a/pdns/distributor.hh
+++ b/pdns/distributor.hh
@@ -51,7 +51,7 @@ template<class Answer, class Question, class Backend> class Distributor
 {
 public:
   static Distributor* Create(int n=1); //!< Create a new Distributor with \param n threads
-  typedef std::function<void(std::unique_ptr<Answer>&)> callback_t;
+  typedef std::function<void(std::unique_ptr<Answer>&, int)> callback_t;
   virtual int question(Question&, callback_t callback) =0; //!< Submit a question to the Distributor
   virtual int getQueueSize() =0; //!< Returns length of question queue
   virtual bool isOverloaded() =0;
@@ -65,7 +65,7 @@ public:
   SingleThreadDistributor(const SingleThreadDistributor&) = delete;
   void operator=(const SingleThreadDistributor&) = delete;
   SingleThreadDistributor();
-  typedef std::function<void(std::unique_ptr<Answer>&)> callback_t;
+  typedef std::function<void(std::unique_ptr<Answer>&, int)> callback_t;
   int question(Question&, callback_t callback) override; //!< Submit a question to the Distributor
   int getQueueSize() override {
     return 0;
@@ -87,7 +87,7 @@ public:
   MultiThreadDistributor(const MultiThreadDistributor&) = delete;
   void operator=(const MultiThreadDistributor&) = delete;
   MultiThreadDistributor(int n);
-  typedef std::function<void(std::unique_ptr<Answer>&)> callback_t;
+  typedef std::function<void(std::unique_ptr<Answer>&, int)> callback_t;
   int question(Question&, callback_t callback) override; //!< Submit a question to the Distributor
   void distribute(int n);
   int getQueueSize() override {
@@ -98,11 +98,13 @@ public:
   {
     QuestionData(const Question& query): Q(query)
     {
+      start = Q.d_dt.udiff();
     }
 
     Question Q;
     callback_t callback{nullptr};
     int id{0};
+    int start{0};
   };
 
   bool isOverloaded() override
@@ -242,7 +244,7 @@ retry:
         }
       }
 
-      QD->callback(a);
+      QD->callback(a, QD->start);
       QD.reset();
     }
 
@@ -264,6 +266,7 @@ retry:
 
 template<class Answer, class Question, class Backend>int SingleThreadDistributor<Answer,Question,Backend>::question(Question& q, callback_t callback)
 {
+  int start = q.d_dt.udiff();
   std::unique_ptr<Answer> a = nullptr;
   bool allowRetry=true;
 retry:
@@ -302,7 +305,7 @@ retry:
       goto retry;
     }
   }
-  callback(a);
+  callback(a, start);
   return 0;
 }
 
diff --git a/pdns/test-distributor_hh.cc b/pdns/test-distributor_hh.cc
index d05131d88f..f8799bd5f1 100644
--- a/pdns/test-distributor_hh.cc
+++ b/pdns/test-distributor_hh.cc
@@ -33,7 +33,7 @@ struct Backend
 };
 
 static std::atomic<int> g_receivedAnswers;
-static void report(std::unique_ptr<DNSPacket>& A)
+static void report(std::unique_ptr<DNSPacket>& A, int B)
 {
   g_receivedAnswers++;
 }
@@ -67,7 +67,7 @@ struct BackendSlow
 };
 
 static std::atomic<int> g_receivedAnswers1;
-static void report1(std::unique_ptr<DNSPacket>& A)
+static void report1(std::unique_ptr<DNSPacket>& A, int B)
 {
   g_receivedAnswers1++;
 }
@@ -119,7 +119,7 @@ std::atomic<int> BackendDies::s_count;
 
 std::atomic<int> g_receivedAnswers2;
 
-static void report2(std::unique_ptr<DNSPacket>& A)
+static void report2(std::unique_ptr<DNSPacket>& A, int B)
 {
   g_receivedAnswers2++;
 }