Skip to content

Commit

Permalink
HPCC-30474 Provide JTrace option to declare span start time
Browse files Browse the repository at this point in the history
- Exposes helper method to obtain system and steady clock time_points
- Exposes createServerSpan function w/ optional starttime params
- Adds simple cppunit tests excersizing both newly exposed functions

Signed-off-by: Rodrigo Pastrana <[email protected]>
  • Loading branch information
rpastrana committed Dec 14, 2023
1 parent 6f3eebb commit ff24036
Show file tree
Hide file tree
Showing 3 changed files with 44 additions and 23 deletions.
35 changes: 19 additions & 16 deletions system/jlib/jtrace.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -458,7 +458,7 @@ class CTraceManager : implements ITraceManager, public CInterface
CTraceManager();
IMPLEMENT_IINTERFACE

virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, SpanFlags flags, std::chrono::nanoseconds spanStartTime) const override;
virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> spanStartTime, const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> spanStartSteadyTime, 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;

Expand Down Expand Up @@ -988,19 +988,16 @@ class CServerSpan : public CSpan
}

public:
CServerSpan(const char * spanName, const IProperties * httpHeaders, SpanFlags flags, std::chrono::nanoseconds spanStartTime)
CServerSpan(const char * spanName, const IProperties * httpHeaders, SpanFlags flags, const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> sytemClockStartTime = {}, const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> steadyClockStartTime = {})
: CSpan(spanName)
{
opts.start_system_time = opentelemetry::common::SystemTimestamp(std::chrono::duration_cast<std::chrono::nanoseconds>(spanStartTime));
opts.kind = opentelemetry::trace::SpanKind::kServer;
setSpanContext(httpHeaders, flags);
init(flags);
setContextAttributes();
}
if (sytemClockStartTime.time_since_epoch() != std::chrono::nanoseconds::zero() &&
steadyClockStartTime.time_since_epoch() != std::chrono::nanoseconds::zero())
{
opts.start_system_time = opentelemetry::common::SystemTimestamp(sytemClockStartTime);
opts.start_steady_time = opentelemetry::common::SteadyTimestamp(steadyClockStartTime);
}

CServerSpan(const char * spanName, const IProperties * httpHeaders, SpanFlags flags)
: CSpan(spanName)
{
opts.kind = opentelemetry::trace::SpanKind::kServer;
setSpanContext(httpHeaders, flags);
init(flags);
Expand Down Expand Up @@ -1047,9 +1044,16 @@ class CServerSpan : public CSpan

//---------------------------------------------------------------------------------------------------------------------

std::chrono::nanoseconds nowTimesStampInNanos()
const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> nowSystemClock()
{
const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> nowTimePoint = std::chrono::system_clock::now();
return nowTimePoint;
}

const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> nowSteadyClock()
{
return std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::system_clock::now().time_since_epoch());
const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> nowTimePoint = std::chrono::steady_clock::now();
return nowTimePoint;
}

IProperties * getClientHeaders(const ISpan * span)
Expand Down Expand Up @@ -1355,11 +1359,10 @@ ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * h
return new CServerSpan(name, httpHeaders, flags);
}

ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * httpHeaders, SpanFlags flags, std::chrono::nanoseconds spanStartTime) const
ISpan * CTraceManager::createServerSpan(const char * name, const IProperties * httpHeaders, const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> systemClockStartTime, const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> steadyClockStartTime, SpanFlags flags = SpanFlags::None) const
{
return new CServerSpan(name, httpHeaders, flags, spanStartTime);
return new CServerSpan(name, httpHeaders, flags, systemClockStartTime, steadyClockStartTime);
}

//---------------------------------------------------------------------------------------------------------------------

MODULE_INIT(INIT_PRIORITY_STANDARD)
Expand Down
8 changes: 6 additions & 2 deletions system/jlib/jtrace.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,8 @@ extern jlib_decl IProperties * getSpanContext(const ISpan * span);

interface ITraceManager : extends IInterface
{
virtual ISpan * createServerSpan(const char * name, const IProperties * httpHeaders, SpanFlags flags, std::chrono::nanoseconds spanStartTime) const = 0;
//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<std::chrono::system_clock, std::chrono::nanoseconds> systemClockStartTime, const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> steadyClockStartTime, 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;
Expand All @@ -88,7 +89,6 @@ 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();
extern jlib_decl std::chrono::nanoseconds nowTimesStampInNanos();
/*
Temporarily disabled due to build issues in certain environments
#ifdef _USE_CPPUNIT
Expand All @@ -100,6 +100,10 @@ extern jlib_decl void testJLogExporterPrintAttributes(StringBuffer & out, const
#endif
*/

extern jlib_decl const std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> nowSystemClock();
extern jlib_decl const std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> 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 <class CONTEXT>
Expand Down
24 changes: 19 additions & 5 deletions testing/unittests/jlibtests.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -191,14 +191,28 @@ class JlibTraceTest : public CppUnit::TestFixture

void testDeclaredSpanStartTime()
{
std::chrono::nanoseconds nownanos = nowTimesStampInNanos();
Owned<IProperties> emptyMockHTTPHeaders = createProperties();
std::chrono::time_point<std::chrono::system_clock, std::chrono::nanoseconds> systemClockTimePoint = {};
std::chrono::time_point<std::chrono::steady_clock, std::chrono::nanoseconds> steadyClockTimePoint = {};

Owned<ISpan> serverSpan = queryTraceManager().createServerSpan("declaredSpanStartSpan", emptyMockHTTPHeaders, SpanFlags::None, nownanos);
{
Owned<ISpan> serverSpan = queryTraceManager().createServerSpan("uninitializedStartTimePoints", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint);
//{ "type": "span", "name": "uninitializedStartTimePoints", "trace_id": "b75d55036323192bf361764a01301742", "span_id": "e20e42d895a165be", "start": 1702430078380386963, "duration": 2075504 }
}

Owned<IProperties> retrievedSpanCtxAttributes = createProperties();
bool getSpanCtxSuccess = serverSpan->getSpanContext(retrievedSpanCtxAttributes, false);
CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected getSpanContext failure detected", true, getSpanCtxSuccess);
systemClockTimePoint += std::chrono::milliseconds(1000);
steadyClockTimePoint += std::chrono::milliseconds(10);
{
Owned<ISpan> serverSpan = queryTraceManager().createServerSpan("longAgoStartTimePoints", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint);
//{ "type": "span", "name": "oldStartTimePoints", "trace_id": "c69b30421fe1bc2284dc1067fe8df65a", "span_id": "e7f8f28943717b65", "start": 1000000000, "duration": 13235212449700 }
}

systemClockTimePoint = nowSystemClock();
steadyClockTimePoint = nowSteadyClock() + std::chrono::hours(1);
{
Owned<ISpan> serverSpan = queryTraceManager().createServerSpan("futureSteadyTimePoint", emptyMockHTTPHeaders, systemClockTimePoint, steadyClockTimePoint);
//{ "type": "span", "name": "futureSteadyTimePoint", "trace_id": "3676cdd536686f37da7d39b87b314bc5", "span_id": "c0987a831cb361e0", "start": 1702430699582015756, "duration": -3598764616294 }
}
}

void testTraceDisableConfig()
Expand Down

0 comments on commit ff24036

Please sign in to comment.