HPCC-32770 Soapcall stats for DNS, connect, num failures

Signed-off-by: M Kelly <[email protected]>
hpcc-systems · Oct 8, 2024 · e56dc7b · e56dc7b
1 parent 0d5a839
commit e56dc7b
Show file tree

Hide file tree

Showing 5 changed files with 27 additions and 3 deletions.
diff --git a/common/thorhelper/thorsoapcall.cpp b/common/thorhelper/thorsoapcall.cpp
@@ -2469,9 +2469,15 @@ class CWSCAsyncFor : implements IWSCAsyncFor, public CInterface, public CAsyncFo
                     checkTimeLimitExceeded(&remainingMS);
                     Url &connUrl = master->proxyUrlArray.empty() ? url : master->proxyUrlArray.item(0);
 
+                    CCycleTimer dnsTimer;
+
                     // TODO: for DNS, do we use timeoutMS or remainingMS or remainingMS / maxRetries+1 or ?
                     ep.set(connUrl.host.get(), connUrl.port, master->timeoutMS);
 
+                    unsigned __int64 dnsNs = dnsTimer.elapsedNs();
+                    master->logctx.noteStatistic(StTimeSoapcallDNS, dnsNs);
+                    master->activitySpanScope->setSpanAttribute("SoapcallDNSTimeNs", dnsNs);
+
                     if (ep.isNull())
                         throw MakeStringException(-1, "Failed to resolve host '%s'", nullText(connUrl.host.get()));
 
@@ -2492,6 +2498,8 @@ class CWSCAsyncFor : implements IWSCAsyncFor, public CInterface, public CAsyncFo
                         isReused = false;
                         keepAlive = true;
 
+                        CCycleTimer connTimer;
+
                         // TODO: for each connect attempt, do we use timeoutMS or remainingMS or remainingMS / maxRetries or ?
                         socket.setown(blacklist->connect(ep, master->logctx, (unsigned)master->maxRetries, master->timeoutMS, master->roxieAbortMonitor, master->rowProvider));
 
@@ -2521,11 +2529,17 @@ class CWSCAsyncFor : implements IWSCAsyncFor, public CInterface, public CAsyncFo
                             throw makeStringException(0, err.str());
 #endif
                         }
+
+                        unsigned __int64 connNs = connTimer.elapsedNs();
+                        master->logctx.noteStatistic(StTimeSoapcallConnect, connNs);
+                        master->activitySpanScope->setSpanAttribute("SoapcallConnectTimeNs", connNs);
                     }
                     break;
                 }
                 catch (IException *e)
                 {
+                    master->logctx.noteStatistic(StNumSoapcallConnectFailures, 1);
+
                     if (master->timeLimitExceeded)
                     {
                         master->activitySpanScope->recordError(SpanError("Time Limit Exceeded", e->errorCode(), true, true));

diff --git a/roxie/ccd/ccdserver.cpp b/roxie/ccd/ccdserver.cpp
@@ -496,7 +496,7 @@ static const StatisticsMapping indexStatistics({StNumServerCacheHits, StNumIndex
 static const StatisticsMapping diskStatistics({StNumServerCacheHits, StNumDiskRowsRead, StNumDiskSeeks, StNumDiskAccepted,
                                                StNumDiskRejected, StSizeAgentReply, StTimeAgentWait, StTimeAgentQueue, StTimeAgentProcess, StTimeIBYTIDelay, StNumAckRetries,
                                                StSizeContinuationData, StNumContinuationRequests }, actStatistics);
-static const StatisticsMapping soapStatistics({ StTimeSoapcall }, actStatistics);
+static const StatisticsMapping soapStatistics({ StTimeSoapcall, StTimeSoapcallDNS, StTimeSoapcallConnect, StNumSoapcallConnectFailures }, actStatistics);
 static const StatisticsMapping groupStatistics({ StNumGroups, StNumGroupMax }, actStatistics);
 static const StatisticsMapping sortStatistics({ StTimeSortElapsed }, actStatistics);
 static const StatisticsMapping indexWriteStatistics({ StNumDuplicateKeys, StNumLeafCacheAdds, StNumNodeCacheAdds, StNumBlobCacheAdds }, actStatistics);
@@ -518,7 +518,7 @@ extern const StatisticsMapping accumulatedStatistics({StWhenFirstRow, StTimeLoca
                                                       StCycleBlobFetchCycles, StCycleLeafFetchCycles, StCycleNodeFetchCycles, StTimeBlobFetch, StTimeLeafFetch, StTimeNodeFetch,
                                                       StNumNodeDiskFetches, StNumLeafDiskFetches, StNumBlobDiskFetches,
                                                       StNumDiskRejected, StSizeAgentReply, StTimeAgentWait,
-                                                      StTimeSoapcall,
+                                                      StTimeSoapcall, StTimeSoapcallDNS, StTimeSoapcallConnect, StNumSoapcallConnectFailures,
                                                       StNumGroups,
                                                       StTimeSortElapsed,
                                                       StNumDuplicateKeys,

diff --git a/system/jlib/jstatcodes.h b/system/jlib/jstatcodes.h
@@ -311,6 +311,11 @@ enum StatisticKind
     StNumMatchRightRowsMax,
     StNumMatchCandidates,
     StNumMatchCandidatesMax,
+    StTimeSoapcallDNS,                  // Time spent in DNS lookups for soapcalls
+    StTimeSoapcallConnect,              // Time spent in connect[+SSL_connect] for soapcalls
+    StCycleSoapcallDNSCycles,
+    StCycleSoapcallConnectCycles,
+    StNumSoapcallConnectFailures,
     StMax,
 
     //For any quantity there is potentially the following variants.

diff --git a/system/jlib/jstats.cpp b/system/jlib/jstats.cpp
@@ -983,6 +983,11 @@ static const constexpr StatisticMeta statsMetaData[StMax] = {
     { NUMSTAT(MatchRightRowsMax), "The largest number of right rows in a join group" },
     { NUMSTAT(MatchCandidates), "The number of candidate combinations of left and right rows forming join groups" },
     { NUMSTAT(MatchCandidatesMax), "The largest number of candidate combinations of left and right rows in a single group" },
+    { TIMESTAT(SoapcallDNS), "The time taken for DNS lookup in SOAPCALL" },
+    { TIMESTAT(SoapcallConnect), "The time taken for connect[+SSL_connect] in SOAPCALL" },
+    { CYCLESTAT(SoapcallDNS) },
+    { CYCLESTAT(SoapcallConnect) },
+    { NUMSTAT(SoapcallConnectFailures), "The number of SOAPCALL connect failures" },
 };
 
 static MapStringTo<StatisticKind, StatisticKind> statisticNameMap(true);

diff --git a/thorlcr/thorutil/thormisc.cpp b/thorlcr/thorutil/thormisc.cpp
@@ -75,7 +75,7 @@ static Owned<IMPtagAllocator> ClusterMPAllocator;
 // stat. mappings shared between master and slave activities
 const StatisticsMapping spillStatistics({StTimeSpillElapsed, StTimeSortElapsed, StNumSpills, StSizeSpillFile, StSizePeakTempDisk});
 const StatisticsMapping executeStatistics({StTimeTotalExecute, StTimeLocalExecute, StTimeBlocked});
-const StatisticsMapping soapcallStatistics({StTimeSoapcall});
+const StatisticsMapping soapcallStatistics({StTimeSoapcall, StTimeSoapcallDNS, StTimeSoapcallConnect, StNumSoapcallConnectFailures});
 const StatisticsMapping basicActivityStatistics({}, executeStatistics, spillStatistics);
 const StatisticsMapping groupActivityStatistics({StNumGroups, StNumGroupMax}, basicActivityStatistics);
 const StatisticsMapping indexReadFileStatistics({}, diskReadRemoteStatistics, jhtreeCacheStatistics);