diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index 8e5fab89106..e7e5fcab60f 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -458,7 +458,7 @@ class CTraceManager : implements ITraceManager, public CInterface CTraceManager(); IMPLEMENT_IINTERFACE - virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const std::chrono::time_point spanStartTime, const std::chrono::time_point spanStartSteadyTime, SpanFlags flags) const override; + virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const SpanTimeStamp * spanStartTimeStamp, SpanFlags flags) const override; virtual ISpan * createServerSpan(const char * name, StringArray & httpHeaders, SpanFlags flags) const override; virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, SpanFlags flags) const override; @@ -988,14 +988,13 @@ class CServerSpan : public CSpan } public: - CServerSpan(const char * spanName, const IProperties * httpHeaders, SpanFlags flags, const std::chrono::time_point sytemClockStartTime = {}, const std::chrono::time_point steadyClockStartTime = {}) + CServerSpan(const char * spanName, const IProperties * httpHeaders, SpanFlags flags, const SpanTimeStamp * spanStartTimeStamp = nullptr) : CSpan(spanName) { - if (sytemClockStartTime.time_since_epoch() != std::chrono::nanoseconds::zero() && - steadyClockStartTime.time_since_epoch() != std::chrono::nanoseconds::zero()) + if (spanStartTimeStamp && spanStartTimeStamp->isInitilized()) { - opts.start_system_time = opentelemetry::common::SystemTimestamp(sytemClockStartTime); - opts.start_steady_time = opentelemetry::common::SteadyTimestamp(steadyClockStartTime); + opts.start_system_time = opentelemetry::common::SystemTimestamp(spanStartTimeStamp->systemClockTime); + opts.start_steady_time = opentelemetry::common::SteadyTimestamp(spanStartTimeStamp->steadyClockTime); } opts.kind = opentelemetry::trace::SpanKind::kServer; @@ -1044,18 +1043,6 @@ class CServerSpan : public CSpan //--------------------------------------------------------------------------------------------------------------------- -const std::chrono::time_point nowSystemClock() -{ - const std::chrono::time_point nowTimePoint = std::chrono::system_clock::now(); - return nowTimePoint; -} - -const std::chrono::time_point nowSteadyClock() -{ - const std::chrono::time_point nowTimePoint = std::chrono::steady_clock::now(); - return nowTimePoint; -} - IProperties * getClientHeaders(const ISpan * span) { Owned headers = createProperties(true); @@ -1359,10 +1346,11 @@ ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * h return new CServerSpan(name, httpHeaders, flags); } -ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * httpHeaders, const std::chrono::time_point systemClockStartTime, const std::chrono::time_point steadyClockStartTime, SpanFlags flags = SpanFlags::None) const +ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * httpHeaders, const SpanTimeStamp * spanStartTimeStamp, SpanFlags flags = SpanFlags::None) const { - return new CServerSpan(name, httpHeaders, flags, systemClockStartTime, steadyClockStartTime); + return new CServerSpan(name, httpHeaders, flags, spanStartTimeStamp); } + //--------------------------------------------------------------------------------------------------------------------- MODULE_INIT(INIT_PRIORITY_STANDARD) diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index bde691313d9..5325032f0bd 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -77,10 +77,32 @@ interface ISpan : extends IInterface extern jlib_decl IProperties * getClientHeaders(const ISpan * span); extern jlib_decl IProperties * getSpanContext(const ISpan * span); +struct SpanTimeStamp +{ + std::chrono::nanoseconds steadyClockTime = std::chrono::nanoseconds::zero(); + std::chrono::nanoseconds systemClockTime = std::chrono::nanoseconds::zero(); + + void now() + { + systemClockTime = std::chrono::duration_cast(std::chrono::system_clock::now().time_since_epoch()); + steadyClockTime = std::chrono::duration_cast(std::chrono::steady_clock::now().time_since_epoch()); + } + + void setMSTickTime(const unsigned int msTickTime) + { + systemClockTime = std::chrono::duration_cast(std::chrono::system_clock::now().time_since_epoch() - std::chrono::milliseconds(msTick() - msTickTime)); + steadyClockTime = std::chrono::duration_cast(std::chrono::steady_clock::now().time_since_epoch() - std::chrono::milliseconds(msTick() - msTickTime)); + } + + bool isInitilized() const + { + return systemClockTime != std::chrono::nanoseconds::zero(); + } +}; + interface ITraceManager : extends IInterface { - //virtual ISpan * createDelayedServerSpan(const char * name, const IProperties * httpHeaders, std::chrono::nanoseconds spanStartTime, std::chrono::nanoseconds spanStartSteadyTime = std::chrono::nanoseconds::zero(), SpanFlags flags = SpanFlags::None) const = 0; - virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const std::chrono::time_point systemClockStartTime, const std::chrono::time_point steadyClockStartTime, SpanFlags flags = SpanFlags::None) const = 0; + virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const SpanTimeStamp * spanStartTimeStamp, SpanFlags flags = SpanFlags::None) const = 0; virtual ISpan * createServerSpan(const char * name, StringArray & httpHeaders, SpanFlags flags = SpanFlags::None) const = 0; virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, SpanFlags flags = SpanFlags::None) const = 0; virtual bool isTracingEnabled() const = 0; @@ -89,6 +111,7 @@ interface ITraceManager : extends IInterface extern jlib_decl ISpan * getNullSpan(); extern jlib_decl void initTraceManager(const char * componentName, const IPropertyTree * componentConfig, const IPropertyTree * globalConfig); extern jlib_decl ITraceManager & queryTraceManager(); + /* Temporarily disabled due to build issues in certain environments #ifdef _USE_CPPUNIT @@ -100,10 +123,6 @@ extern jlib_decl void testJLogExporterPrintAttributes(StringBuffer & out, const #endif */ -extern jlib_decl const std::chrono::time_point nowSystemClock(); -extern jlib_decl const std::chrono::time_point nowSteadyClock(); - - //The following class is responsible for ensuring that the active span is restored in a context when the scope is exited //Use a template class so it can be reused for IContextLogger and IEspContext template diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index cb2754efdbf..4f3fbf595ce 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -23,6 +23,7 @@ #ifdef _USE_CPPUNIT #include #include +#include #include #include "jsem.hpp" #include "jfile.hpp" @@ -66,7 +67,7 @@ class JlibTraceTest : public CppUnit::TestFixture //CPPUNIT_TEST(testJTraceJLOGExporterprintResources); //CPPUNIT_TEST(testJTraceJLOGExporterprintAttributes); - CPPUNIT_TEST(testDeclaredSpanStartTime); + CPPUNIT_TEST(manualTestsDeclaredSpanStartTime); CPPUNIT_TEST_SUITE_END(); const char * simulatedGlobalYaml = R"!!(global: @@ -189,29 +190,30 @@ class JlibTraceTest : public CppUnit::TestFixture CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/telemetry.sdk.name")); }*/ - void testDeclaredSpanStartTime() + //not able to programmatically test yet, but can visually inspect trace output + void manualTestsDeclaredSpanStartTime() { Owned emptyMockHTTPHeaders = createProperties(); - std::chrono::time_point systemClockTimePoint = {}; - std::chrono::time_point steadyClockTimePoint = {}; - + SpanTimeStamp declaredSpanStartTime; + declaredSpanStartTime.now(); // must be initialized via now(), or setMSTickTime + std::this_thread::sleep_for(std::chrono::milliseconds(50)); { - Owned serverSpan = queryTraceManager().createServerSpan("uninitializedStartTimePoints", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint); - //{ "type": "span", "name": "uninitializedStartTimePoints", "trace_id": "b75d55036323192bf361764a01301742", "span_id": "e20e42d895a165be", "start": 1702430078380386963, "duration": 2075504 } + Owned serverSpan = queryTraceManager().createServerSpan("declaredSpanStartTime", emptyMockHTTPHeaders, &declaredSpanStartTime); } - systemClockTimePoint += std::chrono::milliseconds(1000); - steadyClockTimePoint += std::chrono::milliseconds(10); + auto reqStartMSTick = msTick(); + + SpanTimeStamp msTickOffsetTimeStamp; + msTickOffsetTimeStamp.setMSTickTime(reqStartMSTick); + std::this_thread::sleep_for(std::chrono::milliseconds(50)); { - Owned serverSpan = queryTraceManager().createServerSpan("longAgoStartTimePoints", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint); - //{ "type": "span", "name": "oldStartTimePoints", "trace_id": "c69b30421fe1bc2284dc1067fe8df65a", "span_id": "e7f8f28943717b65", "start": 1000000000, "duration": 13235212449700 } + Owned serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); } - systemClockTimePoint = nowSystemClock(); - steadyClockTimePoint = nowSteadyClock() + std::chrono::hours(1); + //uninitialized SpanTimeStamp will be ignored, and current time will be used + SpanTimeStamp uninitializedTS; { - Owned serverSpan = queryTraceManager().createServerSpan("futureSteadyTimePoint", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint); - //{ "type": "span", "name": "futureSteadyTimePoint", "trace_id": "3676cdd536686f37da7d39b87b314bc5", "span_id": "c0987a831cb361e0", "start": 1702430699582015756, "duration": -3598764616294 } + Owned serverSpan = queryTraceManager().createServerSpan("uninitializeddeclaredSpanStartTime", emptyMockHTTPHeaders, &uninitializedTS); } }