diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index f50e696c3f0..69c4f2d0baf 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -557,8 +557,8 @@ class CSpan : public CInterfaceOf return spanID.get(); } - ISpan * createClientSpan(const char * name) override; - ISpan * createInternalSpan(const char * name) override; + ISpan * createClientSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) override; + ISpan * createInternalSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) override; virtual void endSpan() final override { @@ -918,8 +918,8 @@ class CNullSpan final : public CInterfaceOf virtual const char* queryCallerId() const override { return nullptr; } virtual const char* queryLocalId() const override { return nullptr; } - virtual ISpan * createClientSpan(const char * name) override { return getNullSpan(); } - virtual ISpan * createInternalSpan(const char * name) override { return getNullSpan(); } + virtual ISpan * createClientSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) override { return getNullSpan(); } + virtual ISpan * createInternalSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) override { return getNullSpan(); } private: CNullSpan(const CNullSpan&) = delete; @@ -930,9 +930,14 @@ class CNullSpan final : public CInterfaceOf class CChildSpan : public CSpan { protected: - CChildSpan(const char * spanName, CSpan * parent) + CChildSpan(const char * spanName, CSpan * parent, const SpanTimeStamp *spanStartTimeStamp = nullptr) : CSpan(spanName), localParentSpan(parent) { + if (spanStartTimeStamp && spanStartTimeStamp->isInitialized()) + { + opts.start_system_time = opentelemetry::common::SystemTimestamp(spanStartTimeStamp->systemClockTime); + opts.start_steady_time = opentelemetry::common::SteadyTimestamp(spanStartTimeStamp->steadyClockTime); + } injectlocalParentSpan(localParentSpan); } @@ -984,8 +989,8 @@ class CChildSpan : public CSpan class CInternalSpan : public CChildSpan { public: - CInternalSpan(const char * spanName, CSpan * parent) - : CChildSpan(spanName, parent) + CInternalSpan(const char * spanName, CSpan * parent, const SpanTimeStamp * spanStartTimeStamp = nullptr) + : CChildSpan(spanName, parent, spanStartTimeStamp) { opts.kind = opentelemetry::trace::SpanKind::kInternal; init(SpanFlags::None); @@ -1001,8 +1006,8 @@ class CInternalSpan : public CChildSpan class CClientSpan : public CChildSpan { public: - CClientSpan(const char * spanName, CSpan * parent) - : CChildSpan(spanName, parent) + CClientSpan(const char * spanName, CSpan * parent, const SpanTimeStamp * spanStartTimeStamp = nullptr) + : CChildSpan(spanName, parent, spanStartTimeStamp) { opts.kind = opentelemetry::trace::SpanKind::kClient; init(SpanFlags::None); @@ -1015,14 +1020,14 @@ class CClientSpan : public CChildSpan } }; -ISpan * CSpan::createClientSpan(const char * name) +ISpan * CSpan::createClientSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp) { - return new CClientSpan(name, this); + return new CClientSpan(name, this, spanStartTimeStamp); } -ISpan * CSpan::createInternalSpan(const char * name) +ISpan * CSpan::createInternalSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp) { - return new CInternalSpan(name, this); + return new CInternalSpan(name, this, spanStartTimeStamp); } class CServerSpan : public CSpan diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index 85b6e3bb915..7f1e7d9431b 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -108,6 +108,29 @@ struct SpanError void setError(const char * _errorMessage, int _errorCode) { errorMessage = _errorMessage; errorCode = _errorCode; } }; +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 isInitialized() const + { + return systemClockTime != std::chrono::nanoseconds::zero(); + } +}; + interface ISpan : extends IInterface { virtual void setSpanAttribute(const char * key, const char * val) = 0; @@ -127,8 +150,8 @@ interface ISpan : extends IInterface virtual const char * queryTraceId() const = 0; virtual const char * querySpanId() const = 0; - virtual ISpan * createClientSpan(const char * name) = 0; - virtual ISpan * createInternalSpan(const char * name) = 0; + virtual ISpan * createClientSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) = 0; + virtual ISpan * createInternalSpan(const char * name, const SpanTimeStamp * spanStartTimeStamp = nullptr) = 0; //Old-style global/caller/local id interface functions virtual const char* queryGlobalId() const = 0; @@ -159,29 +182,6 @@ class jlib_decl OwnedSpanScope 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 isInitialized() const - { - return systemClockTime != std::chrono::nanoseconds::zero(); - } -}; - interface ITraceManager : extends IInterface { virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const SpanTimeStamp * spanStartTimeStamp, SpanFlags flags = SpanFlags::None) const = 0; diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index 2bf6f831ee4..9b16367a057 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -231,6 +231,13 @@ class JlibTraceTest : public CppUnit::TestFixture OwnedSpanScope 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); + //{ "type": "span", "name": "clientSpanStartTime", "trace_id": "f73b171fdcd120f88ca5b656866befee", "span_id": "7c798125d10ee0ec", + //"start": 1727200325699918374, "duration": 20256156, "parent_span_id": "b79fe15b7d727fca" } } auto reqStartMSTick = msTick(); @@ -247,6 +254,14 @@ class JlibTraceTest : public CppUnit::TestFixture nowTimeStamp.now(); { OwnedSpanScope serverSpan = queryTraceManager().createServerSpan("msTickOffsetStartTime", emptyMockHTTPHeaders, &msTickOffsetTimeStamp); + + unsigned clientStartMS = msTick(); + MilliSleep(20); + SpanTimeStamp clientSpanTimeStamp; + clientSpanTimeStamp.setMSTickTime(clientStartMS); + OwnedSpanScope clientSpan = serverSpan->createClientSpan("clientSpanOffsetTime", &clientSpanTimeStamp); + //{ "type": "span", "name": "clientSpanOffsetTime", "trace_id": "9a41723ddc0048d854ab34b79340e749", "span_id": "11af70aa6a6dbee3", + //"start": 1727200325770619773, "duration": 20015542, "parent_span_id": "531ad336071f453b" } } DBGLOG("MsTickOffset span actual start-time timestamp: %lld", (long long)(nowTimeStamp.systemClockTime).count());