From: Otto Date: Fri, 17 Sep 2021 09:38:07 +0000 (+0200) Subject: Process review comments: move semantics, more general event names and X-Git-Tag: dnsdist-1.7.0-alpha2~9^2~4 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=ade7a5e65b0f91eb531bb10e1b06cdf5c0f531d4;p=thirdparty%2Fpdns.git Process review comments: move semantics, more general event names and re-adjust timebase if an event is added before the current base. --- diff --git a/pdns/dnsmessage.proto b/pdns/dnsmessage.proto index f37a8442bf..49a5951ade 100644 --- a/pdns/dnsmessage.proto +++ b/pdns/dnsmessage.proto @@ -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 { diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc index adc9953993..e14c4e37b5 100644 --- a/pdns/pdns_recursor.cc +++ b/pdns/pdns_recursor.cc @@ -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; diff --git a/pdns/recursordist/docs/performance.rst b/pdns/recursordist/docs/performance.rst index d4b59f944d..f4f9f02363 100644 --- a/pdns/recursordist/docs/performance.rst +++ b/pdns/recursordist/docs/performance.rst @@ -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); diff --git a/pdns/recursordist/rec-eventtrace.cc b/pdns/recursordist/rec-eventtrace.cc index 040e1629b3..6060dbd5f7 100644 --- a/pdns/recursordist/rec-eventtrace.cc +++ b/pdns/recursordist/rec-eventtrace.cc @@ -28,10 +28,10 @@ const std::unordered_map RecEventTrace::s_eventNames = { NameEntry(CustomEvent), - NameEntry(RecRecv), + NameEntry(ReqRecv), NameEntry(PCacheCheck), - NameEntry(SyncRes), NameEntry(AnswerSent), + NameEntry(SyncRes), NameEntry(LuaGetTag), NameEntry(LuaGetTagFFI), NameEntry(LuaIPFilter), diff --git a/pdns/recursordist/rec-eventtrace.hh b/pdns/recursordist/rec-eventtrace.hh index 701cad494f..4c64ac45c3 100644 --- a/pdns/recursordist/rec-eventtrace.hh +++ b/pdns/recursordist/rec-eventtrace.hh @@ -25,7 +25,6 @@ #include "misc.hh" #include "noinitvector.hh" -#include #include #include #include @@ -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 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 - 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 @@ -201,6 +223,7 @@ public: d_events.clear(); reset(); } + void reset() { struct timespec ts; @@ -238,7 +261,7 @@ public: private: std::vector d_events; int64_t d_base; - enum Status + enum Status : uint8_t { Disabled, Invalid,