Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HPCC-32691 Add optional timestamp arg to createClientSpan() #18969

Merged
merged 1 commit into from
Sep 25, 2024
Merged

HPCC-32691 Add optional timestamp arg to createClientSpan() #18969

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 18 additions & 13 deletions system/jlib/jtrace.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -557,8 +557,8 @@ class CSpan : public CInterfaceOf<ISpan>
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
{
Expand Down Expand Up @@ -918,8 +918,8 @@ class CNullSpan final : public CInterfaceOf<ISpan>
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;
Expand All @@ -930,9 +930,14 @@ class CNullSpan final : public CInterfaceOf<ISpan>
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);
}

Expand Down Expand Up @@ -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);
Expand All @@ -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);
Expand All @@ -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
Expand Down
50 changes: 25 additions & 25 deletions system/jlib/jtrace.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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::nanoseconds>(std::chrono::system_clock::now().time_since_epoch());
steadyClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::steady_clock::now().time_since_epoch());
}

void setMSTickTime(const unsigned int msTickTime)
{
systemClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::system_clock::now().time_since_epoch() - std::chrono::milliseconds(msTick() - msTickTime));
steadyClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(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;
Expand All @@ -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;
Expand Down Expand Up @@ -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::nanoseconds>(std::chrono::system_clock::now().time_since_epoch());
steadyClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::steady_clock::now().time_since_epoch());
}

void setMSTickTime(const unsigned int msTickTime)
{
systemClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::system_clock::now().time_since_epoch() - std::chrono::milliseconds(msTick() - msTickTime));
steadyClockTime = std::chrono::duration_cast<std::chrono::nanoseconds>(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;
Expand Down
15 changes: 15 additions & 0 deletions testing/unittests/jlibtests.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

were you able to confirm the start time was adjusted as expected?
We're not able to automatically validate these values (yet) but the log output should match your expected start time (we might need to printout clientSpanTimeStamp.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, I added the comments for the jlog Span output

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();
Expand All @@ -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());
Expand Down
Loading