From c003fb0b5538f151d1c1a88ba8b5ac81eafe5ba3 Mon Sep 17 00:00:00 2001 From: Rodrigo Pastrana Date: Wed, 20 Sep 2023 10:25:47 -0400 Subject: [PATCH] HPCC-30301 JTrace log output inprovements - Sets output to JSON format - Fixes derived destructor toString - Ensures Parent span output is encapsulated - Adds heads-up note on base destructor - Adds cppunit test for json output Signed-off-by: Rodrigo Pastrana --- system/jlib/jtrace.cpp | 62 +++++++++++++++++++++++---------- testing/unittests/jlibtests.cpp | 34 ++++++++++++++++++ 2 files changed, 77 insertions(+), 19 deletions(-) diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index 55fe2056783..fe86d6cb5c8 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -147,15 +147,12 @@ class CSpan : public CInterfaceOf { public: CSpan() = delete; - ~CSpan() + virtual ~CSpan() { + //Derived class specific behavior such as toString() should be + //called from the destructor of the derived class if (span != nullptr) - { - StringBuffer out; - toString(out); - DBGLOG("Span end: (%s)", out.str()); span->End(); - } } ISpan * createClientSpan(const char * name) override; @@ -163,19 +160,23 @@ class CSpan : public CInterfaceOf void toString(StringBuffer & out) const override { + out.append(",\"Name\":\"").append(name.get()).append("\""); + if (!isEmptyString(hpccGlobalId.get())) + out.append(",\"HPCCGlobalID\":\"").append(hpccGlobalId.get()).append("\""); + if (!isEmptyString(hpccCallerId.get())) + out.append(",\"HPCCCallerID\":\"").append(hpccCallerId.get()).append("\""); + if (span != nullptr) { - out.append(" Name: ").append(name.get()) - .append(" SpanID: ").append(spanID.get()) - .append(" TraceID: ").append(traceID.get()) - .append(" TraceFlags: ").append(traceFlags.get()) - .append(" HPCCGlobalID: ").append(hpccGlobalId.get()) - .append(" HPCCCallerID: ").append(hpccCallerId.get()); + out.append(",\"SpanID\":\"").append(spanID.get()).append("\"") + .append(",\"TraceID\":\"").append(traceID.get()).append("\"") + .append(",\"TraceFlags\":\"").append(traceFlags.get()).append("\""); if (localParentSpan != nullptr) { - out.append(" localParentSpan: "); + out.append(",\"LocalParentSpan\":{ "); localParentSpan->toString(out); + out.append(" }"); } } }; @@ -348,7 +349,7 @@ class CSpan : public CInterfaceOf StringBuffer out; toString(out); - DBGLOG("Span start: (%s)", out.str()); + DBGLOG("Span start: {%s}", out.str()); } } @@ -436,6 +437,13 @@ class CSpan : public CInterfaceOf class CInternalSpan : public CSpan { public: + ~CInternalSpan() override + { + StringBuffer out; + toString(out); + DBGLOG("Span end: {%s}", out.str()); + } + CInternalSpan(const char * spanName, CSpan * parent) : CSpan(spanName, parent) { @@ -445,7 +453,7 @@ class CInternalSpan : public CSpan void toString(StringBuffer & out) const override { - out.append("Type: Internal"); + out.append("\"Type\":\"Internal\""); CSpan::toString(out); } }; @@ -453,6 +461,13 @@ class CInternalSpan : public CSpan class CClientSpan : public CSpan { public: + ~CClientSpan() override + { + StringBuffer out; + toString(out); + DBGLOG("Span end: {%s}", out.str()); + } + CClientSpan(const char * spanName, CSpan * parent) : CSpan(spanName, parent) { @@ -462,7 +477,7 @@ class CClientSpan : public CSpan void toString(StringBuffer & out) const override { - out.append("Type: Client"); + out.append("\"Type\":\"Client\""); CSpan::toString(out); } }; @@ -563,6 +578,14 @@ class CServerSpan : public CSpan } public: + + ~CServerSpan() override + { + StringBuffer out; + toString(out); + DBGLOG("Span end: {%s}", out.str()); + } + CServerSpan(const char * spanName, const char * tracerName_, StringArray & httpHeaders) : CSpan(spanName, tracerName_) { @@ -581,15 +604,16 @@ class CServerSpan : public CSpan void toString(StringBuffer & out) const override { - out.append("Type: Server"); + out.append("\"Type\":\"Server\""); CSpan::toString(out); if (remoteParentSpanCtx.IsValid()) { - out.append(" remoteParentSpanID: "); + out.append(",\"RemoteParentSpanID\":\""); char spanId[16] = {0}; remoteParentSpanCtx.span_id().ToLowerBase16(spanId); - out.append(16, spanId); + out.append(16, spanId) + .append("\""); } } }; diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index 5f861add019..3071c060261 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -53,6 +53,7 @@ class JlibTraceTest : public CppUnit::TestFixture CPPUNIT_TEST(testPropegatedServerSpan); CPPUNIT_TEST(testInvalidPropegatedServerSpan); CPPUNIT_TEST(testInternalSpan); + CPPUNIT_TEST(testMultiNestedSpan); CPPUNIT_TEST_SUITE_END(); const char * simulatedGlobalYaml = R"!!(global: @@ -332,6 +333,39 @@ class JlibTraceTest : public CppUnit::TestFixture strcmp("4b960b3e4647da3f", retrievedSpanCtxAttributes->queryProp("remoteParentSpanID"))); } + void testMultiNestedSpan() + { + 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"); + + StringBuffer out; + out.set("{"); + internalSpan2->toString(out); + out.append("}"); + + try + { + Owned jtraceAsTree = createPTreeFromJSONString(out.str()); + + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected toString format failure detected", true, jtraceAsTree != nullptr); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected missing 'TraceID' entry in toString output", true, jtraceAsTree->hasProp("TraceID")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected missing 'SpanID' entry in toString output", true, jtraceAsTree->hasProp("SpanID")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected missing 'Name' entry in toString output", true, jtraceAsTree->hasProp("Name")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected missing 'Type' entry in toString output", true, jtraceAsTree->hasProp("Type")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected missing 'LocalParentSpan' entry in toString output", true, jtraceAsTree->hasProp("LocalParentSpan")); + } + catch (...) + { + CPPUNIT_ASSERT_MESSAGE("Unexpected toString format failure detected", false); + } + + } + void testPropegatedServerSpan() { Owned mockHTTPHeaders = createProperties();