From 5fd4640bdd5b575b9dac721de458957ab07dce3d Mon Sep 17 00:00:00 2001 From: James McMullan Date: Thu, 5 Dec 2024 12:07:54 -0500 Subject: [PATCH] HPCC-32982 JTrace Add alterntative span socpes & OwnedSpanScope refactoring - Added ActiveSpanScope to track only current active span - Renamed existing OwnedSpanScope to OwnedActiveSpanScope - Added OwnedSpanScope to control only span lifetime Signed-off-by: James McMullan James.McMullan@lexisnexis.com --- common/thorhelper/thorsoapcall.cpp | 2 +- ecl/eclagent/eclagent.cpp | 2 +- esp/platform/espcontext.cpp | 2 +- esp/services/esdl_svc_engine/esdl_binding.cpp | 2 +- esp/services/ws_ecl/ws_ecl_service.cpp | 2 +- .../ws_workunits/ws_workunitsHelpers.cpp | 2 +- plugins/fileservices/fileservices.cpp | 20 ++--- roxie/ccd/ccdcontext.cpp | 2 +- roxie/ccd/ccdlistener.cpp | 4 +- system/jlib/jtrace.cpp | 57 +++++++++++++- system/jlib/jtrace.hpp | 56 +++++++++++++- testing/unittests/jlibtests.cpp | 76 +++++++++---------- thorlcr/graph/thgraphmaster.cpp | 2 +- thorlcr/graph/thgraphslave.cpp | 2 +- 14 files changed, 167 insertions(+), 64 deletions(-) diff --git a/common/thorhelper/thorsoapcall.cpp b/common/thorhelper/thorsoapcall.cpp index 1970b44e6a0..5351b86c944 100644 --- a/common/thorhelper/thorsoapcall.cpp +++ b/common/thorhelper/thorsoapcall.cpp @@ -2629,7 +2629,7 @@ class CWSCAsyncFor : implements IWSCAsyncFor, public CInterface, public CAsyncFo StringBuffer spanName; spanName.appendf("%s %s %s:%d", getWsCallTypeName(master->wscType), master->service.str(), url.host.str(), url.port); - OwnedSpanScope requestSpan = master->activitySpanScope->createClientSpan(spanName.str()); + OwnedActiveSpanScope requestSpan = master->activitySpanScope->createClientSpan(spanName.str()); setSpanURLAttributes(requestSpan, url); requestSpan->setSpanAttribute("request.type", getWsCallTypeName(master->wscType)); diff --git a/ecl/eclagent/eclagent.cpp b/ecl/eclagent/eclagent.cpp index 0af88caa6e2..4ae12b3f416 100644 --- a/ecl/eclagent/eclagent.cpp +++ b/ecl/eclagent/eclagent.cpp @@ -2156,7 +2156,7 @@ void EclAgent::runProcess(IEclProcess *process) allocatorMetaCache.setown(createRowAllocatorCache(this)); Owned traceHeaders = extractTraceDebugOptions(queryWorkUnit()); - OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); + OwnedActiveSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); ContextSpanScope spanScope(updateDummyContextLogger(), requestSpan); requestSpan->setSpanAttribute("hpcc.wuid", queryWorkUnit()->queryWuid()); diff --git a/esp/platform/espcontext.cpp b/esp/platform/espcontext.cpp index ea2c90f2d23..398329f3f80 100755 --- a/esp/platform/espcontext.cpp +++ b/esp/platform/espcontext.cpp @@ -89,7 +89,7 @@ class CEspContext : public CInterface, implements IEspContext Owned m_secureContext; StringAttr m_transactionID; - OwnedSpanScope m_requestSpan; // When the context is destroy the span will end. + OwnedActiveSpanScope m_requestSpan; // When the context is destroy the span will end. IHttpMessage* m_request; public: diff --git a/esp/services/esdl_svc_engine/esdl_binding.cpp b/esp/services/esdl_svc_engine/esdl_binding.cpp index 54783bfafb4..d2110932726 100755 --- a/esp/services/esdl_svc_engine/esdl_binding.cpp +++ b/esp/services/esdl_svc_engine/esdl_binding.cpp @@ -1572,7 +1572,7 @@ void EsdlServiceImpl::sendTargetSOAP(IEspContext & context, } ISpan * activeSpan = context.queryActiveSpan(); - OwnedSpanScope clientSpan(activeSpan->createClientSpan("soapcall")); + OwnedActiveSpanScope clientSpan(activeSpan->createClientSpan("soapcall")); Owned headers = ::getClientHeaders(clientSpan); StringBuffer status; diff --git a/esp/services/ws_ecl/ws_ecl_service.cpp b/esp/services/ws_ecl/ws_ecl_service.cpp index 0c330e61cc8..581da49e666 100644 --- a/esp/services/ws_ecl/ws_ecl_service.cpp +++ b/esp/services/ws_ecl/ws_ecl_service.cpp @@ -2069,7 +2069,7 @@ int CWsEclBinding::submitWsEclWorkunit(IEspContext & context, WsEclWuInfo &wsinf bool noTimeout = false; ISpan * activeSpan = context.queryActiveSpan(); - OwnedSpanScope clientSpan(activeSpan->createClientSpan("run_workunit")); + OwnedActiveSpanScope clientSpan(activeSpan->createClientSpan("run_workunit")); Owned httpHeaders = ::getClientHeaders(clientSpan); recordTraceDebugOptions(workunit, httpHeaders); diff --git a/esp/services/ws_workunits/ws_workunitsHelpers.cpp b/esp/services/ws_workunits/ws_workunitsHelpers.cpp index 6532f42acdc..2389e899d96 100644 --- a/esp/services/ws_workunits/ws_workunitsHelpers.cpp +++ b/esp/services/ws_workunits/ws_workunitsHelpers.cpp @@ -3793,7 +3793,7 @@ void WsWuHelpers::submitWsWorkunit(IEspContext& context, IConstWorkUnit* cw, con } ISpan * activeSpan = context.queryActiveSpan(); - OwnedSpanScope clientSpan(activeSpan->createClientSpan("run_workunit")); + OwnedActiveSpanScope clientSpan(activeSpan->createClientSpan("run_workunit")); Owned httpHeaders = ::getClientHeaders(clientSpan); recordTraceDebugOptions(wu, httpHeaders); diff --git a/plugins/fileservices/fileservices.cpp b/plugins/fileservices/fileservices.cpp index b69ef6470b8..bdf896334b2 100644 --- a/plugins/fileservices/fileservices.cpp +++ b/plugins/fileservices/fileservices.cpp @@ -779,7 +779,7 @@ FILESERVICES_API char * FILESERVICES_CALL implementSprayFixed(ICodeContext *ctx, req->setNoCommon(noCommon); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Fixed"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Fixed"); clientSpan->setSpanAttribute("destinationFilename", logicalName); try { @@ -925,7 +925,7 @@ static char * implementSprayVariable(ICodeContext *ctx, const char * sourceIP, c req->setNosplit(true); req->setNoCommon(noCommon); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Variable"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Variable"); clientSpan->setSpanAttribute("destinationFilename", logicalName); try { @@ -1110,7 +1110,7 @@ FILESERVICES_API char * FILESERVICES_CALL implementSprayXml(ICodeContext *ctx, c req->setNoCommon(noCommon); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Xml"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Xml"); clientSpan->setSpanAttribute("destinationFilename", logicalName); try { @@ -1266,7 +1266,7 @@ FILESERVICES_API char * FILESERVICES_CALL implementSprayJson(ICodeContext *ctx, req->setSrcPassword(userPw); } - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Json"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Json"); clientSpan->setSpanAttribute("destinationFilename", logicalName); try { @@ -1358,7 +1358,7 @@ static char * implementDespray(ICodeContext *ctx, const char * sourceLogicalName if (maxConnections != -1) req->setMaxConnections(maxConnections); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Despray"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Despray"); clientSpan->setSpanAttribute("sourceFilename", logicalName); try { @@ -1457,7 +1457,7 @@ FILESERVICES_API char * FILESERVICES_CALL implementCopy(ICodeContext *ctx, const req->setWrap(true); req->setExpireDays(expireDays); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Copy"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Copy"); clientSpan->setSpanAttribute("sourceFilename", sourceLogicalName); clientSpan->setSpanAttribute("destinationFilename", destinationLogicalName); try @@ -1565,7 +1565,7 @@ FILESERVICES_API char * FILESERVICES_CALL fsfReplicate(ICodeContext *ctx, const req->setSourceLogicalName(logicalName.str()); - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Fixed"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Spray Fixed"); clientSpan->setSpanAttribute("destinationFilename", logicalName); try { @@ -2126,7 +2126,7 @@ FILESERVICES_API char * FILESERVICES_CALL fsfMonitorLogicalFileName(ICodeContex if (shotcount == 0) shotcount = -1; - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Monitor Logical Filename"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Monitor Logical Filename"); clientSpan->setSpanAttribute("filename", lfn); try { @@ -2167,7 +2167,7 @@ FILESERVICES_API char * FILESERVICES_CALL fsfMonitorFile(ICodeContext *ctx, con if (shotcount == 0) shotcount = -1; - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Monitor File"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Monitor File"); clientSpan->setSpanAttribute("filename", filename); try { @@ -2503,7 +2503,7 @@ FILESERVICES_API char * FILESERVICES_CALL fsfRemotePull_impl(ICodeContext *ctx, req->setSrcpassword(userPw); } - OwnedSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Remote Pull"); + OwnedActiveSpanScope clientSpan = queryThreadedActiveSpan()->createClientSpan("Dfu Remote Pull"); clientSpan->setSpanAttribute("sourceFilename", sourceLogicalName); clientSpan->setSpanAttribute("destinationFilename", destinationLogicalName); try diff --git a/roxie/ccd/ccdcontext.cpp b/roxie/ccd/ccdcontext.cpp index e064a6552cb..2d84c5b7d6b 100644 --- a/roxie/ccd/ccdcontext.cpp +++ b/roxie/ccd/ccdcontext.cpp @@ -1658,7 +1658,7 @@ class CRoxieContextBase : implements IRoxieAgentContext, implements ICodeContext } else { - OwnedSpanScope graphScope = queryThreadedActiveSpan()->createInternalSpan(name); + OwnedActiveSpanScope graphScope = queryThreadedActiveSpan()->createInternalSpan(name); ProcessInfo startProcessInfo; if (workUnit || statsWu) startProcessInfo.update(ReadAllInfo); diff --git a/roxie/ccd/ccdlistener.cpp b/roxie/ccd/ccdlistener.cpp index 19c4bc81b91..4b19ab3afb2 100644 --- a/roxie/ccd/ccdlistener.cpp +++ b/roxie/ccd/ccdlistener.cpp @@ -1283,7 +1283,7 @@ class RoxieWorkUnitWorker : public RoxieQueryWorker Owned logctx = new StringContextLogger(wuid.get()); Owned traceHeaders = extractTraceDebugOptions(wu); - OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); + OwnedActiveSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); requestSpan->setSpanAttribute("hpcc.wuid", wuid); ContextSpanScope spanScope(*logctx, requestSpan); @@ -1464,7 +1464,7 @@ class RoxieProtocolMsgContext : implements IHpccProtocolMsgContext, public CInte Owned debugCmdHandler; Owned logctx; Owned queryFactory; - OwnedSpanScope requestSpan; + OwnedActiveSpanScope requestSpan; SocketEndpoint ep; time_t startTime; diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index fdfb4058647..f7ae2941b2e 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -1504,13 +1504,36 @@ ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * h //--------------------------------------------------------------------------------------------------------------------- -OwnedSpanScope::OwnedSpanScope(ISpan * _ptr) : span(_ptr) +ActiveSpanScope::ActiveSpanScope(ISpan * _ptr) : ActiveSpanScope(_ptr, queryThreadedActiveSpan()) {} +ActiveSpanScope::ActiveSpanScope(ISpan * _ptr, ISpan * _prev) : span(_ptr), prevSpan(_prev) +{ + setThreadedActiveSpan(_ptr); +} + +ActiveSpanScope::~ActiveSpanScope() +{ + ISpan* current = queryThreadedActiveSpan(); + if (current != span) + { + const char* currSpanID = current != nullptr ? current->querySpanId() : "null"; + const char* expectedSpanID = span != nullptr ? span->querySpanId() : "null"; + + IERRLOG("~ActiveSpanScope: threadActiveSpan has changed unexpectedly, expected: %s actual: %s", expectedSpanID, currSpanID); + return; + } + + setThreadedActiveSpan(prevSpan); +} + +//--------------------------------------------------------------------------------------------------------------------- + +OwnedActiveSpanScope::OwnedActiveSpanScope(ISpan * _ptr) : span(_ptr) { if (_ptr) prevSpan = setThreadedActiveSpan(_ptr); } -void OwnedSpanScope::setown(ISpan * _span) +void OwnedActiveSpanScope::setown(ISpan * _span) { assertex(_span); //Just in case the span is already set, ensure it is ended and that the previous span is restored. @@ -1519,6 +1542,35 @@ void OwnedSpanScope::setown(ISpan * _span) prevSpan = setThreadedActiveSpan(_span); } +void OwnedActiveSpanScope::set(ISpan * _span) +{ + setown(LINK(_span)); +} + +void OwnedActiveSpanScope::clear() +{ + if (span) + { + span->endSpan(); + setThreadedActiveSpan(prevSpan); + span.clear(); + } +} + +OwnedActiveSpanScope::~OwnedActiveSpanScope() +{ + clear(); +} + +//--------------------------------------------------------------------------------------------------------------------- + +void OwnedSpanScope::setown(ISpan * _span) +{ + assertex(_span); + clear(); + span.setown(_span); +} + void OwnedSpanScope::set(ISpan * _span) { setown(LINK(_span)); @@ -1529,7 +1581,6 @@ void OwnedSpanScope::clear() if (span) { span->endSpan(); - setThreadedActiveSpan(prevSpan); span.clear(); } } diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index 7f1e7d9431b..af8e26e5e52 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -159,11 +159,64 @@ interface ISpan : extends IInterface virtual const char* queryLocalId() const = 0; }; +//------------------------------------------------------------------------------ +// ActiveSpanScope vs OwnedActiveSpanScope Usage: +//------------------------------------------------------------------------------ +// The primary difference between OwnedActiveSpanScope and ActiveSpanScope is that +// OwnedActiveSpanScope controls the lifetime of its ISpan while ActiveSpanScope +// does not. In cases where the ISpan will be used from a single thread and within +// a single scope OwnedActiveSpanScope should be used. For more complicated scenarios, +// involving multiple threads, time sliced work, etc ActiveSpanScope should be used. +//------------------------------------------------------------------------------ + +class ActiveSpanScope +{ +public: + // Captures current threadActiveSpan for prevSpan + ActiveSpanScope(ISpan * _ptr); + ActiveSpanScope(ISpan * _ptr, ISpan * _prev); + + ActiveSpanScope(const ActiveSpanScope& rhs) = delete; + ~ActiveSpanScope(); + + inline ISpan * operator -> () const { return span; } + inline operator ISpan *() const { return span; } + + inline ActiveSpanScope& operator=(ISpan * ptr) = delete; + inline ActiveSpanScope& operator=(const ActiveSpanScope& rhs) = delete; + + inline bool operator == (ISpan * _ptr) const { return span == _ptr; } + inline bool operator != (ISpan * _ptr) const { return span != _ptr; } +private: + ISpan * span = nullptr; + ISpan * prevSpan = nullptr; +}; + +class jlib_decl OwnedActiveSpanScope +{ +public: + OwnedActiveSpanScope() = default; + OwnedActiveSpanScope(ISpan * _ptr); + ~OwnedActiveSpanScope(); + + inline ISpan * operator -> () const { return span; } + inline operator ISpan *() const { return span; } + + void clear(); + ISpan * query() const { return span; } + void set(ISpan * _span); + void setown(ISpan * _span); + +private: + Owned span; + ISpan * prevSpan = nullptr; +}; + class jlib_decl OwnedSpanScope { public: OwnedSpanScope() = default; - OwnedSpanScope(ISpan * _ptr); + OwnedSpanScope(ISpan * _ptr) : span(_ptr) {} ~OwnedSpanScope(); inline ISpan * operator -> () const { return span; } @@ -176,7 +229,6 @@ class jlib_decl OwnedSpanScope private: Owned span; - ISpan * prevSpan = nullptr; }; extern jlib_decl IProperties * getClientHeaders(const ISpan * span); diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index 195a34c3705..7e324c5c8aa 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -198,7 +198,7 @@ class JlibTraceTest : public CppUnit::TestFixture { Owned emptyMockHTTPHeaders = createProperties(); { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("spanWithEventsNoAtts", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("spanWithEventsNoAtts", emptyMockHTTPHeaders); Owned emptyEventAtts = createProperties(); serverSpan->addSpanEvent("event1", emptyEventAtts); } @@ -208,12 +208,12 @@ class JlibTraceTest : public CppUnit::TestFixture twoEventAtt->setProp("key2", ""); { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("spanWithEvent1Att", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("spanWithEvent1Att", emptyMockHTTPHeaders); serverSpan->addSpanEvent("event2", twoEventAtt); }//{ "type": "span", "name": "spanWithEvents1Att", "trace_id": "3b9f55aaf8fab51fb0d73a32db7d704f", "span_id": "2a25a44ae0b3abe0", "start": 1709696036335278770, "duration": 3363911469, "events":[ { "name": "event2", "time_stamp": 1709696038413023245, "attributes": {"key": "value" } } ] } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("spanWith2Events", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("spanWith2Events", emptyMockHTTPHeaders); serverSpan->addSpanEvent("event1", twoEventAtt); serverSpan->addSpanEvent("event2", twoEventAtt); }//{ "type": "span", "name": "spanWith2Events", "trace_id": "ff5c5919b9c5f85913652b77f289bf0b", "span_id": "82f91ca1f9d469c1", "start": 1709698012480805016, "duration": 2811601377, "events":[ { "name": "event1", "time_stamp": 1709698013294323139, "attributes": {"key": "value" } },{ "name": "event2", "time_stamp": 1709698014500350802, "attributes": {"key": "value" } } ] } @@ -228,14 +228,14 @@ class JlibTraceTest : public CppUnit::TestFixture { //duration should be at least 125 milliseconds - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("declaredSpanStartTime", emptyMockHTTPHeaders, &declaredSpanStartTime); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("declaredSpanStartTime", emptyMockHTTPHeaders, &declaredSpanStartTime); //{ "type": "span", "name": "declaredSpanStartTime", "trace_id": "0a2eff24e1996540056745aaeb2f5824", "span_id": "46d0faf8b4da893e", //"start": 1702672311203213259, "duration": 125311051 } SpanTimeStamp clientSpanTimeStamp; clientSpanTimeStamp.now(); MilliSleep(20); - OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpanStartTime", &clientSpanTimeStamp); + OwnedActiveSpanScope clientSpan = serverSpan->createClientSpan("clientSpanStartTime", &clientSpanTimeStamp); //{ "type": "span", "name": "clientSpanStartTime", "trace_id": "f73b171fdcd120f88ca5b656866befee", "span_id": "7c798125d10ee0ec", //"start": 1727200325699918374, "duration": 20256156, "parent_span_id": "b79fe15b7d727fca" } } @@ -253,13 +253,13 @@ class JlibTraceTest : public CppUnit::TestFixture SpanTimeStamp nowTimeStamp; //not used, printed out as "start" time for manual comparison nowTimeStamp.now(); { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); unsigned clientStartMS = msTick(); MilliSleep(20); SpanTimeStamp clientSpanTimeStamp; clientSpanTimeStamp.setMSTickTime(clientStartMS); - OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpanOffsetTime", &clientSpanTimeStamp); + OwnedActiveSpanScope clientSpan = serverSpan->createClientSpan("clientSpanOffsetTime", &clientSpanTimeStamp); //{ "type": "span", "name": "clientSpanOffsetTime", "trace_id": "9a41723ddc0048d854ab34b79340e749", "span_id": "11af70aa6a6dbee3", //"start": 1727200325770619773, "duration": 20015542, "parent_span_id": "531ad336071f453b" } } @@ -277,7 +277,7 @@ class JlibTraceTest : public CppUnit::TestFixture CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected initialized spanTimeStamp", true, uninitializedTS.systemClockTime == std::chrono::nanoseconds::zero()); CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected initialized spanTimeStamp", true, uninitializedTS.steadyClockTime == std::chrono::nanoseconds::zero()); { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("uninitializeddeclaredSpanStartTime", emptyMockHTTPHeaders, &uninitializedTS); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("uninitializeddeclaredSpanStartTime", emptyMockHTTPHeaders, &uninitializedTS); //sleep for 75 milliseconds after span creation, expect at least 75 milliseconds duration output MilliSleep(75); @@ -292,43 +292,43 @@ class JlibTraceTest : public CppUnit::TestFixture { Owned emptyMockHTTPHeaders = createProperties(); { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("defaultErrorSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("defaultErrorSpan", emptyMockHTTPHeaders); serverSpan->recordError(); }//{ "type": "span", "name": "defaultErrorSpan", "trace_id": "209b5d8cea0aec9785d2dfa3117e37ad", "span_id": "ab72e76c2f2466c2", "start": 1709675278129335702, "duration": 188292867932, "status": "Error", "kind": "Server", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675465508149013, "attributes": {"escaped": 0 } } ] } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("defaultErrorSpanStruct", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("defaultErrorSpanStruct", emptyMockHTTPHeaders); SpanError error; serverSpan->recordError(error); }//{ "type": "span", "name": "defaultErrorSpanStruct", "trace_id": "19803a446b971f2e0bdddc9c00db50fe", "span_id": "04c93a91ab8785a2", "start": 1709675487767044352, "duration": 2287497219, "status": "Error", "kind": "Server", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675489216412154, "attributes": {"escaped": 0 } } ] } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("failedErrorSpanEscaped", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("failedErrorSpanEscaped", emptyMockHTTPHeaders); serverSpan->recordError(SpanError("hello", -1, true, true)); //error message hello, no error code, error caused failure, and error caused escape }//{ "type": "span", "name": "failedErrorSpanEscaped", "trace_id": "634f386c18a6140544c980e0d5a15905", "span_id": "e2f59c48f63a8f82", "start": 1709675508231168974, "duration": 7731717678, "status": "Error", "kind": "Server", "description": "hello", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675512164430668, "attributes": {"escaped": 1,"message": "hello" } } ] } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("failedErrEscapedMsgErrCode", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("failedErrEscapedMsgErrCode", emptyMockHTTPHeaders); serverSpan->recordError(SpanError("hello", 34, true, true)); //error message hello, error code 34, error caused failure, and error caused escape }//failedErrEscapedMsgErrCode { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("containsErrorAndMessageSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("containsErrorAndMessageSpan", emptyMockHTTPHeaders); serverSpan->recordError(SpanError("Error Message!!")); }//{ "type": "span", "name": "containsErrorAndMessageSpan", "trace_id": "9a6e00ea309bc0427733f9b2d452f9e2", "span_id": "de63e9c69b64e411", "start": 1709675552302360510, "duration": 5233037523, "status": "Error", "kind": "Server", "description": "Error Message!!", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675555149852711, "attributes": {"escaped": 0,"message": "Error Message!!" } } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("containsErrorAndMessageFailedNotEscapedSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("containsErrorAndMessageFailedNotEscapedSpan", emptyMockHTTPHeaders); serverSpan->recordError(SpanError("Error Message!!", 23, true, false)); }//{ "type": "span", "name": "containsErrorAndMessageFailedNotEscapedSpan", "trace_id": "02f4b2d215f8230b15063862f8a91e41", "span_id": "c665ec371d6db147", "start": 1709675573581678954, "duration": 3467489486, "status": "Error", "kind": "Server", "description": "Error Message!!", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675576145074240, "attributes": {"code": 23,"escaped": 0,"message": "Error Message!!" } } ] } { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("mockExceptionSpanNotFailedNotEscaped", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("mockExceptionSpanNotFailedNotEscaped", emptyMockHTTPHeaders); serverSpan->recordException( makeStringExceptionV(76,"Mock exception"), false, false); }//{ "type": "span", "name": "mockExceptionSpanNotFailedNotEscaped", "trace_id": "e01766474db05ce9085943fa3955cd73", "span_id": "7da620e96e10e42c", "start": 1709675595987480704, "duration": 2609091267, "status": "Unset", "kind": "Server", "instrumented_library": "unittests", "events":[ { "name": "Exception", "time_stamp": 1709675597728975355, "attributes": {"code": 76,"escaped": 0,"message": "Mock exception" } } ] { - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("thrownExceptionSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("thrownExceptionSpan", emptyMockHTTPHeaders); try { throw makeStringExceptionV( 356, "Mock thrown exception"); @@ -347,7 +347,7 @@ class JlibTraceTest : public CppUnit::TestFixture { SpanFlags flags = SpanFlags::EnsureTraceId; Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("mySpan", emptyMockHTTPHeaders, flags); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("mySpan", emptyMockHTTPHeaders, flags); DBGLOG("mySpan is alive"); savedSpan.set(serverSpan); }//{ "type": "span", "name": "mySpan", "trace_id": "fe266416e7d588113a5131394d913ab4", "span_id": "7ac62328b04442c5", "start": 1709824793826023368, "duration": 16952 } @@ -376,7 +376,7 @@ class JlibTraceTest : public CppUnit::TestFixture { SpanFlags flags = SpanFlags::EnsureTraceId; Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes.get()); @@ -389,7 +389,7 @@ class JlibTraceTest : public CppUnit::TestFixture { SpanFlags flags = SpanFlags::EnsureTraceId; Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes.get()); @@ -409,7 +409,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //traceID, spanID, remoteParentSpanID, traceFlags, traceState, globalID, callerID @@ -461,7 +461,7 @@ class JlibTraceTest : public CppUnit::TestFixture return; } - OwnedSpanScope nullSpan = getNullSpan(); + OwnedActiveSpanScope nullSpan = getNullSpan(); CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected nullptr nullspan detected", true, nullSpan != nullptr); { @@ -469,14 +469,14 @@ class JlibTraceTest : public CppUnit::TestFixture nullSpan->getClientHeaders(headers); } - OwnedSpanScope nullSpanChild = nullSpan->createClientSpan("nullSpanChild"); + OwnedActiveSpanScope nullSpanChild = nullSpan->createClientSpan("nullSpanChild"); CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected nullptr nullSpanChild detected", true, nullSpanChild != nullptr); } void testClientSpan() { Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes); @@ -486,7 +486,7 @@ class JlibTraceTest : public CppUnit::TestFixture const char * serverTraceID = retrievedSpanCtxAttributes->queryProp("traceID"); { - OwnedSpanScope internalSpan = serverSpan->createClientSpan("clientSpan"); + OwnedActiveSpanScope internalSpan = serverSpan->createClientSpan("clientSpan"); //retrieve clientSpan context with the intent to propogate otel and HPCC context { Owned retrievedSpanCtxAttributes = createProperties(); @@ -520,7 +520,7 @@ class JlibTraceTest : public CppUnit::TestFixture void testInternalSpan() { Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes); @@ -531,7 +531,7 @@ class JlibTraceTest : public CppUnit::TestFixture const char * serverTraceID = retrievedSpanCtxAttributes->queryProp("traceID"); { - OwnedSpanScope internalSpan = serverSpan->createInternalSpan("internalSpan"); + OwnedActiveSpanScope internalSpan = serverSpan->createInternalSpan("internalSpan"); //retrieve internalSpan context with the intent to interrogate attributes { @@ -565,7 +565,7 @@ class JlibTraceTest : public CppUnit::TestFixture void testRootServerSpan() { Owned emptyMockHTTPHeaders = createProperties(); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); //retrieve serverSpan context with the intent to propagate it to a remote child span { @@ -639,7 +639,7 @@ class JlibTraceTest : public CppUnit::TestFixture { Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, false); - OwnedSpanScope currentSpanScope = queryTraceManager().createServerSpan("currentSpanScope", mockHTTPHeaders); + OwnedActiveSpanScope currentSpanScope = queryTraceManager().createServerSpan("currentSpanScope", mockHTTPHeaders); CPPUNIT_ASSERT_MESSAGE("currentSpanScope Span == nullptr!", currentSpanScope != nullptr); @@ -668,7 +668,7 @@ class JlibTraceTest : public CppUnit::TestFixture { Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, false); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("invalidPropegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("invalidPropegatedServerSpan", mockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getClientHeaders(retrievedSpanCtxAttributes.get()); @@ -689,7 +689,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //remoteParentSpanID, globalID, callerID @@ -710,10 +710,10 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); - OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpan"); - OwnedSpanScope internalSpan = clientSpan->createInternalSpan("internalSpan"); - OwnedSpanScope internalSpan2 = internalSpan->createInternalSpan("internalSpan2"); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope clientSpan = serverSpan->createClientSpan("clientSpan"); + OwnedActiveSpanScope internalSpan = clientSpan->createInternalSpan("internalSpan"); + OwnedActiveSpanScope internalSpan2 = internalSpan->createInternalSpan("internalSpan2"); StringBuffer out; out.set("{"); @@ -748,8 +748,8 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); //includes global ID - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); - OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpanWithGlobalID"); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope clientSpan = serverSpan->createClientSpan("clientSpanWithGlobalID"); //retrieve serverSpan context with the intent to interrogate attributes { @@ -771,7 +771,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //traceID, spanID, remoteParentSpanID, traceFlags, traceState, globalID, callerID @@ -817,7 +817,7 @@ class JlibTraceTest : public CppUnit::TestFixture mockHTTPHeadersSA.append("HPCC-Global-Id:someGlobalID"); mockHTTPHeadersSA.append("HPCC-Caller-Id:IncomingCID"); - OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("StringArrayPropegatedServerSpan", mockHTTPHeadersSA); + OwnedActiveSpanScope serverSpan = queryTraceManager().createServerSpan("StringArrayPropegatedServerSpan", mockHTTPHeadersSA); //at this point the serverSpan should have the following context attributes //traceID, spanID, remoteParentSpanID, traceFlags, traceState, globalID, callerID diff --git a/thorlcr/graph/thgraphmaster.cpp b/thorlcr/graph/thgraphmaster.cpp index b06a345fb1c..25c3f5ff8f7 100644 --- a/thorlcr/graph/thgraphmaster.cpp +++ b/thorlcr/graph/thgraphmaster.cpp @@ -1503,7 +1503,7 @@ CJobMaster::CJobMaster(IConstWorkUnit &_workunit, const char *graphName, ILoaded init(); Owned traceHeaders = extractTraceDebugOptions(workunit); - OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + OwnedActiveSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); ContextSpanScope spanScope(*logctx, requestSpan); requestSpan->setSpanAttribute("hpcc.wuid", workunit->queryWuid()); requestSpan->setSpanAttribute("hpcc.graph", graphName); diff --git a/thorlcr/graph/thgraphslave.cpp b/thorlcr/graph/thgraphslave.cpp index e39c45909d5..35e3ad0f96d 100644 --- a/thorlcr/graph/thgraphslave.cpp +++ b/thorlcr/graph/thgraphslave.cpp @@ -1726,7 +1726,7 @@ CJobSlave::CJobSlave(ISlaveWatchdog *_watchdog, IPropertyTree *_workUnitInfo, co init(); Owned traceHeaders = deserializeTraceDebugOptions(workUnitInfo->queryPropTree("Debug")); - OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + OwnedActiveSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); ContextSpanScope spanScope(*logctx, requestSpan); requestSpan->setSpanAttribute("hpcc.wuid", wuid); requestSpan->setSpanAttribute("hpcc.graph", graphName);