From: Otto Moerbeek Date: Thu, 11 Sep 2025 07:49:33 +0000 (+0200) Subject: Provide more spans for input processing X-Git-Tag: rec-5.4.0-alpha1~178^2~4 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=3dfe7b4ca11796c91b68bc8be4d5ffcc7c9e6095;p=thirdparty%2Fpdns.git Provide more spans for input processing Signed-off-by: Otto Moerbeek --- diff --git a/pdns/recursordist/pdns_recursor.cc b/pdns/recursordist/pdns_recursor.cc index 4ac18ec19b..62788544a5 100644 --- a/pdns/recursordist/pdns_recursor.cc +++ b/pdns/recursordist/pdns_recursor.cc @@ -1778,6 +1778,7 @@ void startDoResolve(void* arg) // NOLINT(readability-function-cognitive-complexi t_Counters.updateSnap(g_regressionTestMode); } + auto match = resolver.d_eventTrace.add(RecEventTrace::AnswerSent); if (!comboWriter->d_tcp) { struct msghdr msgh{}; struct iovec iov{}; @@ -1799,7 +1800,7 @@ void startDoResolve(void* arg) // NOLINT(readability-function-cognitive-complexi tcpGuard.setHandled(); } - resolver.d_eventTrace.add(RecEventTrace::AnswerSent); + resolver.d_eventTrace.add(RecEventTrace::AnswerSent, 0, false, match); // Now do the per query changing part of the protobuf message if (t_protobufServers.servers && !(luaconfsLocal->protobufExportConfig.taggedOnly && appliedPolicy.getName().empty() && comboWriter->d_policyTags.empty())) { @@ -2140,6 +2141,9 @@ bool expectProxyProtocol(const ComboAddress& from, const ComboAddress& listenAdd // mappedSource: the address we assume the query is coming from. Differs from source if table based mapping has been applied static string* doProcessUDPQuestion(const std::string& question, const ComboAddress& fromaddr, const ComboAddress& destaddr, ComboAddress source, ComboAddress destination, const ComboAddress& mappedSource, struct timeval tval, int fileDesc, std::vector& proxyProtocolValues, RecEventTrace& eventTrace, pdns::trace::InitialSpanInfo& otTrace) // NOLINT(readability-function-cognitive-complexity): https://github.com/PowerDNS/pdns/issues/12791 { + auto newParent = eventTrace.add(RecEventTrace::ProcessUDP); + auto oldParent = eventTrace.setParent(newParent); + RecEventTrace::EventScope traceScope(oldParent, eventTrace); RecThreadInfo::self().incNumberOfDistributedQueries(); gettimeofday(&g_now, nullptr); if (tval.tv_sec != 0) { @@ -2220,6 +2224,7 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr // We do not have a SyncRes specific Lua context at this point yet, so ok to use t_pdl if (needEDNSParse || (t_pdl && (t_pdl->hasGettagFunc() || t_pdl->hasGettagFFIFunc())) || dnsheader->opcode == static_cast(Opcode::Notify)) { try { + auto parseMatch = eventTrace.add(RecEventTrace::PacketParse); EDNSOptionViewMap ednsOptions; ecsFound = false; @@ -2229,12 +2234,14 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr (g_gettagNeedsEDNSOptions || SyncRes::eventTraceEnabled(SyncRes::event_trace_to_ot)) ? &ednsOptions : nullptr, ednsVersion); + eventTrace.add(RecEventTrace::PacketParse, 0, false, parseMatch); qnameParsed = true; ecsParsed = true; if (SyncRes::eventTraceEnabled(SyncRes::event_trace_to_ot)) { pdns::trace::extractOTraceIDs(ednsOptions, otTrace); } + if (t_pdl) { try { if (t_pdl->hasGettagFFIFunc()) { @@ -2289,6 +2296,7 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr "qname", Logging::Loggable(qname), "qtype", Logging::Loggable(QType(qtype)), "source", Logging::Loggable(source), "remote", Logging::Loggable(fromaddr)); } + match = eventTrace.add(RecEventTrace::AnswerSent); struct msghdr msgh{}; struct iovec iov{}; cmsgbuf_aligned cbuf{}; @@ -2299,8 +2307,8 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr addCMsgSrcAddr(&msgh, &cbuf, &destaddr, 0); } int sendErr = sendOnNBSocket(fileDesc, &msgh); - eventTrace.add(RecEventTrace::AnswerSent); - + eventTrace.add(RecEventTrace::AnswerSent, sendErr, false, match); + traceScope.close(0); if (t_protobufServers.servers && logResponse && (!luaconfsLocal->protobufExportConfig.taggedOnly || (pbData && pbData->d_tagged))) { protobufLogResponse(qname, qtype, dnsheader, luaconfsLocal, pbData, tval, false, source, destination, mappedSource, ednssubnet, uniqueId, requestorId, deviceId, deviceName, meta, eventTrace, otTrace, policyTags); } @@ -2404,6 +2412,7 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr comboWriter->d_responsePaddingDisabled = responsePaddingDisabled; comboWriter->d_meta = std::move(meta); + traceScope.close(0); comboWriter->d_eventTrace = std::move(eventTrace); comboWriter->d_otTrace = std::move(otTrace); @@ -2442,7 +2451,7 @@ static void handleNewUDPQuestion(int fileDesc, FDMultiplexer::funcparam_t& /* va // established the reference point, get an absolute TS as close as possible to the // eventTrace start of trace time. auto traceTS = pdns::trace::timestamp(); - eventTrace.add(RecEventTrace::ReqRecv); + auto match = eventTrace.add(RecEventTrace::ReqRecv); if (SyncRes::eventTraceEnabled(SyncRes::event_trace_to_ot)) { otTrace.clear(); otTrace.start_time_unix_nano = traceTS; @@ -2592,6 +2601,7 @@ static void handleNewUDPQuestion(int fileDesc, FDMultiplexer::funcparam_t& /* va destination = destaddr; } + eventTrace.add(RecEventTrace::ReqRecv, 0, false, match); if (RecThreadInfo::weDistributeQueries()) { std::string localdata = data; distributeAsyncFunction(data, [localdata = std::move(localdata), fromaddr, destaddr, source, destination, mappedSource, tval, fileDesc, proxyProtocolValues, eventTrace, otTrace]() mutable { diff --git a/pdns/recursordist/rec-eventtrace.cc b/pdns/recursordist/rec-eventtrace.cc index 8b1be8f529..33cde98d62 100644 --- a/pdns/recursordist/rec-eventtrace.cc +++ b/pdns/recursordist/rec-eventtrace.cc @@ -40,6 +40,9 @@ const std::unordered_map RecEventTrace::s NameEntry(LuaNXDomain), NameEntry(LuaPostResolveFFI), NameEntry(AuthRequest), + NameEntry(PacketParse), + NameEntry(ProcessUDP), + NameEntry(ProcessTCP), }; using namespace pdns::trace; diff --git a/pdns/recursordist/rec-eventtrace.hh b/pdns/recursordist/rec-eventtrace.hh index a661f5afc3..74117f0e6e 100644 --- a/pdns/recursordist/rec-eventtrace.hh +++ b/pdns/recursordist/rec-eventtrace.hh @@ -56,6 +56,9 @@ public: LuaPostResolveFFI = 110, AuthRequest = 120, + PacketParse = 121, + ProcessUDP = 122, + ProcessTCP = 123, }; static const std::unordered_map s_eventNames; diff --git a/pdns/recursordist/rec-tcp.cc b/pdns/recursordist/rec-tcp.cc index 6d26f2b417..fa7c9a7264 100644 --- a/pdns/recursordist/rec-tcp.cc +++ b/pdns/recursordist/rec-tcp.cc @@ -311,6 +311,10 @@ static void doProcessTCPQuestion(std::unique_ptr& comboWriter, s comboWriter->d_otTrace.clear(); comboWriter->d_otTrace.start_time_unix_nano = traceTS; } + auto newParent = comboWriter->d_eventTrace.add(RecEventTrace::ProcessTCP); + auto oldParent = comboWriter->d_eventTrace.setParent(newParent); + RecEventTrace::EventScope traceScope(oldParent, comboWriter->d_eventTrace); + auto luaconfsLocal = g_luaconfs.getLocal(); if (checkProtobufExport(luaconfsLocal)) { needEDNSParse = true; @@ -321,12 +325,14 @@ static void doProcessTCPQuestion(std::unique_ptr& comboWriter, s if (needEDNSParse || (t_pdl && (t_pdl->hasGettagFFIFunc() || t_pdl->hasGettagFunc())) || comboWriter->d_mdp.d_header.opcode == static_cast(Opcode::Notify)) { try { + auto parseMatch = comboWriter->d_eventTrace.add(RecEventTrace::PacketParse); EDNSOptionViewMap ednsOptions; comboWriter->d_ecsParsed = true; comboWriter->d_ecsFound = false; getQNameAndSubnet(conn->data, &qname, &qtype, &qclass, comboWriter->d_ecsFound, &comboWriter->d_ednssubnet, (g_gettagNeedsEDNSOptions || SyncRes::eventTraceEnabled(SyncRes::event_trace_to_ot)) ? &ednsOptions : nullptr, ednsVersion); + comboWriter->d_eventTrace.add(RecEventTrace::PacketParse, 0, false, parseMatch); qnameParsed = true; if (SyncRes::eventTraceEnabled(SyncRes::event_trace_to_ot)) { @@ -452,13 +458,15 @@ static void doProcessTCPQuestion(std::unique_ptr& comboWriter, s "source", Logging::Loggable(comboWriter->d_source), "remote", Logging::Loggable(comboWriter->d_remote)); } + auto answerMatch = comboWriter->d_eventTrace.add(RecEventTrace::AnswerSent); bool hadError = sendResponseOverTCP(comboWriter, response); finishTCPReply(comboWriter, hadError, false); struct timeval now{}; Utility::gettimeofday(&now, nullptr); uint64_t spentUsec = uSec(now - start); t_Counters.at(rec::Histogram::cumulativeAnswers)(spentUsec); - comboWriter->d_eventTrace.add(RecEventTrace::AnswerSent); + comboWriter->d_eventTrace.add(RecEventTrace::AnswerSent, 0, false, answerMatch); + traceScope.close(0); if (t_protobufServers.servers && comboWriter->d_logResponse && (!luaconfsLocal->protobufExportConfig.taggedOnly || (pbData && pbData->d_tagged))) { struct timeval tval{ @@ -500,6 +508,7 @@ static void doProcessTCPQuestion(std::unique_ptr& comboWriter, s t_fdm->setReadTTD(fileDesc, ttd, g_tcpTimeout); } tcpGuard.keep(); + traceScope.close(0); g_multiTasker->makeThread(startDoResolve, comboWriter.release()); // deletes dc } // good query } diff --git a/pdns/recursordist/syncres.cc b/pdns/recursordist/syncres.cc index e7c8ae1ffa..27ce77b7d6 100644 --- a/pdns/recursordist/syncres.cc +++ b/pdns/recursordist/syncres.cc @@ -5453,7 +5453,7 @@ bool SyncRes::doResolveAtThisIP(const std::string& prefix, const DNSName& qname, LOG(prefix << qname << ": Adding EDNS Client Subnet Mask " << ednsmask->toString() << " to query" << endl); s_ecsqueries++; } - auto match = d_eventTrace.add(RecEventTrace::AuthRequest, qname.toLogString() + '/' + qtype.toString(), true, 0); + auto match = d_eventTrace.add(RecEventTrace::AuthRequest, qname.toLogString() + '/' + qtype.toString() + '/' + remoteIP.toString(), true, 0); updateQueryCounts(prefix, qname, remoteIP, doTCP, doDoT); resolveret = asyncresolveWrapper(LogObject(prefix), remoteIP, d_doDNSSEC, qname, auth, qtype.getCode(), doTCP, sendRDQuery, &d_now, ednsmask, &lwr, &chained, nsName); // <- we go out on the wire!