diff --git a/ecl/eclagent/eclagent.cpp b/ecl/eclagent/eclagent.cpp index d14babf3a0b..1284dcc8b20 100644 --- a/ecl/eclagent/eclagent.cpp +++ b/ecl/eclagent/eclagent.cpp @@ -2128,9 +2128,9 @@ void EclAgent::runProcess(IEclProcess *process) allocatorMetaCache.setown(createRowAllocatorCache(this)); Owned traceHeaders = extractTraceDebugOptions(queryWorkUnit()); - Owned requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); - requestSpan->setSpanAttribute("hpcc.wuid", queryWorkUnit()->queryWuid()); + OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); ContextSpanScope spanScope(updateDummyContextLogger(), requestSpan); + requestSpan->setSpanAttribute("hpcc.wuid", queryWorkUnit()->queryWuid()); // a component may specify an alternate name for the agent/workflow memory area, // e.g. Thor specifies in "eclAgentMemory" diff --git a/esp/bindings/http/platform/httpservice.cpp b/esp/bindings/http/platform/httpservice.cpp index 748155df69e..c5d82667d21 100644 --- a/esp/bindings/http/platform/httpservice.cpp +++ b/esp/bindings/http/platform/httpservice.cpp @@ -412,13 +412,10 @@ int CEspHttpServer::processRequest() return 0; } - //The context will be destroyed when this request is destroyed. So rather than using - //EspContextSpanScope spanContext(*ctx, serverSpan); - //which would remove the activeSpan when this function exits, use - //setActiveSpan() - //It is possible that using EspContextSpanScope would be better + //The context will be destroyed when this request is destroyed. So initialise a SpanScope in the context to + //ensure the span is also terminated at the same time. Owned serverSpan = m_request->createServerSpan(serviceName, methodName); - ctx->setActiveSpan(serverSpan); + ctx->setRequestSpan(serverSpan); if (thebinding!=NULL) { diff --git a/esp/platform/esp.hpp b/esp/platform/esp.hpp index 75dd142b14b..65c3008f412 100644 --- a/esp/platform/esp.hpp +++ b/esp/platform/esp.hpp @@ -235,15 +235,13 @@ interface IEspContext : extends IInterface virtual void setRequest(IHttpMessage* req) = 0; virtual IHttpMessage* queryRequest() = 0; - virtual void setActiveSpan(ISpan * span)=0; // Only call this function directly if this object's lifetime matches the lifetime of the span. If there is any doubt use EspContextSpanScope(ctx, span) + virtual void setRequestSpan(ISpan * span)=0; // Call this function to set the server span for the query. The spans's lifetime will match the lifetime of the context object. virtual ISpan * queryActiveSpan() const = 0; virtual IProperties * getClientSpanHeaders() const = 0; virtual const char* getGlobalId() const = 0; virtual const char* getCallerId() const = 0; virtual const char* getLocalId() const = 0; }; -//Class for managing the active span in the context -using EspContextSpanScope = ContextSpanScopeImp; typedef unsigned LogLevel; diff --git a/esp/platform/espcontext.cpp b/esp/platform/espcontext.cpp index a2bca7b701f..3270273fe5b 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; - Owned m_activeSpan; + OwnedSpanScope m_requestSpan; // When the context is destroy the span will end. IHttpMessage* m_request; public: @@ -114,7 +114,7 @@ class CEspContext : public CInterface, implements IEspContext updateTraceSummaryHeader(); m_secureContext.setown(secureContext); m_SecurityHandler.setSecureContext(secureContext); - m_activeSpan.set(getNullSpan()); + m_requestSpan.setown(getNullSpan()); } ~CEspContext() @@ -626,30 +626,30 @@ class CEspContext : public CInterface, implements IEspContext { return m_request; } - virtual void setActiveSpan(ISpan * span) override + virtual void setRequestSpan(ISpan * span) override { - m_activeSpan.set(span); + m_requestSpan.set(span); } virtual ISpan * queryActiveSpan() const override { - return m_activeSpan; + return m_requestSpan; } virtual const char* getGlobalId() const override { - return m_activeSpan->queryGlobalId(); + return m_requestSpan->queryGlobalId(); } virtual const char* getCallerId() const override { - return m_activeSpan->queryCallerId(); + return m_requestSpan->queryCallerId(); } virtual const char* getLocalId() const override { - return m_activeSpan->queryLocalId(); + return m_requestSpan->queryLocalId(); } virtual IProperties * getClientSpanHeaders() const override { - return ::getClientHeaders(m_activeSpan); + return ::getClientHeaders(m_requestSpan); } }; diff --git a/esp/services/esdl_svc_engine/esdl_binding.cpp b/esp/services/esdl_svc_engine/esdl_binding.cpp index 5c63e363737..54783bfafb4 100755 --- a/esp/services/esdl_svc_engine/esdl_binding.cpp +++ b/esp/services/esdl_svc_engine/esdl_binding.cpp @@ -1571,9 +1571,8 @@ void EsdlServiceImpl::sendTargetSOAP(IEspContext & context, httpclient->setPassword(password.str()); } - Owned clientSpan; ISpan * activeSpan = context.queryActiveSpan(); - clientSpan.setown(activeSpan->createClientSpan("soapcall")); + OwnedSpanScope 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 c8dd8b64a26..9a2db171a3d 100644 --- a/esp/services/ws_ecl/ws_ecl_service.cpp +++ b/esp/services/ws_ecl/ws_ecl_service.cpp @@ -1978,9 +1978,8 @@ int CWsEclBinding::submitWsEclWorkunit(IEspContext & context, WsEclWuInfo &wsinf bool noTimeout = false; - Owned clientSpan; ISpan * activeSpan = context.queryActiveSpan(); - clientSpan.setown(activeSpan->createClientSpan("run_workunit")); + OwnedSpanScope 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 bb6fd445832..8598752f888 100644 --- a/esp/services/ws_workunits/ws_workunitsHelpers.cpp +++ b/esp/services/ws_workunits/ws_workunitsHelpers.cpp @@ -3779,7 +3779,7 @@ void WsWuHelpers::submitWsWorkunit(IEspContext& context, IConstWorkUnit* cw, con } ISpan * activeSpan = context.queryActiveSpan(); - Owned clientSpan(activeSpan->createClientSpan("run_workunit")); + OwnedSpanScope clientSpan(activeSpan->createClientSpan("run_workunit")); Owned httpHeaders = ::getClientHeaders(clientSpan); recordTraceDebugOptions(wu, httpHeaders); diff --git a/roxie/ccd/ccdlistener.cpp b/roxie/ccd/ccdlistener.cpp index 7badb16cc46..6427dfc6991 100644 --- a/roxie/ccd/ccdlistener.cpp +++ b/roxie/ccd/ccdlistener.cpp @@ -1200,7 +1200,7 @@ class RoxieWorkUnitWorker : public RoxieQueryWorker Owned logctx = new StringContextLogger(wuid.get()); Owned traceHeaders = extractTraceDebugOptions(wu); - Owned requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); + OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_workunit", traceHeaders); requestSpan->setSpanAttribute("hpcc.wuid", wuid); ContextSpanScope spanScope(*logctx, requestSpan); @@ -1381,6 +1381,7 @@ class RoxieProtocolMsgContext : implements IHpccProtocolMsgContext, public CInte Owned debugCmdHandler; Owned logctx; Owned queryFactory; + OwnedSpanScope requestSpan; SocketEndpoint ep; time_t startTime; @@ -1484,8 +1485,7 @@ class RoxieProtocolMsgContext : implements IHpccProtocolMsgContext, public CInte if (spanName.length()) spanName.append('/'); spanName.append(spanQueryName); - Owned 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 + requestSpan.setown(queryTraceManager().createServerSpan(spanName, allHeaders, flags)); logctx->setActiveSpan(requestSpan); const char * globalId = requestSpan->queryGlobalId(); diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index bc213c6c197..7a379dfc1cb 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -536,8 +536,7 @@ class CSpan : public CInterfaceOf virtual void beforeDispose() override { //Record the span as complete before we output the logging for the end of the span - if (span != nullptr) - span->End(); + endSpan(); } const char * getSpanID() const @@ -548,6 +547,13 @@ class CSpan : public CInterfaceOf ISpan * createClientSpan(const char * name) override; ISpan * createInternalSpan(const char * name) override; + virtual void endSpan() final override + { + //It is legal to call endSpan multiple times, but only the first call will have any effect + if (span != nullptr) + span->End(); + } + virtual void toString(StringBuffer & out) const { toString(out, true); @@ -822,7 +828,7 @@ class CSpan : public CInterfaceOf }; -class CNullSpan : public CInterfaceOf +class CNullSpan final : public CInterfaceOf { public: CNullSpan() = default; @@ -832,6 +838,7 @@ class CNullSpan : public CInterfaceOf virtual void setSpanAttributes(const IProperties * attributes) override {} virtual void addSpanEvent(const char * eventName) override {} virtual void addSpanEvent(const char * eventName, IProperties * attributes) override {}; + virtual void endSpan() override {} virtual void getSpanContext(IProperties * ctxProps) const override {} virtual void getClientHeaders(IProperties * clientHeaders) const override {} diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index 94efd87e8bd..3afd169a150 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -62,6 +62,7 @@ interface ISpan : extends IInterface virtual void setSpanAttributes(const IProperties * attributes) = 0; virtual void addSpanEvent(const char * eventName) = 0; virtual void addSpanEvent(const char * eventName, IProperties * attributes) = 0; + virtual void endSpan() = 0; // Indicate that the span has ended even if it has not yet been destroyed virtual void getSpanContext(IProperties * ctxProps) const = 0; virtual void getClientHeaders(IProperties * clientHeaders) const = 0; virtual void toString(StringBuffer & out) const = 0; @@ -77,6 +78,18 @@ interface ISpan : extends IInterface virtual const char* queryLocalId() const = 0; }; +class OwnedSpanScope : public Owned +{ +public: + inline OwnedSpanScope() { } + inline OwnedSpanScope(ISpan * _ptr) : Owned(_ptr) { } + ~OwnedSpanScope() + { + if (get()) + get()->endSpan(); + } +}; + extern jlib_decl IProperties * getClientHeaders(const ISpan * span); extern jlib_decl IProperties * getSpanContext(const ISpan * span); diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index 6565ff83c54..d6406999973 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -199,7 +199,7 @@ class JlibTraceTest : public CppUnit::TestFixture { //duration should be at least 125 milliseconds - Owned serverSpan = queryTraceManager().createServerSpan("declaredSpanStartTime", emptyMockHTTPHeaders, &declaredSpanStartTime); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("declaredSpanStartTime", emptyMockHTTPHeaders, &declaredSpanStartTime); //{ "type": "span", "name": "declaredSpanStartTime", "trace_id": "0a2eff24e1996540056745aaeb2f5824", "span_id": "46d0faf8b4da893e", //"start": 1702672311203213259, "duration": 125311051 } } @@ -217,7 +217,7 @@ class JlibTraceTest : public CppUnit::TestFixture SpanTimeStamp nowTimeStamp; //not used, printed out as "start" time for manual comparison nowTimeStamp.now(); { - Owned serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); } DBGLOG("MsTickOffset span actual start-time timestamp: %lld", (long long)(nowTimeStamp.systemClockTime).count()); @@ -233,7 +233,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()); { - Owned serverSpan = queryTraceManager().createServerSpan("uninitializeddeclaredSpanStartTime", emptyMockHTTPHeaders, &uninitializedTS); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("uninitializeddeclaredSpanStartTime", emptyMockHTTPHeaders, &uninitializedTS); //sleep for 75 milliseconds after span creation, expect at least 75 milliseconds duration output MilliSleep(75); @@ -256,7 +256,7 @@ class JlibTraceTest : public CppUnit::TestFixture { SpanFlags flags = SpanFlags::EnsureTraceId; Owned emptyMockHTTPHeaders = createProperties(); - Owned serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("noRemoteParentEnsureTraceID", emptyMockHTTPHeaders, flags); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes.get()); @@ -270,7 +270,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //traceID, spanID, remoteParentSpanID, traceFlags, traceState, globalID, callerID @@ -322,7 +322,7 @@ class JlibTraceTest : public CppUnit::TestFixture return; } - Owned nullSpan = getNullSpan(); + OwnedSpanScope nullSpan = getNullSpan(); CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected nullptr nullspan detected", true, nullSpan != nullptr); { @@ -330,14 +330,14 @@ class JlibTraceTest : public CppUnit::TestFixture nullSpan->getClientHeaders(headers); } - Owned nullSpanChild = nullSpan->createClientSpan("nullSpanChild"); + OwnedSpanScope nullSpanChild = nullSpan->createClientSpan("nullSpanChild"); CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected nullptr nullSpanChild detected", true, nullSpanChild != nullptr); } void testClientSpan() { Owned emptyMockHTTPHeaders = createProperties(); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes); @@ -348,7 +348,7 @@ class JlibTraceTest : public CppUnit::TestFixture const char * serverTraceID = retrievedSpanCtxAttributes->queryProp("traceID"); { - Owned internalSpan = serverSpan->createClientSpan("clientSpan"); + OwnedSpanScope internalSpan = serverSpan->createClientSpan("clientSpan"); //retrieve clientSpan context with the intent to propogate otel and HPCC context { @@ -384,7 +384,7 @@ class JlibTraceTest : public CppUnit::TestFixture void testInternalSpan() { Owned emptyMockHTTPHeaders = createProperties(); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getSpanContext(retrievedSpanCtxAttributes); @@ -395,7 +395,7 @@ class JlibTraceTest : public CppUnit::TestFixture const char * serverTraceID = retrievedSpanCtxAttributes->queryProp("traceID"); { - Owned internalSpan = serverSpan->createInternalSpan("internalSpan"); + OwnedSpanScope internalSpan = serverSpan->createInternalSpan("internalSpan"); //retrieve internalSpan context with the intent to interrogate attributes { @@ -429,7 +429,7 @@ class JlibTraceTest : public CppUnit::TestFixture void testRootServerSpan() { Owned emptyMockHTTPHeaders = createProperties(); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", emptyMockHTTPHeaders); //retrieve serverSpan context with the intent to propagate it to a remote child span { @@ -467,7 +467,7 @@ class JlibTraceTest : public CppUnit::TestFixture { Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, false); - Owned serverSpan = queryTraceManager().createServerSpan("invalidPropegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("invalidPropegatedServerSpan", mockHTTPHeaders); Owned retrievedSpanCtxAttributes = createProperties(); serverSpan->getClientHeaders(retrievedSpanCtxAttributes.get()); @@ -488,7 +488,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //remoteParentSpanID, globalID, callerID @@ -509,10 +509,10 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); - Owned clientSpan = serverSpan->createClientSpan("clientSpan"); - Owned internalSpan = clientSpan->createInternalSpan("internalSpan"); - Owned internalSpan2 = internalSpan->createInternalSpan("internalSpan2"); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpan"); + OwnedSpanScope internalSpan = clientSpan->createInternalSpan("internalSpan"); + OwnedSpanScope internalSpan2 = internalSpan->createInternalSpan("internalSpan2"); StringBuffer out; out.set("{"); @@ -547,8 +547,8 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); //includes global ID - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); - Owned clientSpan = serverSpan->createClientSpan("clientSpanWithGlobalID"); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpanWithGlobalID"); //retrieve serverSpan context with the intent to interrogate attributes { @@ -570,7 +570,7 @@ class JlibTraceTest : public CppUnit::TestFixture Owned mockHTTPHeaders = createProperties(); createMockHTTPHeaders(mockHTTPHeaders, true); - Owned serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); + OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("propegatedServerSpan", mockHTTPHeaders); //at this point the serverSpan should have the following context attributes //traceID, spanID, remoteParentSpanID, traceFlags, traceState, globalID, callerID @@ -616,7 +616,7 @@ class JlibTraceTest : public CppUnit::TestFixture mockHTTPHeadersSA.append("HPCC-Global-Id:someGlobalID"); mockHTTPHeadersSA.append("HPCC-Caller-Id:IncomingCID"); - Owned serverSpan = queryTraceManager().createServerSpan("StringArrayPropegatedServerSpan", mockHTTPHeadersSA); + OwnedSpanScope 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 158c7ee226f..2feb711afad 100644 --- a/thorlcr/graph/thgraphmaster.cpp +++ b/thorlcr/graph/thgraphmaster.cpp @@ -1502,10 +1502,10 @@ CJobMaster::CJobMaster(IConstWorkUnit &_workunit, const char *graphName, ILoaded init(); Owned traceHeaders = extractTraceDebugOptions(workunit); - Owned requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + ContextSpanScope spanScope(*logctx, requestSpan); requestSpan->setSpanAttribute("hpcc.wuid", workunit->queryWuid()); requestSpan->setSpanAttribute("hpcc.graph", graphName); - ContextSpanScope spanScope(*logctx, requestSpan); resumed = WUActionResume == workunit->getAction(); fatalHandler.setown(new CFatalHandler(globals->getPropInt("@fatal_timeout", FATAL_TIMEOUT))); diff --git a/thorlcr/graph/thgraphslave.cpp b/thorlcr/graph/thgraphslave.cpp index c510d59960b..4c339769d5f 100644 --- a/thorlcr/graph/thgraphslave.cpp +++ b/thorlcr/graph/thgraphslave.cpp @@ -1680,10 +1680,10 @@ CJobSlave::CJobSlave(ISlaveWatchdog *_watchdog, IPropertyTree *_workUnitInfo, co init(); Owned traceHeaders = deserializeTraceDebugOptions(workUnitInfo->queryPropTree("Debug")); - Owned requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + OwnedSpanScope requestSpan = queryTraceManager().createServerSpan("run_graph", traceHeaders); + ContextSpanScope spanScope(*logctx, requestSpan); requestSpan->setSpanAttribute("hpcc.wuid", wuid); requestSpan->setSpanAttribute("hpcc.graph", graphName); - ContextSpanScope spanScope(*logctx, requestSpan); oldNodeCacheMem = 0; slavemptag = _slavemptag;