Merge pull request #18056 from ghalliday/issue30397

HPCC-30397 Review existing server spans to match expected conventions Reviewed-By: Rodrigo Pastrana <[email protected]> Reviewed-By: Anthony Fishbeck <[email protected]> Merged-by: Gavin Halliday <[email protected]>
hpcc-systems · Dec 15, 2023 · d6e08bb · d6e08bb
2 parents c834127 + 27b54ba
commit d6e08bb
Show file tree

Hide file tree

Showing 19 changed files with 105 additions and 24 deletions.
diff --git a/common/thorhelper/thorsoapcall.cpp b/common/thorhelper/thorsoapcall.cpp
@@ -1675,6 +1675,20 @@ IWSCHelper * createHttpCallHelper(IWSCRowProvider *r, IEngineRowAllocator * outp
 }
 
 //=================================================================================================
+
+const char * queryAlternativeHeader(const char * header)
+{
+    if (strieq(header, kGlobalIdHttpHeaderName))
+        return kLegacyGlobalIdHttpHeaderName;
+    if (strieq(header, kLegacyGlobalIdHttpHeaderName))
+        return kGlobalIdHttpHeaderName;
+    if (strieq(header, kCallerIdHttpHeaderName))
+        return kLegacyCallerIdHttpHeaderName;
+    if (strieq(header, kLegacyCallerIdHttpHeaderName))
+        return kCallerIdHttpHeaderName;
+    return nullptr;
+}
+
 bool httpHeaderBlockContainsHeader(const char *httpheaders, const char *header)
 {
     if (!httpheaders || !*httpheaders)
@@ -1921,11 +1935,18 @@ class CWSCAsyncFor : implements IWSCAsyncFor, public CInterface, public CAsyncFo
             ForEach(*iter)
             {
                 const char * key = iter->getPropKey();
-                if (!httpHeaderBlockContainsHeader(httpheaders, key))
+                bool hasHeader = httpHeaderBlockContainsHeader(httpheaders, key);
+                if (!hasHeader)
                 {
-                    const char * value = iter->queryPropValue();
-                    if (!isEmptyString(value))
-                        request.append(key).append(": ").append(value).append("\r\n");
+                    //If this header is http-global-id, check that global-id hasn't been explicitly added already
+                    const char * altHeader = queryAlternativeHeader(key);
+                    bool hasAltHeader = altHeader && httpHeaderBlockContainsHeader(httpheaders, altHeader);
+                    if (!hasAltHeader)
+                    {
+                        const char * value = iter->queryPropValue();
+                        if (!isEmptyString(value))
+                            request.append(key).append(": ").append(value).append("\r\n");
+                    }
                 }
             }
         }

diff --git a/ecl/eclagent/eclagent.cpp b/ecl/eclagent/eclagent.cpp
@@ -2131,7 +2131,8 @@ void EclAgent::runProcess(IEclProcess *process)
     allocatorMetaCache.setown(createRowAllocatorCache(this));
 
     Owned<IProperties> traceHeaders = extractTraceDebugOptions(queryWorkUnit());
-    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan(queryWorkUnit()->queryWuid(), traceHeaders);
+    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders);
+    requestSpan->setSpanAttribute("hpcc.wuid", queryWorkUnit()->queryWuid());
     ContextSpanScope spanScope(updateDummyContextLogger(), requestSpan);
 
     // a component may specify an alternate name for the agent/workflow memory area,

diff --git a/esp/bindings/http/platform/httpservice.cpp b/esp/bindings/http/platform/httpservice.cpp
@@ -390,7 +390,7 @@ int CEspHttpServer::processRequest()
             //which would remove the activeSpan when this function exits, use
             //setActiveSpan()
             //It is possible that using EspContextSpanScope would be better
-            Owned<ISpan> serverSpan = m_request->createServerSpan();
+            Owned<ISpan> serverSpan = m_request->createServerSpan(serviceName, methodName);
             ctx->setActiveSpan(serverSpan);
 
             if (thebinding!=NULL)

diff --git a/esp/bindings/http/platform/httptransport.cpp b/esp/bindings/http/platform/httptransport.cpp
@@ -1915,11 +1915,16 @@ int CHttpRequest::receive(IMultiException *me)
     return 0;
 }
 
-ISpan * CHttpRequest::createServerSpan()
+ISpan * CHttpRequest::createServerSpan(const char * serviceName, const char * methodName)
 {
     //MORE: The previous code would be better off querying httpHeaders...
+    StringBuffer spanName;
+    spanName.append(serviceName);
+    if (!isEmptyString(methodName))
+        spanName.append("/").append(methodName);
+    spanName.toLowerCase();
     Owned<IProperties> httpHeaders = getHeadersAsProperties(m_headers);
-    return queryTraceManager().createServerSpan("HTTPRequest", httpHeaders, SpanFlags::EnsureGlobalId);
+    return queryTraceManager().createServerSpan(spanName, httpHeaders, SpanFlags::EnsureGlobalId);
 }
 
 void CHttpRequest::annotateSpan(const char * key, const char * value)

diff --git a/esp/bindings/http/platform/httptransport.ipp b/esp/bindings/http/platform/httptransport.ipp
@@ -369,7 +369,7 @@ public:
 
     virtual int receive(IMultiException *me);
 
-    ISpan * createServerSpan();
+    ISpan * createServerSpan(const char * serviceName, const char * methodName);
     void updateContext();
     void annotateSpan(const char * key, const char * value);
 

diff --git a/esp/services/ws_ecl/ws_ecl_service.cpp b/esp/services/ws_ecl/ws_ecl_service.cpp
@@ -2001,7 +2001,7 @@ int CWsEclBinding::submitWsEclWorkunit(IEspContext & context, WsEclWuInfo &wsinf
 
     Owned<ISpan> clientSpan;
     ISpan * activeSpan = context.queryActiveSpan();
-    clientSpan.setown(activeSpan->createClientSpan("wsecl/SubmitWorkunit"));
+    clientSpan.setown(activeSpan->createClientSpan("run_workunit"));
     Owned<IProperties> httpHeaders = ::getClientHeaders(clientSpan);
     recordTraceDebugOptions(workunit, httpHeaders);
 

diff --git a/esp/services/ws_workunits/ws_workunitsHelpers.cpp b/esp/services/ws_workunits/ws_workunitsHelpers.cpp
@@ -3769,6 +3769,11 @@ void WsWuHelpers::submitWsWorkunit(IEspContext& context, IConstWorkUnit* cw, con
         }
     }
 
+    ISpan * activeSpan = context.queryActiveSpan();
+    Owned<ISpan> clientSpan(activeSpan->createClientSpan("run_workunit"));
+    Owned<IProperties> httpHeaders = ::getClientHeaders(clientSpan);
+    recordTraceDebugOptions(wu, httpHeaders);
+
     if (resetWorkflow)
         wu->resetWorkflow();
     if (!compile)

diff --git a/roxie/ccd/ccdlistener.cpp b/roxie/ccd/ccdlistener.cpp
@@ -1179,7 +1179,8 @@ class RoxieWorkUnitWorker : public RoxieQueryWorker
         Owned<StringContextLogger> logctx = new StringContextLogger(wuid.get());
 
         Owned<IProperties> traceHeaders = extractTraceDebugOptions(wu);
-        Owned<ISpan> requestSpan = queryTraceManager().createServerSpan(wu->queryWuid(), traceHeaders);
+        Owned<ISpan> requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders);
+        requestSpan->setSpanAttribute("hpcc.wuid", wuid);
         ContextSpanScope spanScope(*logctx, requestSpan);
 
         Owned<IQueryFactory> queryFactory;
@@ -1438,7 +1439,7 @@ class RoxieProtocolMsgContext : implements IHpccProtocolMsgContext, public CInte
         return *cascade;
     }
 
-    virtual void startSpan(const char * id, const IProperties * headers) override
+    virtual void startSpan(const char * id, const char * querySetName, const char * queryName, const IProperties * headers) override
     {
         Linked<const IProperties> allHeaders = headers;
         SpanFlags flags = (ensureGlobalIdExists) ? SpanFlags::EnsureGlobalId : SpanFlags::None;
@@ -1455,7 +1456,12 @@ class RoxieProtocolMsgContext : implements IHpccProtocolMsgContext, public CInte
 
         ensureContextLogger();
 
-        Owned<ISpan> requestSpan = queryTraceManager().createServerSpan("request", allHeaders, flags);
+        const char * spanQueryName = !isEmptyString(queryName) ? queryName : "run_query";
+        StringBuffer spanName(querySetName);
+        if (spanName.length())
+            spanName.append('/');
+        spanName.append(spanQueryName);
+        Owned<ISpan> requestSpan = queryTraceManager().createServerSpan(spanName, allHeaders, flags);
         //The span has a lifetime the same length as the logctx, so no need to restore it at the end of the query
         logctx->setActiveSpan(requestSpan);
 

diff --git a/roxie/ccd/ccdprotocol.cpp b/roxie/ccd/ccdprotocol.cpp
@@ -1891,7 +1891,7 @@ class RoxieSocketWorker : public ProtocolQueryWorker
                 uid = NULL;
                 sanitizeQuery(queryPT, queryName, sanitizedText, httpHelper, uid, isBlind, isDebug);
 
-                msgctx->startSpan(uid, httpHelper.queryRequestHeaders());
+                msgctx->startSpan(uid, querySetName, queryName, httpHelper.queryRequestHeaders());
 
                 if (!uid)
                     uid = "-";

diff --git a/roxie/ccd/hpccprotocol.hpp b/roxie/ccd/hpccprotocol.hpp
@@ -41,7 +41,7 @@ interface IHpccProtocolMsgContext : extends IInterface
     virtual bool getIntercept() = 0;
     virtual void outputLogXML(IXmlStreamFlusher &out) = 0;
     virtual void writeLogXML(IXmlWriter &writer) = 0;
-    virtual void startSpan(const char * uid, const IProperties * headers) = 0;
+    virtual void startSpan(const char * uid, const char * querySetName, const char * queryName, const IProperties * headers) = 0;
 };
 
 interface IHpccProtocolResultsWriter : extends IInterface

diff --git a/system/jlib/jprop.cpp b/system/jlib/jprop.cpp
@@ -448,6 +448,36 @@ IProperties * getHeadersAsProperties(const StringArray & httpHeaders, char separ
 }
 
 
+void getPropertiesAsXml(StringBuffer & out, const IProperties * properties)
+{
+    if (properties)
+    {
+        Owned<IPropertyIterator> it = properties->getIterator();
+        for (it->first(); it->isValid(); it->next())
+        {
+            const char* k = it->getPropKey();
+            const char* v = it->queryPropValue();
+            out.append(' ').append(k).append("=\"");
+            encodeUtf8XML(v, out);
+            out.append('"');
+        }
+    }
+}
+
+void printProperties(const IProperties * properties)
+{
+    StringBuffer temp;
+    getPropertiesAsXml(temp, properties);
+    puts(temp.str());
+}
+
+void dbglogProperties(const IProperties * properties, const char * prefix)
+{
+    StringBuffer temp;
+    getPropertiesAsXml(temp, properties);
+    DBGLOG("%s: %s", prefix, temp.str());
+}
+
 static CProperties *sysProps = NULL;
 
 extern jlib_decl IProperties *querySystemProperties()

diff --git a/system/jlib/jprop.hpp b/system/jlib/jprop.hpp
@@ -79,5 +79,9 @@ extern jlib_decl IProperties *getSystemProperties();
 extern jlib_decl void extractHeaders(IProperties * target, const StringArray & httpHeaders, char separator = ':');
 extern jlib_decl IProperties * getHeadersAsProperties(const StringArray & httpHeaders, char separator = ':');
 
+extern jlib_decl void getPropertiesAsXml(StringBuffer & out, const IProperties * properties);
+extern jlib_decl void printProperties(const IProperties * properties);
+extern jlib_decl void dbglogProperties(const IProperties * properties, const char * prefix);
+
 #endif
 
diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp
@@ -954,7 +954,7 @@ class CServerSpan : public CSpan
     {
         bool success = CSpan::getSpanContext(ctxProps, otelFormatted);
 
-        if (remoteParentSpanCtx.IsValid())
+        if (!otelFormatted && remoteParentSpanCtx.IsValid())
         {
             StringBuffer remoteParentSpanID;
             char remoteParentSpanId[16] = {0};

diff --git a/testing/regress/ecl/globalid.ecl b/testing/regress/ecl/globalid.ecl
@@ -21,6 +21,9 @@ import lib_workunitservices;
 #option('CallerId', 'PkAntaCLkY4MknCnXA');
 #option('GlobalId', 'xPSDvT9akc1fGSTZWJKb');
 
-OUTPUT(logging.getGlobalId(), NAMED('GlobalId'));
-OUTPUT(logging.getCallerId(), NAMED('CallerId'));
+//The global and caller ids could either be set by esp when the query is received
+//or from the #options above, so the test checks that it has been set by someone.
+
+OUTPUT(logging.getGlobalId() != '', NAMED('GlobalId'));
+OUTPUT(logging.getCallerId() != '', NAMED('CallerId'));
 
diff --git a/testing/regress/ecl/key/globalid.xml b/testing/regress/ecl/key/globalid.xml
@@ -1,6 +1,6 @@
 <Dataset name='GlobalId'>
- <Row><GlobalId>xPSDvT9akc1fGSTZWJKb</GlobalId></Row>
+ <Row><GlobalId>true</GlobalId></Row>
 </Dataset>
 <Dataset name='CallerId'>
- <Row><CallerId>PkAntaCLkY4MknCnXA</CallerId></Row>
+ <Row><CallerId>true</CallerId></Row>
 </Dataset>
diff --git a/testing/regress/ecl/key/soapcall_multihttpheader.xml b/testing/regress/ecl/key/soapcall_multihttpheader.xml
@@ -1,5 +1,5 @@
 <Dataset name='soapcallResult'>
- <Row><Method>POST</Method><UrlPath>/WsSmc/HttpEcho</UrlPath><UrlParameters>name=doe,joe&amp;number=1</UrlParameters><Headers><Header>Accept-Encoding: gzip, deflate</Header><Header>StoredHeader: StoredHeaderDefault</Header><Header>constHeader: constHeaderValue</Header><Header>literalHeader: literalHeaderValue</Header><Header>traceparent: 00-0123456789abcdef0123456789abcdef-0123456789abcdef-01</Header></Headers><Content>&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soap:Envelope xmlns:soap=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot;&gt;
+ <Row><Method>POST</Method><UrlPath>/WsSmc/HttpEcho</UrlPath><UrlParameters>name=doe,joe&amp;number=1</UrlParameters><Headers><Header>Accept-Encoding: gzip, deflate</Header><Header>HPCC-Caller-Id: http111</Header><Header>HPCC-Global-Id: 9876543210</Header><Header>StoredHeader: StoredHeaderDefault</Header><Header>constHeader: constHeaderValue</Header><Header>literalHeader: literalHeaderValue</Header><Header>traceparent: 00-0123456789abcdef0123456789abcdef-0123456789abcdef-01</Header></Headers><Content>&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soap:Envelope xmlns:soap=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot;&gt;
  &lt;soap:Body&gt;
   &lt;HttpEcho&gt;
    &lt;Name&gt;Doe, Joe&lt;/Name&gt;
@@ -10,7 +10,7 @@
 &lt;/soap:Envelope&gt;</Content></Row>
 </Dataset>
 <Dataset name='proxyResult'>
- <Row><Method>POST</Method><UrlPath>/WsSmc/HttpEcho</UrlPath><UrlParameters>name=doe,joe&amp;number=1</UrlParameters><Headers><Header>Accept-Encoding: gzip, deflate</Header><Header>StoredHeader: StoredHeaderDefault</Header><Header>constHeader: constHeaderValue</Header><Header>literalHeader: literalHeaderValue</Header><Header>traceparent: 00-0123456789abcdef0123456789abcdef-f123456789abcdef-01</Header></Headers><Content>&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soap:Envelope xmlns:soap=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot;&gt;
+ <Row><Method>POST</Method><UrlPath>/WsSmc/HttpEcho</UrlPath><UrlParameters>name=doe,joe&amp;number=1</UrlParameters><Headers><Header>Accept-Encoding: gzip, deflate</Header><Header>HPCC-Caller-Id: http111</Header><Header>HPCC-Global-Id: 9876543210</Header><Header>StoredHeader: StoredHeaderDefault</Header><Header>constHeader: constHeaderValue</Header><Header>literalHeader: literalHeaderValue</Header><Header>traceparent: 00-0123456789abcdef0123456789abcdef-f123456789abcdef-01</Header></Headers><Content>&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soap:Envelope xmlns:soap=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot;&gt;
  &lt;soap:Body&gt;
   &lt;HttpEcho&gt;
    &lt;Name&gt;Doe, Joe&lt;/Name&gt;

diff --git a/testing/regress/ecl/soapcall_multihttpheader.ecl b/testing/regress/ecl/soapcall_multihttpheader.ecl
@@ -41,6 +41,7 @@ string constHeader := 'constHeaderValue';
 
 soapcallResult := SOAPCALL(TargetURL, 'HttpEcho', httpEchoServiceRequestRecord, DATASET(httpEchoServiceResponseRecord), LITERAL, xpath('HttpEchoResponse'),
                 httpheader('StoredHeader', storedHeader), httpheader('literalHeader', 'literalHeaderValue'), httpheader('constHeader', constHeader),
+                httpheader('HPCC-Global-Id','9876543210'), httpheader('HPCC-Caller-Id','http111'),
                 httpheader('traceparent', '00-0123456789abcdef0123456789abcdef-0123456789abcdef-01'));
 
 output(soapcallResult, named('soapcallResult'));
@@ -52,6 +53,7 @@ string TargetProxy := 'http://' + TargetIP + ':8010';
 
 proxyResult := SOAPCALL(HostURL, 'HttpEcho', httpEchoServiceRequestRecord, DATASET(httpEchoServiceResponseRecord), LITERAL, xpath('HttpEchoResponse'), proxyAddress(TargetProxy),
                 httpheader('StoredHeader', storedHeader), httpheader('literalHeader', 'literalHeaderValue'), httpheader('constHeader', constHeader),
+                httpheader('HPCC-Global-Id','9876543210'), httpheader('HPCC-Caller-Id','http111'),
                 httpheader('traceparent', '00-0123456789abcdef0123456789abcdef-f123456789abcdef-01'));
 
 output(proxyResult, named('proxyResult'));
diff --git a/thorlcr/graph/thgraphmaster.cpp b/thorlcr/graph/thgraphmaster.cpp
@@ -1486,7 +1486,9 @@ CJobMaster::CJobMaster(IConstWorkUnit &_workunit, const char *graphName, ILoaded
     init();
 
     Owned<IProperties> traceHeaders = extractTraceDebugOptions(workunit);
-    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan(workunit->queryWuid(), traceHeaders);
+    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders);
+    requestSpan->setSpanAttribute("hpcc.wuid", workunit->queryWuid());
+    requestSpan->setSpanAttribute("hpcc.graph", graphName);
     ContextSpanScope spanScope(*logctx, requestSpan);
 
     resumed = WUActionResume == workunit->getAction();

diff --git a/thorlcr/graph/thgraphslave.cpp b/thorlcr/graph/thgraphslave.cpp
@@ -1680,7 +1680,9 @@ CJobSlave::CJobSlave(ISlaveWatchdog *_watchdog, IPropertyTree *_workUnitInfo, co
     init();
 
     Owned<IProperties> traceHeaders = deserializeTraceDebugOptions(workUnitInfo->queryPropTree("Debug"));
-    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan(wuid, traceHeaders);
+    Owned<ISpan> requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders);
+    requestSpan->setSpanAttribute("hpcc.wuid", wuid);
+    requestSpan->setSpanAttribute("hpcc.graph", graphName);
     ContextSpanScope spanScope(*logctx, requestSpan);
 
     oldNodeCacheMem = 0;