From fcfcaaffc934e3c1489bbd4e89cdeae9dec82383 Mon Sep 17 00:00:00 2001 From: Rodrigo Pastrana Date: Tue, 5 Dec 2023 20:04:42 -0500 Subject: [PATCH] HPCC-30470 codereviewX - Updates README's invalid default exporter claim - Removed comments deemed not useful - Adds inline type:span annotation - Casts chrono values to long long - labeled printXYZ functions public for unittest - Config related log output labeled ops info - Enabled all logfeature flags, if none provided, default - Adds several unittests - not full coverage Signed-off-by: Rodrigo Pastrana --- helm/examples/tracing/README.md | 10 ++-- system/jlib/jtrace.cpp | 65 ++++++++++++++--------- testing/unittests/CMakeLists.txt | 1 + testing/unittests/jlibtests.cpp | 89 ++++++++++++++++++++++++++++++++ 4 files changed, 135 insertions(+), 30 deletions(-) diff --git a/helm/examples/tracing/README.md b/helm/examples/tracing/README.md index e525663ce8c..153ffad5ced 100644 --- a/helm/examples/tracing/README.md +++ b/helm/examples/tracing/README.md @@ -14,7 +14,7 @@ All configuration options detailed here are part of the HPCC Systems Helm chart, - logSpanStart - If true, generate a log entry whenever a span is started (default: false) - logSpanFinish - If true, generate a log entry whenever a span is finished (default: false) - exporter - Defines The type of exporter in charge of forwarding span data to target back-end - - type - (defalt: NONE) "OTLP-HTTP" | "OTLP-GRCP" | "OS" | "JLOG" | "NONE" + - type - (defalt: JLOG) "OTLP-HTTP" | "OTLP-GRCP" | "OS" | "JLOG" | "NONE" - JLOG - logSpanDetails - Log span details such as description, status, kind - logParentInfo - Log the span's parent info such as ParentSpanId, and TraceState @@ -76,7 +76,7 @@ Sample exported span data: "span_id": "b9489283b66c1073", "start": 1701456073994968800, "duration": 1002426, - "Attributes": { + "attributes": { "http.request.method": "GET", "hpcc.localid": "JJmvRRBJ1QYU8o4xe1sgxJ", "hpcc.globalid": "JJmvRRBjnJGY6vgkjkAjJc" @@ -85,21 +85,21 @@ Sample exported span data: { "name": "Acquiring lock", "time_stamp": 1701456073995175400, - "Attributes": { + "attributes": { "lock_name": "resourcelock" } }, { "name": "Got lock, doing work...", "time_stamp": 1701456073995269400, - "Attributes": { + "attributes": { "lock_name": "resourcelock" } }, { "name": "Release lock", "time_stamp": 1701456073996269400, - "Attributes": { + "attributes": { "lock_name": "resourcelock" } } diff --git a/system/jlib/jtrace.cpp b/system/jlib/jtrace.cpp index 74e368cb86d..44b50e6dc22 100644 --- a/system/jlib/jtrace.cpp +++ b/system/jlib/jtrace.cpp @@ -180,10 +180,7 @@ class JLogSpanExporter final : public opentelemetry::sdk::trace::SpanExporter const nostd::span> &recordables) noexcept override { if (isShutDown()) - { - //Not logging this event per code review comments return opentelemetry::sdk::common::ExportResult::kFailure; - } for (auto &recordable : recordables) { @@ -198,12 +195,12 @@ class JLogSpanExporter final : public opentelemetry::sdk::trace::SpanExporter span->GetTraceId().ToLowerBase16(traceID); span->GetSpanId().ToLowerBase16(spanID); - StringBuffer out; - out.setf("{ \"name\": \"%s\"", span->GetName().data()); + StringBuffer out("{ \"type\": \"span\""); //for simple identification in log scraping + out.appendf(", \"name\": \"%s\"", span->GetName().data()); out.append(", \"trace_id\": \"").append(32, traceID).append("\""); out.append(", \"span_id\": \"").append(16, spanID).append("\""); - out.appendf(", \"start\": %s", std::to_string(span->GetStartTime().time_since_epoch().count()).c_str()); - out.appendf(", \"duration\": %s", std::to_string(span->GetDuration().count()).c_str()); + out.appendf(", \"start\": %lld", (long long)(span->GetStartTime().time_since_epoch()).count()); + out.appendf(", \"duration\": %lld", (long long)span->GetDuration().count()); if (hasMask(logFlags, SpanLogFlags::LogParentInfo)) { @@ -268,7 +265,8 @@ class JLogSpanExporter final : public opentelemetry::sdk::trace::SpanExporter return shutDown; } - static void printAttributes(StringBuffer & out, const std::unordered_map &map, const char * attsContainerName = "Attributes") +public: + static void printAttributes(StringBuffer & out, const std::unordered_map &map, const char * attsContainerName = "attributes") { if (map.size() == 0) return; @@ -311,7 +309,7 @@ class JLogSpanExporter final : public opentelemetry::sdk::trace::SpanExporter first = false; out.append("{ \"name\": \"").append(event.GetName().data()).append("\""); - out.appendf(", \"time_stamp\": \"%s\"", std::to_string(event.GetTimestamp().time_since_epoch().count()).c_str()); + out.appendf(", \"time_stamp\": %lld", (long long)event.GetTimestamp().time_since_epoch().count()); printAttributes(out, event.GetAttributes()); out.append(" }"); @@ -1125,14 +1123,14 @@ void CTraceManager::initTracerProviderAndGlobalInternals(const IPropertyTree * t { StringBuffer exportType; exportConfig->getProp("@type", exportType); - DBGLOG("Exporter type: %s", exportType.str()); + LOG(MCoperatorInfo, "Exporter type: %s", exportType.str()); if (!exportType.isEmpty()) { if (stricmp(exportType.str(), "OS")==0) //To stdout/err { exporter = opentelemetry::exporter::trace::OStreamSpanExporterFactory::Create(); - DBGLOG("Tracing exporter set OS"); + LOG(MCoperatorInfo, "Tracing exporter set OS"); } else if (stricmp(exportType.str(), "OTLP")==0 || stricmp(exportType.str(), "OTLP-HTTP")==0) { @@ -1148,7 +1146,7 @@ void CTraceManager::initTracerProviderAndGlobalInternals(const IPropertyTree * t trace_opts.console_debug = exportConfig->getPropBool("@consoleDebug", false); exporter = opentelemetry::exporter::otlp::OtlpHttpExporterFactory::Create(trace_opts); - DBGLOG("Tracing exporter set to OTLP/HTTP to: (%s)", trace_opts.url.c_str()); + LOG(MCoperatorInfo,"Tracing exporter set to OTLP/HTTP to: (%s)", trace_opts.url.c_str()); } else if (stricmp(exportType.str(), "OTLP-GRPC")==0) { @@ -1173,13 +1171,28 @@ void CTraceManager::initTracerProviderAndGlobalInternals(const IPropertyTree * t opts.timeout = std::chrono::seconds(exportConfig->getPropInt("@timeOutSecs")); exporter = otlp::OtlpGrpcExporterFactory::Create(opts); - DBGLOG("Tracing exporter set to OTLP/GRPC to: (%s)", opts.endpoint.c_str()); + LOG(MCoperatorInfo, "Tracing exporter set to OTLP/GRPC to: (%s)", opts.endpoint.c_str()); } - else if (stricmp(exportType.str(), "JLog")==0) + else if (stricmp(exportType.str(), "JLOG")==0) { StringBuffer logFlagsStr; - SpanLogFlags logFlags = DEFAULT_SPAN_LOG_FLAGS; //LogParentInfo|LogAttributes + SpanLogFlags logFlags = SpanLogFlags::LogNone; + if (exportConfig->getPropBool("@logSpanDetails", false)) + { + logFlags |= SpanLogFlags::LogSpanDetails; + logFlagsStr.append(" LogDetails "); + } + if (exportConfig->getPropBool("@logParentInfo", false)) + { + logFlags |= SpanLogFlags::LogParentInfo; + logFlagsStr.append(" LogParentInfo "); + } + if (exportConfig->getPropBool("@logAttributes", false)) + { + logFlags |= SpanLogFlags::LogAttributes; + logFlagsStr.append(" LogAttributes "); + } if (exportConfig->getPropBool("@logEvents", false)) { logFlags |= SpanLogFlags::LogEvents; @@ -1196,23 +1209,26 @@ void CTraceManager::initTracerProviderAndGlobalInternals(const IPropertyTree * t logFlagsStr.append(" LogLinks "); } - // Unconditionally recreating exporter per code review comments + //if no log feature flags provided, use default + if (logFlags == SpanLogFlags::LogNone) + logFlags = DEFAULT_SPAN_LOG_FLAGS; + exporter = JLogSpanExporterFactory::Create(logFlags); - DBGLOG("Tracing exporter set to JLog: logFlags( LogAttributes LogParentInfo %s)", logFlagsStr.str()); + LOG(MCoperatorInfo, "Tracing exporter set to JLog: logFlags( LogAttributes LogParentInfo %s)", logFlagsStr.str()); } else if (stricmp(exportType.str(), "Prometheus")==0) - DBGLOG("Tracing to Prometheus currently not supported"); + LOG(MCoperatorInfo, "Tracing to Prometheus currently not supported"); else if (stricmp(exportType.str(), "NONE")==0) { exporter = NoopSpanExporterFactory::Create(); - DBGLOG("Tracing exporter set to 'NONE', no trace exporting will be performed"); + LOG(MCoperatorInfo, "Tracing exporter set to 'NONE', no trace exporting will be performed"); } else - DBGLOG("Tracing exporter type not supported: '%s', JLog trace exporting will be performed", exportType.str()); + LOG(MCoperatorInfo, "Tracing exporter type not supported: '%s', JLog trace exporting will be performed", exportType.str()); } else - DBGLOG("Tracing exporter type not specified"); + LOG(MCoperatorInfo, "Tracing exporter type not specified"); } } @@ -1235,15 +1251,15 @@ void CTraceManager::initTracerProviderAndGlobalInternals(const IPropertyTree * t //equal to max_queue_size. //size_t max_export_batch_size = 512 processor = opentelemetry::sdk::trace::BatchSpanProcessorFactory::Create(std::move(exporter), options); - DBGLOG("OpenTel tracing using batch Span Processor"); + LOG(MCoperatorInfo, "OpenTel tracing using batch Span Processor"); } else if (foundProcessorType && strcmp("simple", processorType.str())==0) { - DBGLOG("OpenTel tracing using batch simple Processor"); + LOG(MCoperatorInfo, "OpenTel tracing using batch simple Processor"); } else { - DBGLOG("OpenTel tracing detected invalid processor type: '%s'", processorType.str()); + LOG(MCoperatorInfo, "OpenTel tracing detected invalid processor type: '%s'", processorType.str()); } } @@ -1296,7 +1312,6 @@ void CTraceManager::initTracer(const IPropertyTree * traceConfig) logEvents: true logLinks: true logResources: true - )!!"; testTree.setown(createPTreeFromYAMLString(simulatedGlobalYaml, ipt_none, ptr_ignoreWhiteSpace, nullptr)); traceConfig = testTree->queryPropTree("global/tracing"); diff --git a/testing/unittests/CMakeLists.txt b/testing/unittests/CMakeLists.txt index 58153493d35..6b1b343864d 100644 --- a/testing/unittests/CMakeLists.txt +++ b/testing/unittests/CMakeLists.txt @@ -93,6 +93,7 @@ include_directories ( ${CMAKE_BINARY_DIR}/generated ${CMAKE_BINARY_DIR} ${CMAKE_BINARY_DIR}/oss + ${HPCC_SOURCE_DIR}/system/globalid ) ADD_DEFINITIONS( -D_CONSOLE ) diff --git a/testing/unittests/jlibtests.cpp b/testing/unittests/jlibtests.cpp index 9918b77c5ef..ea2fbc36ddb 100644 --- a/testing/unittests/jlibtests.cpp +++ b/testing/unittests/jlibtests.cpp @@ -36,6 +36,10 @@ #include "jutil.hpp" #include "junicode.hpp" +#include "lnuid.h" +#undef UNIMPLEMENTED //opentelemetry defines UNIMPLEMENTED +#include "jtrace.cpp" + #include "unittests.hpp" #define CPPUNIT_ASSERT_EQUAL_STR(x, y) CPPUNIT_ASSERT_EQUAL(std::string(x),std::string(y)) @@ -60,6 +64,9 @@ class JlibTraceTest : public CppUnit::TestFixture CPPUNIT_TEST(testNullSpan); CPPUNIT_TEST(testClientSpanGlobalID); CPPUNIT_TEST(testEnsureTraceID); + + CPPUNIT_TEST(testJTraceJLOGExporterprintResources); + CPPUNIT_TEST(testJTraceJLOGExporterprintAttributes); CPPUNIT_TEST_SUITE_END(); const char * simulatedGlobalYaml = R"!!(global: @@ -104,6 +111,88 @@ class JlibTraceTest : public CppUnit::TestFixture protected: + void testJTraceJLOGExporterprintAttributes() + { + StringBuffer out; + JLogSpanExporter::printAttributes(out, {}, "attributes"); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected non-empty printattributes", true, out.length() == 0); + + + JLogSpanExporter::printAttributes(out, {{"url", "https://localhost"}, {"content-length", 562}, {"content-type", "html/text"}}, "attributes"); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected empty printattributes", false, out.length() == 0); + + Owned jtraceAsTree; + try + { + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected leading non-comma char in printattributes", true, out.charAt(0) == ','); + + out.setCharAt(0, '{'); + out.append("}"); + + jtraceAsTree.setown(createPTreeFromJSONString(out.str())); + + StringBuffer msg; + toXML(jtraceAsTree, msg); + DBGLOG("#####testJTraceJLOGExporterprintAttributes: %s", msg.str()); + } + catch (IException *e) + { + StringBuffer msg; + msg.append("Unexpected printAttributes format failure detected: "); + e->errorMessage(msg); + e->Release(); + CPPUNIT_ASSERT_MESSAGE(msg.str(), false); + } + + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected printresources format failure detected", true, jtraceAsTree != nullptr); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("attributes")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("attributes/url")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("attributes/content-length")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("attributes/content-type")); + } + + void testJTraceJLOGExporterprintResources() + { + StringBuffer out; + auto dummyAttributes = opentelemetry::sdk::resource::ResourceAttributes + { + {"service.name", "shoppingcart"}, + {"service.instance.id", "instance-12"} + }; + auto dummyResources = opentelemetry::sdk::resource::Resource::Create(dummyAttributes); + + JLogSpanExporter::printResources(out, dummyResources); + + Owned jtraceAsTree; + try + { + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected empty printresources return", false, out.length() == 0); + + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected leading non-comma char in printresources return", true, out.charAt(0) == ','); + + out.setCharAt(0, '{'); + out.append("}"); + + jtraceAsTree.setown(createPTreeFromJSONString(out.str())); + } + catch (IException *e) + { + StringBuffer msg; + msg.append("Unexpected printresources format failure detected: "); + e->errorMessage(msg); + e->Release(); + CPPUNIT_ASSERT_MESSAGE(msg.str(), false); + } + + CPPUNIT_ASSERT_EQUAL_MESSAGE("Unexpected printresources format failure detected", true, jtraceAsTree != nullptr); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/service.name")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/service.instance.id")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/telemetry.sdk.language")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/telemetry.sdk.version")); + CPPUNIT_ASSERT_EQUAL_MESSAGE("Missing resource attribute detected", true, jtraceAsTree->hasProp("resources/telemetry.sdk.name")); + } + void testTraceDisableConfig() { Owned testTree = createPTreeFromYAMLString(disableTracingYaml, ipt_none, ptr_ignoreWhiteSpace, nullptr);