From: Otto Date: Wed, 16 Jun 2021 10:34:01 +0000 (+0200) Subject: Start of eventTrace code. X-Git-Tag: dnsdist-1.7.0-alpha2~9^2~15 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=0f14442c78a1004a45989536a3e1df8f69a839b1;p=thirdparty%2Fpdns.git Start of eventTrace code. Missing: config, many trace points, protobuf export. --- diff --git a/pdns/lua-recursor4.cc b/pdns/lua-recursor4.cc index 98244c9da6..235e6b405e 100644 --- a/pdns/lua-recursor4.cc +++ b/pdns/lua-recursor4.cc @@ -502,32 +502,47 @@ void RecursorLua4::maintenance() const } } -bool RecursorLua4::prerpz(DNSQuestion& dq, int& ret) const +bool RecursorLua4::prerpz(DNSQuestion& dq, int& ret, RecEventTrace& et) const { - return genhook(d_prerpz, dq, ret); + et.add(RecEventTrace::LuaPreRPZ); + bool ok = genhook(d_prerpz, dq, ret); + et.add(RecEventTrace::LuaPreRPZ, ok, false); + return ok; } -bool RecursorLua4::preresolve(DNSQuestion& dq, int& ret) const +bool RecursorLua4::preresolve(DNSQuestion& dq, int& ret, RecEventTrace& et) const { - return genhook(d_preresolve, dq, ret); + et.add(RecEventTrace::LuaPreResolve); + bool ok = genhook(d_preresolve, dq, ret); + et.add(RecEventTrace::LuaPreResolve, ok, false); + return ok; } -bool RecursorLua4::nxdomain(DNSQuestion& dq, int& ret) const +bool RecursorLua4::nxdomain(DNSQuestion& dq, int& ret, RecEventTrace& et) const { - return genhook(d_nxdomain, dq, ret); + et.add(RecEventTrace::LuaNXDomain); + bool ok = genhook(d_nxdomain, dq, ret); + et.add(RecEventTrace::LuaNXDomain, ok, false); + return ok; } -bool RecursorLua4::nodata(DNSQuestion& dq, int& ret) const +bool RecursorLua4::nodata(DNSQuestion& dq, int& ret, RecEventTrace& et) const { - return genhook(d_nodata, dq, ret); + et.add(RecEventTrace::LuaNoData); + bool ok = genhook(d_nodata, dq, ret); + et.add(RecEventTrace::LuaNoData, ok, false); + return ok; } -bool RecursorLua4::postresolve(DNSQuestion& dq, int& ret) const +bool RecursorLua4::postresolve(DNSQuestion& dq, int& ret, RecEventTrace& et) const { - return genhook(d_postresolve, dq, ret); + et.add(RecEventTrace::LuaPostResolve); + bool ok = genhook(d_postresolve, dq, ret); + et.add(RecEventTrace::LuaPostResolve, ok, false); + return ok; } -bool RecursorLua4::preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret) const +bool RecursorLua4::preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret, RecEventTrace& et) const { bool variableAnswer = false; bool wantsRPZ = false; @@ -535,8 +550,10 @@ bool RecursorLua4::preoutquery(const ComboAddress& ns, const ComboAddress& reque bool addPaddingToResponse = false; RecursorLua4::DNSQuestion dq(ns, requestor, query, qtype.getCode(), isTcp, variableAnswer, wantsRPZ, logQuery, addPaddingToResponse); dq.currentRecords = &res; - - return genhook(d_preoutquery, dq, ret); + et.add(RecEventTrace::LuaPreOutQuery); + bool ok = genhook(d_preoutquery, dq, ret); + et.add(RecEventTrace::LuaPreOutQuery, ok, false); + return ok; } bool RecursorLua4::ipfilter(const ComboAddress& remote, const ComboAddress& local, const struct dnsheader& dh) const diff --git a/pdns/lua-recursor4.hh b/pdns/lua-recursor4.hh index a1ff21e89d..b3d409f906 100644 --- a/pdns/lua-recursor4.hh +++ b/pdns/lua-recursor4.hh @@ -35,6 +35,7 @@ #include "lua-base4.hh" #include "proxy-protocol.hh" #include "noinitvector.hh" +#include "rec-eventtrace.hh" #include @@ -185,13 +186,13 @@ public: unsigned int gettag_ffi(FFIParams&) const; void maintenance() const; - bool prerpz(DNSQuestion& dq, int& ret) const; - bool preresolve(DNSQuestion& dq, int& ret) const; - bool nxdomain(DNSQuestion& dq, int& ret) const; - bool nodata(DNSQuestion& dq, int& ret) const; - bool postresolve(DNSQuestion& dq, int& ret) const; + bool prerpz(DNSQuestion& dq, int& ret, RecEventTrace&) const; + bool preresolve(DNSQuestion& dq, int& ret, RecEventTrace&) const; + bool nxdomain(DNSQuestion& dq, int& ret, RecEventTrace&) const; + bool nodata(DNSQuestion& dq, int& ret, RecEventTrace&) const; + bool postresolve(DNSQuestion& dq, int& ret, RecEventTrace&) const; - bool preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret) const; + bool preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret, RecEventTrace& et) const; bool ipfilter(const ComboAddress& remote, const ComboAddress& local, const struct dnsheader&) const; bool policyHitEventFilter(const ComboAddress& remote, const DNSName& qname, const QType& qtype, bool tcp, DNSFilterEngine::Policy& policy, std::unordered_set& tags, std::unordered_map& discardedPolicies) const; diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc index 2133fa57e9..50e9c82162 100644 --- a/pdns/pdns_recursor.cc +++ b/pdns/pdns_recursor.cc @@ -115,6 +115,7 @@ #include "rec-protozero.hh" #include "xpf.hh" +#include "rec-eventtrace.hh" typedef map tcpClientCounts_t; @@ -337,6 +338,7 @@ struct DNSComboWriter { d_local holds our own. */ ComboAddress d_local; ComboAddress d_destination; + RecEventTrace d_eventTrace; boost::uuids::uuid d_uuid; string d_requestorId; string d_deviceId; @@ -1683,6 +1685,7 @@ static void startDoResolve(void *p) uint32_t minTTL = dc->d_ttlCap; SyncRes sr(dc->d_now); + sr.d_eventTrace = std::move(dc->d_eventTrace); sr.setId(MT->getTid()); bool DNSSECOK=false; @@ -1781,7 +1784,7 @@ static void startDoResolve(void *p) } if (t_pdl) { - t_pdl->prerpz(dq, res); + t_pdl->prerpz(dq, res, sr.d_eventTrace); } // Check if the client has a policy attached to it @@ -1828,7 +1831,7 @@ static void startDoResolve(void *p) } // if there is a RecursorLua active, and it 'took' the query in preResolve, we don't launch beginResolve - if (!t_pdl || !t_pdl->preresolve(dq, res)) { + if (!t_pdl || !t_pdl->preresolve(dq, res, sr.d_eventTrace)) { if (!g_dns64PrefixReverse.empty() && dq.qtype == QType::PTR && dq.qname.isPartOf(g_dns64PrefixReverse)) { res = getFakePTRRecords(dq.qname, ret); @@ -1917,7 +1920,7 @@ static void startDoResolve(void *p) if (t_pdl || (g_dns64Prefix && dq.qtype == QType::AAAA && !vStateIsBogus(dq.validationState))) { if (res == RCode::NoError) { if (answerIsNOData(dc->d_mdp.d_qtype, res, ret)) { - if (t_pdl && t_pdl->nodata(dq, res)) { + if (t_pdl && t_pdl->nodata(dq, res, sr.d_eventTrace)) { shouldNotValidate = true; auto policyResult = handlePolicyHit(appliedPolicy, dc, sr, res, ret, pw); if (policyResult == PolicyResult::HaveAnswer) { @@ -1933,7 +1936,7 @@ static void startDoResolve(void *p) } } } - else if (res == RCode::NXDomain && t_pdl && t_pdl->nxdomain(dq, res)) { + else if (res == RCode::NXDomain && t_pdl && t_pdl->nxdomain(dq, res, sr.d_eventTrace)) { shouldNotValidate = true; auto policyResult = handlePolicyHit(appliedPolicy, dc, sr, res, ret, pw); if (policyResult == PolicyResult::HaveAnswer) { @@ -1944,7 +1947,7 @@ static void startDoResolve(void *p) } } - if (t_pdl && t_pdl->postresolve(dq, res)) { + if (t_pdl && t_pdl->postresolve(dq, res, sr.d_eventTrace)) { shouldNotValidate = true; auto policyResult = handlePolicyHit(appliedPolicy, dc, sr, res, ret, pw); // haveAnswer case redundant @@ -2334,6 +2337,11 @@ static void startDoResolve(void *p) bool hadError = sendResponseOverTCP(dc, packet); finishTCPReply(dc, hadError, true); } + // Protobuf sending should be here... + sr.d_eventTrace.add(RecEventTrace::AnswerSent); + if (sr.d_eventTrace.enabled()) { + g_log << Logger::Info << sr.d_eventTrace.toString() << endl; + } // Originally this code used a mix of floats, doubles, uint64_t with different units. // Now it always uses an integral number of microseconds, except for averages, which use doubles @@ -2736,6 +2744,8 @@ static void handleRunningTCPQuestion(int fd, FDMultiplexer::funcparam_t& var) bool logQuery = false; bool qnameParsed = false; + dc->d_eventTrace.setEnabled(true); + dc->d_eventTrace.add(RecEventTrace::RecRecv); auto luaconfsLocal = g_luaconfs.getLocal(); if (checkProtobufExport(luaconfsLocal)) { needECS = true; @@ -2764,9 +2774,12 @@ static void handleRunningTCPQuestion(int fd, FDMultiplexer::funcparam_t& var) if (t_pdl->d_gettag_ffi) { RecursorLua4::FFIParams params(qname, qtype, dc->d_destination, dc->d_source, dc->d_ednssubnet.source, dc->d_data, dc->d_policyTags, dc->d_records, ednsOptions, dc->d_proxyProtocolValues, requestorId, deviceId, deviceName, dc->d_routingTag, dc->d_rcode, dc->d_ttlCap, dc->d_variable, true, logQuery, dc->d_logResponse, dc->d_followCNAMERecords, dc->d_extendedErrorCode, dc->d_extendedErrorExtra, dc->d_responsePaddingDisabled, dc->d_meta); dc->d_tag = t_pdl->gettag_ffi(params); + dc->d_eventTrace.add(RecEventTrace::LuaGetTagFFI, dc->d_tag, false); } else if (t_pdl->d_gettag) { + dc->d_eventTrace.add(RecEventTrace::LuaGetTag); dc->d_tag = t_pdl->gettag(dc->d_source, dc->d_ednssubnet.source, dc->d_destination, qname, qtype, &dc->d_policyTags, dc->d_data, ednsOptions, true, requestorId, deviceId, deviceName, dc->d_routingTag, dc->d_proxyProtocolValues); + dc->d_eventTrace.add(RecEventTrace::LuaGetTag, dc->d_tag, false); } } catch(const std::exception& e) { @@ -2812,7 +2825,10 @@ static void handleRunningTCPQuestion(int fd, FDMultiplexer::funcparam_t& var) } if (t_pdl) { - if (t_pdl->ipfilter(dc->d_source, dc->d_destination, *dh)) { + dc->d_eventTrace.add(RecEventTrace::LuaIPFilter); + bool ipf = t_pdl->ipfilter(dc->d_source, dc->d_destination, *dh); + dc->d_eventTrace.add(RecEventTrace::LuaIPFilter, ipf, false); + if (ipf) { if (!g_quiet) { g_log<getTid()<<"/"<numProcesses()<<"] DROPPED TCP question from "<d_source.toStringWithPort()<<(dc->d_source != dc->d_remote ? " (via "+dc->d_remote.toStringWithPort()+")" : "")<<" based on policy"<d_eventTrace.add(RecEventTrace::PCacheCheck); bool cacheHit = checkForCacheHit(qnameParsed, dc->d_tag, conn->data, qname, qtype, qclass, g_now, response, dc->d_qhash, pbData, true, dc->d_source); + dc->d_eventTrace.add(RecEventTrace::PCacheCheck, cacheHit, false); if (cacheHit) { if (t_protobufServers && dc->d_logResponse && !(luaconfsLocal->protobufExportConfig.taggedOnly && pbData && !pbData->d_tagged)) { @@ -2875,6 +2893,10 @@ static void handleRunningTCPQuestion(int fd, FDMultiplexer::funcparam_t& var) Utility::gettimeofday(&now, nullptr); uint64_t spentUsec = uSec(now - start); g_stats.cumulativeAnswers(spentUsec); + dc->d_eventTrace.add(RecEventTrace::AnswerSent); + if (dc->d_eventTrace.enabled()) { + g_log << Logger::Info << dc->d_eventTrace.toString() << endl; + } } else { // No cache hit, setup for startDoResolve() in an mthread ++conn->d_requestsInFlight; @@ -2970,7 +2992,7 @@ static void handleNewTCPQuestion(int fd, FDMultiplexer::funcparam_t& ) } } -static string* doProcessUDPQuestion(const std::string& question, const ComboAddress& fromaddr, const ComboAddress& destaddr, ComboAddress source, ComboAddress destination, struct timeval tv, int fd, std::vector& proxyProtocolValues) +static string* doProcessUDPQuestion(const std::string& question, const ComboAddress& fromaddr, const ComboAddress& destaddr, ComboAddress source, ComboAddress destination, struct timeval tv, int fd, std::vector& proxyProtocolValues, RecEventTrace& eventTrace) { gettimeofday(&g_now, nullptr); if (tv.tv_sec) { @@ -3063,9 +3085,12 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr RecursorLua4::FFIParams params(qname, qtype, destination, source, ednssubnet.source, data, policyTags, records, ednsOptions, proxyProtocolValues, requestorId, deviceId, deviceName, routingTag, rcode, ttlCap, variable, false, logQuery, logResponse, followCNAMEs, extendedErrorCode, extendedErrorExtra, responsePaddingDisabled, meta); ctag = t_pdl->gettag_ffi(params); + eventTrace.add(RecEventTrace::LuaGetTagFFI, ctag, false); } else if (t_pdl->d_gettag) { + eventTrace.add(RecEventTrace::LuaGetTag); ctag = t_pdl->gettag(source, ednssubnet.source, destination, qname, qtype, &policyTags, data, ednsOptions, false, requestorId, deviceId, deviceName, routingTag, proxyProtocolValues); + eventTrace.add(RecEventTrace::LuaGetTag, ctag, false); } } catch (const std::exception& e) { @@ -3096,7 +3121,9 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr /* It might seem like a good idea to skip the packet cache lookup if we know that the answer is not cacheable, but it means that the hash would not be computed. If some script decides at a later time to mark back the answer as cacheable we would cache it with a wrong tag, so better safe than sorry. */ + eventTrace.add(RecEventTrace::PCacheCheck); bool cacheHit = checkForCacheHit(qnameParsed, ctag, question, qname, qtype, qclass, g_now, response, qhash, pbData, false, source); + eventTrace.add(RecEventTrace::PCacheCheck, cacheHit, false); if (cacheHit) { if (t_protobufServers && logResponse && !(luaconfsLocal->protobufExportConfig.taggedOnly && pbData && !pbData->d_tagged)) { protobufLogResponse(dh, luaconfsLocal, pbData, tv, false, source, destination, ednssubnet, uniqueId, requestorId, deviceId, deviceName, meta); @@ -3115,6 +3142,10 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr addCMsgSrcAddr(&msgh, &cbuf, &destaddr, 0); } int sendErr = sendOnNBSocket(fd, &msgh); + eventTrace.add(RecEventTrace::AnswerSent); + if (eventTrace.enabled()) { + g_log << Logger::Info << eventTrace.toString() << endl; + } if (sendErr && g_logCommonErrors) { g_log << Logger::Warning << "Sending UDP reply to client " << source.toStringWithPort() << (source != fromaddr ? " (via " + fromaddr.toStringWithPort() + ")" : "") << " failed with: " @@ -3135,7 +3166,10 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr } if (t_pdl) { - if (t_pdl->ipfilter(source, destination, *dh)) { + eventTrace.add(RecEventTrace::LuaIPFilter); + bool ipf = t_pdl->ipfilter(source, destination, *dh); + eventTrace.add(RecEventTrace::LuaIPFilter, ipf, false); + if (ipf) { if (!g_quiet) { g_log<getTid()<<"/"<numProcesses()<<"] DROPPED question from "<d_responsePaddingDisabled = responsePaddingDisabled; dc->d_meta = std::move(meta); + dc->d_eventTrace = std::move(eventTrace); MT->makeThread(startDoResolve, (void*) dc.release()); // deletes dc + return 0; } @@ -3201,6 +3237,7 @@ static void handleNewUDPQuestion(int fd, FDMultiplexer::funcparam_t& var) cmsgbuf_aligned cbuf; bool firstQuery = true; std::vector proxyProtocolValues; + RecEventTrace eventTrace; for(size_t queriesCounter = 0; queriesCounter < s_maxUDPQueriesPerRound; queriesCounter++) { bool proxyProto = false; @@ -3210,6 +3247,9 @@ static void handleNewUDPQuestion(int fd, FDMultiplexer::funcparam_t& var) fillMSGHdr(&msgh, &iov, &cbuf, sizeof(cbuf), &data[0], data.size(), &fromaddr); if((len=recvmsg(fd, &msgh, 0)) >= 0) { + eventTrace.clear(); + eventTrace.setEnabled(true); + eventTrace.add(RecEventTrace::RecRecv); firstQuery = false; @@ -3335,12 +3375,13 @@ static void handleNewUDPQuestion(int fd, FDMultiplexer::funcparam_t& var) if(g_weDistributeQueries) { std::string localdata = data; - distributeAsyncFunction(data, [localdata, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues]() mutable - { return doProcessUDPQuestion(localdata, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues); }); + distributeAsyncFunction(data, [localdata, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues, eventTrace]() mutable { + return doProcessUDPQuestion(localdata, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues, eventTrace); + }); } else { ++s_threadInfos[t_id].numberOfDistributedQueries; - doProcessUDPQuestion(data, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues); + doProcessUDPQuestion(data, fromaddr, dest, source, destination, tv, fd, proxyProtocolValues, eventTrace); } } } diff --git a/pdns/recursordist/Makefile.am b/pdns/recursordist/Makefile.am index 9c157f43c0..593fd7d762 100644 --- a/pdns/recursordist/Makefile.am +++ b/pdns/recursordist/Makefile.am @@ -159,6 +159,7 @@ pdns_recursor_SOURCES = \ query-local-address.hh query-local-address.cc \ rcpgenerator.cc rcpgenerator.hh \ rec-carbon.cc \ + rec-eventtrace.cc rec-eventtrace.hh \ rec-lua-conf.hh rec-lua-conf.cc \ rec-protozero.cc rec-protozero.hh \ rec-snmp.hh rec-snmp.cc \ @@ -277,6 +278,7 @@ testrunner_SOURCES = \ qtype.cc qtype.hh \ query-local-address.hh query-local-address.cc \ rcpgenerator.cc \ + rec-eventtrace.cc rec-eventtrace.hh \ rec-zonetocache.cc rec-zonetocache.hh \ recpacketcache.cc recpacketcache.hh \ recursor_cache.cc recursor_cache.hh \ diff --git a/pdns/recursordist/rec-eventtrace.cc b/pdns/recursordist/rec-eventtrace.cc new file mode 100644 index 0000000000..c5ceca4efd --- /dev/null +++ b/pdns/recursordist/rec-eventtrace.cc @@ -0,0 +1,44 @@ +/* + * This file is part of PowerDNS or dnsdist. + * Copyright -- PowerDNS.COM B.V. and its contributors + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of version 2 of the GNU General Public License as + * published by the Free Software Foundation. + * + * In addition, for the avoidance of any doubt, permission is granted to + * link this program with OpenSSL and to (re)distribute the binaries + * produced as the result of such linking. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ +#include "rec-eventtrace.hh" + +#define NameEntry(M) \ + { \ + M, #M \ + } + +const std::map RecEventTrace::s_eventNames = { + NameEntry(Processing), + NameEntry(RecRecv), + NameEntry(DistPipe), + NameEntry(PCacheCheck), + NameEntry(SyncRes), + NameEntry(AnswerSent), + NameEntry(LuaGetTag), + NameEntry(LuaGetTagFFI), + NameEntry(LuaIPFilter), + NameEntry(LuaPreRPZ), + NameEntry(LuaPreResolve), + NameEntry(LuaPreOutQuery), + NameEntry(LuaPostResolve), + NameEntry(LuaNoData), + NameEntry(LuaNXDomain)}; diff --git a/pdns/recursordist/rec-eventtrace.hh b/pdns/recursordist/rec-eventtrace.hh new file mode 100644 index 0000000000..569a5739db --- /dev/null +++ b/pdns/recursordist/rec-eventtrace.hh @@ -0,0 +1,210 @@ +/* + * This file is part of PowerDNS or dnsdist. + * Copyright -- PowerDNS.COM B.V. and its contributors + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of version 2 of the GNU General Public License as + * published by the Free Software Foundation. + * + * In addition, for the avoidance of any doubt, permission is granted to + * link this program with OpenSSL and to (re)distribute the binaries + * produced as the result of such linking. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ +#pragma once + +#include "namespaces.hh" +#include +#include +#include + +class RecEventTrace +{ +public: + enum EventType : uint8_t + { + // Don't forget to add a new entry to the table in the .cc file! + Processing = 1, + RecRecv = 2, + DistPipe = 3, + PCacheCheck = 4, + SyncRes = 5, + AnswerSent = 6, + LuaGetTag = 50, + LuaGetTagFFI = 51, + LuaIPFilter = 52, + LuaPreRPZ = 53, + LuaPreResolve = 54, + LuaPreOutQuery = 55, + LuaPostResolve = 56, + LuaNoData = 57, + LuaNXDomain = 58 + }; + + static const std::map s_eventNames; + + RecEventTrace() + { + reset(); + } + + RecEventTrace(const RecEventTrace& old) : + d_events(std::move(old.d_events)), + d_base(old.d_base), + d_status(old.d_status) + { + old.d_status = Invalid; + } + RecEventTrace(RecEventTrace&& old) : + d_events(std::move(old.d_events)), + d_base(old.d_base), + d_status(old.d_status) + { + old.d_status = Invalid; + } + RecEventTrace& operator=(const RecEventTrace& old) = delete; + RecEventTrace& operator=(RecEventTrace&& old) + { + d_events = std::move(old.d_events); + d_base = old.d_base; + d_status = old.d_status; + old.d_status = Invalid; + return *this; + } + + typedef std::variant Value_t; + + static std::string toString(const EventType v) + { + return s_eventNames.at(v); + } + + static std::string toString(const Value_t& v) + { + if (std::holds_alternative(v)) { + return ""; + } + else if (std::holds_alternative(v)) { + return std::to_string(std::get(v)); + } + else if (std::holds_alternative(v)) { + return std::to_string(std::get(v)); + } + else if (std::holds_alternative(v)) { + return std::to_string(std::get(v)); + } + else if (std::holds_alternative(v)) { + return std::get(v); + } + return "?"; + } + + struct Entry + { + Entry(Value_t& v, EventType e, bool start, uint32_t ts) : + d_value(v), d_ts(ts), d_event(e), d_start(start) + { + } + Value_t d_value; + uint64_t d_ts; + EventType d_event; + bool d_start; + + std::string toString() const + { + std::string v = RecEventTrace::toString(d_value); + if (!v.empty()) { + v = "," + v; + } + return RecEventTrace::toString(d_event) + "(" + std::to_string(d_ts) + v + (d_start ? ")" : ",done)"); + } + }; + + void setEnabled(bool flag) + { + assert(d_status != Invalid); + d_status = flag ? Enabled : Disabled; + } + + bool enabled() const + { + return d_status == Enabled; + } + + void add(EventType e, Value_t v, bool start) + { + assert(d_status != Invalid); + if (d_status == Disabled) { + return; + } + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + uint64_t stamp = ts.tv_nsec + ts.tv_sec * 1000000000; + stamp -= d_base; + d_events.emplace_back(v, e, start, stamp); + } + + void add(EventType e) + { + add(e, Value_t(std::nullopt), true); + } + + template + void add(EventType e, T v, bool start) + { + add(e, Value_t(v), start); + } + + void clear() + { + d_events.clear(); + reset(); + } + void reset() + { + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + d_base = ts.tv_nsec + ts.tv_sec * 1000000000; + d_status = Disabled; + } + + std::string toString() const + { + assert(d_status != Invalid); + if (d_status == Disabled) { + return "Disabled\n"; + } + std::string ret = "eventTrace ["; + bool first = true; + for (const auto& e : d_events) { + if (first) { + first = false; + } + else { + ret += "; "; + } + ret += e.toString(); + } + ret += ']'; + return ret; + } + +private: + std::vector d_events; + uint64_t d_base; + enum Status + { + Disabled, + Invalid, + Enabled + }; + mutable Status d_status{Disabled}; +}; diff --git a/pdns/recursordist/test-syncres_cc.cc b/pdns/recursordist/test-syncres_cc.cc index ba81b99920..a18e206d99 100644 --- a/pdns/recursordist/test-syncres_cc.cc +++ b/pdns/recursordist/test-syncres_cc.cc @@ -39,7 +39,7 @@ void BaseLua4::getFeatures(Features&) { } -bool RecursorLua4::preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret) const +bool RecursorLua4::preoutquery(const ComboAddress& ns, const ComboAddress& requestor, const DNSName& query, const QType& qtype, bool isTcp, vector& res, int& ret, RecEventTrace& et) const { return false; } diff --git a/pdns/syncres.cc b/pdns/syncres.cc index 3a9009df49..b73f21ac30 100644 --- a/pdns/syncres.cc +++ b/pdns/syncres.cc @@ -125,6 +125,7 @@ SyncRes::SyncRes(const struct timeval& now) : d_authzonequeries(0), d_outquerie /** everything begins here - this is the entry point just after receiving a packet */ int SyncRes::beginResolve(const DNSName &qname, const QType qtype, QClass qclass, vector&ret, unsigned int depth) { + d_eventTrace.add(RecEventTrace::SyncRes); vState state = vState::Indeterminate; s_queries++; d_wasVariable=false; @@ -170,6 +171,7 @@ int SyncRes::beginResolve(const DNSName &qname, const QType qtype, QClass qclass } } + d_eventTrace.add(RecEventTrace::SyncRes, res, false); return res; } @@ -3932,7 +3934,7 @@ bool SyncRes::doResolveAtThisIP(const std::string& prefix, const DNSName& qname, } int preOutQueryRet = RCode::NoError; - if(d_pdl && d_pdl->preoutquery(remoteIP, d_requestor, qname, qtype, doTCP, lwr.d_records, preOutQueryRet)) { + if(d_pdl && d_pdl->preoutquery(remoteIP, d_requestor, qname, qtype, doTCP, lwr.d_records, preOutQueryRet, d_eventTrace)) { LOG(prefix< d_policyTags; boost::optional d_routingTag; + RecEventTrace d_eventTrace; unsigned int d_authzonequeries; unsigned int d_outqueries;