]> git.ipfire.org Git - thirdparty/pdns.git/commitdiff
Process review comments: move semantics, more general event names and
authorOtto <otto.moerbeek@open-xchange.com>
Fri, 17 Sep 2021 09:38:07 +0000 (11:38 +0200)
committerOtto <otto.moerbeek@open-xchange.com>
Wed, 13 Oct 2021 12:33:17 +0000 (14:33 +0200)
re-adjust timebase if an event is added before the current base.

pdns/dnsmessage.proto
pdns/pdns_recursor.cc
pdns/recursordist/docs/performance.rst
pdns/recursordist/rec-eventtrace.cc
pdns/recursordist/rec-eventtrace.hh

index f37a8442bf1ea47d385437d6df3920fd65683249..49a5951adeef5a524b2ac90e364d136d49bb3346 100644 (file)
@@ -129,20 +129,23 @@ message PBDNSMessage {
 
   // The well known EventTrace event numbers
   enum EventType {
+                                                // Range 0..99: Generic events
     CustomEvent = 0;                            // A custom event
-    RecRecv = 1;                                // A request was received by the recursor process
+    ReqRecv = 1;                                // A request was received
     PCacheCheck = 2;                            // A packet cache check was initiated or completed; value: bool cacheHit
-    SyncRes = 3;                                // Syncres main function has started or completed; value: int rcode
-    AnswerSent = 4;                             // The answer was sent to the client
-    LuaGetTag = 100;                            // Events below mark start or end of Lua hook calls; value: return value of hook
-    LuaGetTagFFI = 101;
-    LuaIPFilter = 102;
-    LuaPreRPZ = 103;
-    LuaPreResolve = 104;
-    LuaPreOutQuery = 105;
-    LuaPostResolve = 106;
-    LuaNoData = 107;
-    LuaNXDomain = 108;
+    AnswerSent = 3;                             // An answer was sent to the client
+
+                                                // Range 100: Recursor events
+    SyncRes = 100;                              // Recursor Syncres main function has started or completed; value: int rcode
+    LuaGetTag = 101;                            // Events below mark start or end of Lua hook calls; value: return value of hook
+    LuaGetTagFFI = 102;
+    LuaIPFilter = 103;
+    LuaPreRPZ = 104;
+    LuaPreResolve = 105;
+    LuaPreOutQuery = 106;
+    LuaPostResolve = 107;
+    LuaNoData = 108;
+    LuaNXDomain = 109;
   }
 
   message Event {
index adc99539932f6e63496ce519ebee40556945f99e..e14c4e37b51f0af0a7b6137cc01a5e77ea96107f 100644 (file)
@@ -2750,7 +2750,7 @@ static void handleRunningTCPQuestion(int fd, FDMultiplexer::funcparam_t& var)
       bool qnameParsed = false;
 
       dc->d_eventTrace.setEnabled(SyncRes::s_event_trace_enabled);
-      dc->d_eventTrace.add(RecEventTrace::RecRecv);
+      dc->d_eventTrace.add(RecEventTrace::ReqRecv);
       auto luaconfsLocal = g_luaconfs.getLocal();
       if (checkProtobufExport(luaconfsLocal)) {
         needECS = true;
@@ -3259,7 +3259,7 @@ static void handleNewUDPQuestion(int fd, FDMultiplexer::funcparam_t& var)
     if((len=recvmsg(fd, &msgh, 0)) >= 0) {
       eventTrace.clear();
       eventTrace.setEnabled(SyncRes::s_event_trace_enabled);
-      eventTrace.add(RecEventTrace::RecRecv);
+      eventTrace.add(RecEventTrace::ReqRecv);
 
       firstQuery = false;
 
index d4b59f944d8631470d1ff6b4ab6f0d04f42fb015..f4f9f023630d5c4b4075207ff0be7f5a1f8d843f 100644 (file)
@@ -209,21 +209,24 @@ Currently, an event protobuf message has the following definition:
 .. code-block:: protobuf
 
     enum EventType {
-      CustomEvent = 0;
-      RecRecv = 1;
-      PCacheCheck = 2;
-      SyncRes = 3;
-      AnswerSent = 4;
-      LuaGetTag = 100;
-      LuaGetTagFFI = 101;
-      LuaIPFilter = 102;
-      LuaPreRPZ = 103;
-      LuaPreResolve = 104;
-      LuaPreOutQuery = 105;
-      LuaPostResolve = 106;
-      LuaNoData = 107;
-      LuaNXDomain = 108;
-    }
+                                                  // Range 0..99: Generic events
+      CustomEvent = 0;                            // A custom event
+      ReqRecv = 1;                                // A request was received
+      PCacheCheck = 2;                            // A packet cache check was initiated or completed; value: bool cacheHit
+      AnswerSent = 3;                             // An answer was sent to the client
+
+                                                  // Range 100: Recursor events
+      SyncRes = 100;                              // Recursor Syncres main function has started or completed; value: int rcode
+      LuaGetTag = 101;                            // Events below mark start or end of Lua hook calls; value: return value of hook
+      LuaGetTagFFI = 102;
+      LuaIPFilter = 103;
+      LuaPreRPZ = 104;
+      LuaPreResolve = 105;
+      LuaPreOutQuery = 106;
+      LuaPostResolve = 107;
+      LuaNoData = 108;
+      LuaNXDomain = 109;
+  }
 
 .. code-block:: protobuf
 
@@ -245,7 +248,7 @@ An example of a trace (timestamps are relative in nanoseconds) as shown  in the
 
 .. code-block:: C
 
-    - RecRecv(70);
+    - ReqRecv(70);
     - PCacheCheck(411964);
     - PCacheCheck(416783,0,done);
     - SyncRes(441811);
@@ -260,7 +263,7 @@ An example of a trace with a packet cache hit):
 
 .. code-block:: C
 
-    - RecRecv(60);
+    - ReqRecv(60);
     - PCacheCheck(22913);
     - PCacheCheck(113255,1,done);
     - AnswerSent(117493)
@@ -271,7 +274,7 @@ An example where various Lua related events can be seen:
 
 .. code-block:: C
 
-    RecRecv(150);
+    ReqRecv(150);
     PCacheCheck(26912);
     PCacheCheck(51308,0,done);
     LuaIPFilter(56868);
index 040e1629b35baae7beef74330d8ed72eaef9517e..6060dbd5f7677f36236e16959db976054158e294 100644 (file)
 
 const std::unordered_map<RecEventTrace::EventType, std::string> RecEventTrace::s_eventNames = {
   NameEntry(CustomEvent),
-  NameEntry(RecRecv),
+  NameEntry(ReqRecv),
   NameEntry(PCacheCheck),
-  NameEntry(SyncRes),
   NameEntry(AnswerSent),
+  NameEntry(SyncRes),
   NameEntry(LuaGetTag),
   NameEntry(LuaGetTagFFI),
   NameEntry(LuaIPFilter),
index 701cad494faa4f922615a63ab6f72db586d174ed..4c64ac45c3e9da8c22700484f57a76498ca3ebeb 100644 (file)
@@ -25,7 +25,6 @@
 #include "misc.hh"
 #include "noinitvector.hh"
 
-#include <protozero/pbf_writer.hpp>
 #include <optional>
 #include <time.h>
 #include <unordered_map>
@@ -36,21 +35,25 @@ class RecEventTrace
 public:
   enum EventType : uint8_t
   {
+    // Keep in-syc with dnsmessagge.proto!
     // Don't forget to add a new entry to the table in the .cc file!
+    // Generic events
     CustomEvent = 0,
-    RecRecv = 1,
+    ReqRecv = 1,
     PCacheCheck = 2,
-    SyncRes = 3,
-    AnswerSent = 4,
-    LuaGetTag = 100,
-    LuaGetTagFFI = 101,
-    LuaIPFilter = 102,
-    LuaPreRPZ = 103,
-    LuaPreResolve = 104,
-    LuaPreOutQuery = 105,
-    LuaPostResolve = 106,
-    LuaNoData = 107,
-    LuaNXDomain = 108,
+    AnswerSent = 3,
+
+    // Recursor specific events
+    SyncRes = 100,
+    LuaGetTag = 101,
+    LuaGetTagFFI = 102,
+    LuaIPFilter = 103,
+    LuaPreRPZ = 104,
+    LuaPreResolve = 105,
+    LuaPreOutQuery = 106,
+    LuaPostResolve = 107,
+    LuaNoData = 108,
+    LuaNXDomain = 109,
   };
 
   static const std::unordered_map<EventType, std::string> s_eventNames;
@@ -61,10 +64,13 @@ public:
   }
 
   RecEventTrace(const RecEventTrace& old) :
-    d_events(std::move(old.d_events)),
+    d_events(old.d_events),
     d_base(old.d_base),
     d_status(old.d_status)
   {
+    // An RecEventTrace object can be copied, but the original will be marked invalid.
+    // This is do detect (very likely) unintended modifications to the original after
+    // the ownership changed.
     old.d_status = Invalid;
   }
 
@@ -73,6 +79,9 @@ public:
     d_base(old.d_base),
     d_status(old.d_status)
   {
+    // An RecEventTrace object can be moved, but the original will be marked invalid.
+    // This is do detect (very likely) unintended modifications to the original after
+    // the ownership changed.
     old.d_status = Invalid;
   }
 
@@ -117,12 +126,12 @@ public:
 
   struct Entry
   {
-    Entry(Value_t& v, EventType e, bool start, int64_t ts) :
-      d_value(v), d_ts(ts), d_event(e), d_start(start)
+    Entry(Value_t&& v, EventType e, bool start, int64_t ts) :
+      d_value(std::move(v)), d_ts(ts), d_event(e), d_start(start)
     {
     }
-    Entry(Value_t& v, const std::string& custom, bool start, int64_t ts) :
-      d_value(v), d_custom(custom), d_ts(ts), d_event(CustomEvent), d_start(start)
+    Entry(Value_t&& v, const std::string& custom, bool start, int64_t ts) :
+      d_value(std::move(v)), d_custom(custom), d_ts(ts), d_event(CustomEvent), d_start(start)
     {
     }
     Value_t d_value;
@@ -158,17 +167,30 @@ public:
   }
 
   template <class E>
-  void add(E e, Value_t v, bool start)
+  void add(E e, Value_t&& v, bool start, int64_t stamp = 0)
   {
     assert(d_status != Invalid);
     if (d_status == Disabled) {
       return;
     }
-    struct timespec ts;
-    clock_gettime(CLOCK_MONOTONIC, &ts);
-    int64_t stamp = ts.tv_nsec + ts.tv_sec * 1000000000;
+    if (stamp == 0) {
+      struct timespec ts;
+      clock_gettime(CLOCK_MONOTONIC, &ts);
+      stamp = ts.tv_nsec + ts.tv_sec * 1000000000;
+    }
+    if (stamp < d_base) {
+      // If we get a ts before d_base, we adjust d_base and the existing events
+      // This is possble if we add a kernel provided packet timestamp in the future
+      // (Though it seems those timestamps do not use CLOCK_MONOTONIC...)
+      const int64_t adj = d_base - stamp;
+      for (auto& i : d_events) {
+        i.d_ts += adj;
+      }
+      // and move to the new base
+      d_base = stamp;
+    }
     stamp -= d_base;
-    d_events.emplace_back(v, e, start, stamp);
+    d_events.emplace_back(std::move(v), e, start, stamp);
   }
 
   template <class E>
@@ -201,6 +223,7 @@ public:
     d_events.clear();
     reset();
   }
+
   void reset()
   {
     struct timespec ts;
@@ -238,7 +261,7 @@ public:
 private:
   std::vector<Entry> d_events;
   int64_t d_base;
-  enum Status
+  enum Status : uint8_t
   {
     Disabled,
     Invalid,