Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HPCC-30397 Review existing server spans to match expected conventions #18056

Merged
merged 1 commit into from
Dec 15, 2023
Merged

HPCC-30397 Review existing server spans to match expected conventions #18056

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
29 changes: 25 additions & 4 deletions common/thorhelper/thorsoapcall.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If a query set "hpcc-global-id" but the headers line set "global-id" or vice-versa you would get both values in the headers potentially causing confusion. Only likely to affect the regression tests - but it did once the ids were preserved where they were previously dropped.

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");
}
}
}
}
Expand Down
3 changes: 2 additions & 1 deletion ecl/eclagent/eclagent.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
2 changes: 1 addition & 1 deletion esp/bindings/http/platform/httpservice.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down
9 changes: 7 additions & 2 deletions esp/bindings/http/platform/httptransport.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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))
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@afishbeck depending on how the service function is called, sometimes the methodName is not known at this point (part of the soap envelope?) How can it be cleanly extracted? May require some refactoring, so a different PR.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes this timing issue related to when we know the name comes up sometimes. You could open a JIRA to refactor to always get the name at the beginning. I actually did similar refactoring in roxie.

One idea would be to do a quick pull parser extraction of the name even if it came from the SOAP/XML/JSON content of the message body. Generally the pull parser would usually only have to walk a few tags to find what it needs. It could then abandon the parsing until the body is fully parsed later.

Another way would be to always parse the body much sooner. Early on we decided to avoid extra overhead in case we rejected the request for other reasons.. for example security. We save a little time and memory, or perhaps there may occasionally be huge requests. I think Roxie parses pretty early but isn't as close to the front lines as ESP.

Either way would be good in the sense that it would let us refactor some other code that has to wait until the method is known.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See QueryNameExtractor in roxie.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

HPCC-31013 created.

spanName.append("/").append(methodName);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's prob fine, but I wonder if the / delimiter could cause problems downstream. (prometheous, grafana, elastic will likely use this value in UI widgets). I didn't find specific rules on span nomenclature or even attribute naming rules which excludes the slash, but I'd consider another delimiter

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One of the examples on the open telemetry recommendations for span name conventions (https://github.com/open-telemetry/opentelemetry-specification/blob/v1.26.0/specification/trace/api.md#span) uses a / : "get_account/{accountId}" - so I think it can be considered safe.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair enough.

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)
Expand Down
2 changes: 1 addition & 1 deletion esp/bindings/http/platform/httptransport.ipp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);

Expand Down
2 changes: 1 addition & 1 deletion esp/services/ws_ecl/ws_ecl_service.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is where the idea of PRODUCER spans gets interesting. I guess the producer span would be created here? or would we do it in workunit.dll when a workunit is created? Then even the most basic eclagent/roxie/hthor job would be represented by a CONSUMER span? And thor jobs may create multiple consumer spans.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree, this is where the producer span would be. I'm not sure that I agree it makes sense to differentiate a consumer span from a server span though. In general the service does not know whether the parent span is waiting for it or not. It may make sense with an internal producer/consumer model.

Copy link
Member

@afishbeck afishbeck Dec 14, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ghalliday just wanted to make a note to retain this thought.

The reality could be different then the theory. BUT I think the reason for a consumer span rather than a server span is that a server span should show up as a sequential child within the timeframe of the span of its parent.

If a THOR job itermitantly / asynchronously works on a workunit the spans would not correlate to the original parent at all which isn't what I think is expected of server spans.

Web app example

WEB server span 
---------------------------------------------------------------------------------
ROXIE server span1        ROXIE server span2          ROXIE server span3
-------------------      -------------------------     ---------------------------    
                                           SOAPCALL span1 
                                           ------------------ 

THOR job example

JOB kickoff PRODUCER span
(finished before any work even really begins)
--

                                       THOR graph CONSUMER1                  THOR graph CONSUMER2
                                       ------------------------------           -------------------------------

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What I am not sure about in this model is that the consumer does not really know whether the caller is waiting for it or not. Does a webservice know if the caller is waiting for it? On reflection maybe it does. What happens if a server span sends an acknowledgement to the client before it finishes processing? Is it require to create an internal producer/consumer span if that happens?
In which case anything that pulls something off a queue should be a consumer span, but anything that is processing an http request is a server span. Definitely something to flesh out in a further discussion.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ghalliday, regarding "Does a webservice know if the caller is waiting for it?", I would think so in the case of simple synchronous HTTP. But what about the async or even asymmetric case? Such as where a web server does HTTP/2 Push, or Server-Sent Events? That seems to match the PRODUCER pattern.
[ Sorry if this is not a use case/pattern currently being considered or discussed. But as a discussion of span naming conventions that will extend beyond HPCC, I though the question is relevant ]

Copy link
Member

@afishbeck afishbeck Dec 15, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

WsECL specifically lets the caller decide if they want to have it return immediately giving them the WUID so they can retrieve the result, or will wait for the workunit to complete.

I'd consider:

  1. having a flag in the workunit that determines whether graph processors should create server or consumer spans. A use case that waits for the workunit to finish could set the flag to produce server spans, and batch like component could set it to create consumers.
  2. We aren't talking about HPCC behavior, rather about how this is recorded on the backend for external observability stacks to display. In some sense we are choosing a diagram we want used? or perhaps tools will provide different functionality. But in any case the reality of how those tools operate on the data will be the long term deciding factor for which representation is best. Since they probably modeled current PRODUCER behavior around message queues and databases we could see how well the representation of those in grafana and elastic match with async workunits.

Owned<IProperties> httpHeaders = ::getClientHeaders(clientSpan);
recordTraceDebugOptions(workunit, httpHeaders);

Expand Down
5 changes: 5 additions & 0 deletions esp/services/ws_workunits/ws_workunitsHelpers.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3769,6 +3769,11 @@ void WsWuHelpers::submitWsWorkunit(IEspContext& context, IConstWorkUnit* cw, con
}
}

ISpan * activeSpan = context.queryActiveSpan();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@afishbeck if you submitted a workunit the globalids etc. where not preserved in the workunit. They are now. Should this code be commoned up with the code in ws_ecl_service.cpp?

Copy link
Member

@afishbeck afishbeck Dec 12, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, when ws_ecl_service.cpp runs the job as a workunit (as opposed to calling out to roxie) it clones the original workunit. Because of that submitWsEclWorkunit is a bit different from submitWsWorkunit here, BUT it has context available so this bit of code should be able to be commoned up.

Owned<ISpan> clientSpan(activeSpan->createClientSpan("run_workunit"));
Owned<IProperties> httpHeaders = ::getClientHeaders(clientSpan);
recordTraceDebugOptions(wu, httpHeaders);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixing the headers not being recorded in the workunit revealed another problem - see thorsoapcall for details.


if (resetWorkflow)
wu->resetWorkflow();
if (!compile)
Expand Down
12 changes: 9 additions & 3 deletions roxie/ccd/ccdlistener.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand All @@ -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);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The name of the deployed roxie query is used as the span name.

Copy link
Member

@afishbeck afishbeck Dec 12, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do wonder if prefixing with the queryset name (aka target, and generally in AKS this is just the roxie name) would help find queries from the same roxie.. but knowing that for sure will come down to experience.

//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);

Expand Down
2 changes: 1 addition & 1 deletion roxie/ccd/ccdprotocol.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 = "-";
Expand Down
2 changes: 1 addition & 1 deletion roxie/ccd/hpccprotocol.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
30 changes: 30 additions & 0 deletions system/jlib/jprop.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down
4 changes: 4 additions & 0 deletions system/jlib/jprop.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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

2 changes: 1 addition & 1 deletion system/jlib/jtrace.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -707,7 +707,7 @@ class CServerSpan : public CSpan
{
bool success = CSpan::getSpanContext(ctxProps, otelFormatted);

if (remoteParentSpanCtx.IsValid())
if (!otelFormatted && remoteParentSpanCtx.IsValid())
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@afishbeck please check. remoteParentSpanId shouldn't have been being included in the client headers. I opened HPCC-30927 to split this function into two, because it is confusing as it stands.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed. For what it's worth, I thought I had 2 independent versions of this function in at least one of my many PR commits.
One function should provide propagation headers the traceparent and tracestate, the other should provide the context as props.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agree with both of you, these should be 2 functions it's very confusing.

So I guess if blocking remoteParentSpanID when otelFormatted is set prevents it from being sent as a header then this code is right?

{
StringBuffer remoteParentSpanID;
char remoteParentSpanId[16] = {0};
Expand Down
7 changes: 5 additions & 2 deletions testing/regress/ecl/globalid.ecl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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'));

4 changes: 2 additions & 2 deletions testing/regress/ecl/key/globalid.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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>
4 changes: 2 additions & 2 deletions testing/regress/ecl/key/soapcall_multihttpheader.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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;
Expand All @@ -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;
Expand Down
2 changes: 2 additions & 0 deletions testing/regress/ecl/soapcall_multihttpheader.ecl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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'));
Expand All @@ -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'));
4 changes: 3 additions & 1 deletion thorlcr/graph/thgraphmaster.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1485,7 +1485,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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ghalliday I wonder if workunit spans should be created as PRODUCER spans and then when a component works on that workunit it should be CONSUMER spans. (consumer may sound weird for something like thor, but see the description below):

  • SERVER Indicates that the span covers server-side handling of a synchronous RPC or other remote request. This span is often the child of a remote CLIENT span that was expected to wait for a response.
  • CLIENT Indicates that the span describes a request to some remote service. This span is usually the parent of a remote SERVER span and does not end until the response is received.
  • PRODUCER Indicates that the span describes the initiators of an asynchronous request. This parent span will often end before the corresponding child CONSUMER span, possibly even before the child span starts. In messaging scenarios with batching, tracing individual messages requires a new PRODUCER span per message to be created.
  • CONSUMER Indicates that the span describes a child of an asynchronous PRODUCER request.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this should probably be a server span, but the code that adds the workunit to the execution queue should probably be a producer span. I have added a jira to introduce the new concept and we can revisit existing spans when that is available.

requestSpan->setSpanAttribute("hpcc.wuid", workunit->queryWuid());
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It feels like some of the most common attributes should be defined in JTrace

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is something I'm still not sure about. I can see the argument for having common strings - it catches typing mistakes, but I also find the code harder to read.

I suspect I could be persuaded for strings like this that are likely to be scattered through the code.

requestSpan->setSpanAttribute("hpcc.graph", graphName);
ContextSpanScope spanScope(*logctx, requestSpan);

resumed = WUActionResume == workunit->getAction();
Expand Down
4 changes: 3 additions & 1 deletion thorlcr/graph/thgraphslave.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
Loading