enhance: add trace_id into segcore logs (#37656)

issue: #37655 Signed-off-by: chyezh <chyezh@outlook.com>
milvus-io · Nov 18, 2024 · 3f1614e · 3f1614e
1 parent 00edec2
commit 3f1614e
Show file tree

Hide file tree

Showing 5 changed files with 52 additions and 6 deletions.
diff --git a/Makefile b/Makefile
@@ -268,7 +268,7 @@ build-cpp-gpu: generated-proto
 
 build-cpp-with-unittest: generated-proto
 	@echo "Building Milvus cpp library with unittest ... "
-	@(env bash $(PWD)/scripts/core_build.sh -t ${mode} -u -n ${use_disk_index} -y ${use_dynamic_simd} ${AZURE_OPTION} -x ${index_engine} -o ${use_opendal})
+	@(env bash $(PWD)/scripts/core_build.sh -t ${mode} -a ${use_asan} -u -n ${use_disk_index} -y ${use_dynamic_simd} ${AZURE_OPTION} -x ${index_engine} -o ${use_opendal})
 
 build-cpp-with-coverage: generated-proto
 	@echo "Building Milvus cpp library with coverage and unittest ..."

diff --git a/internal/core/src/common/Tracer.cpp b/internal/core/src/common/Tracer.cpp
@@ -134,6 +134,28 @@ StartSpan(const std::string& name, const std::shared_ptr<trace::Span>& span) {
 }
 
 thread_local std::shared_ptr<trace::Span> local_span;
+
+std::string
+GetTraceID() {
+    // !!! The span is not sent by the calling context, but saved in the thread local now.
+    // So we cannot get the accurate trace id if the thread is switched to execute another task.
+    // Because we don't use folly thread pool to yield multi task,
+    // the trace id is almost accurate by now.
+    // It's safe to access local_span without mutex, because the span is not sent to other threads.
+    if (local_span == nullptr) {
+        return std::string();
+    }
+    auto ctx = local_span->GetContext();
+    auto trace_id = ctx.trace_id();
+    // The span is noop if the trace is off, 00000000... will be returned,
+    // so return "0" string directly to distinguish from the no local span.
+    if (!trace_id.IsValid()) {
+        return "0";
+    }
+    auto rep = trace_id.Id();
+    return BytesToHexStr(rep.data(), rep.size());
+}
+
 void
 SetRootSpan(std::shared_ptr<trace::Span> span) {
     if (enable_trace.load()) {

diff --git a/internal/core/src/common/Tracer.h b/internal/core/src/common/Tracer.h
@@ -80,6 +80,9 @@ GetTraceIDAsHexStr(const TraceContext* ctx);
 std::string
 GetSpanIDAsHexStr(const TraceContext* ctx);
 
+std::string
+GetTraceID();
+
 struct AutoSpan {
     explicit AutoSpan(const std::string& name,
                       TraceContext* ctx = nullptr,

diff --git a/internal/core/src/log/Log.h b/internal/core/src/log/Log.h
@@ -21,6 +21,7 @@
 #include <unistd.h>
 #include "glog/logging.h"
 #include "fmt/core.h"
+#include "common/Tracer.h"
 
 // namespace milvus {
 
@@ -67,11 +68,12 @@
            (typeid(*this).name()),   \
            __FUNCTION__,             \
            GetThreadName().c_str())
-#define SERVER_MODULE_FUNCTION \
-    LogOut("[%s][%s][%s] ",    \
-           SERVER_MODULE_NAME, \
-           __FUNCTION__,       \
-           GetThreadName().c_str())
+#define SERVER_MODULE_FUNCTION      \
+    fmt::format("[{}][{}][{}][{}]", \
+                SERVER_MODULE_NAME, \
+                __FUNCTION__,       \
+                GetThreadName(),    \
+                milvus::tracer::GetTraceID())
 
 #define LOG_DEBUG(args...) \
     VLOG(GLOG_DEBUG) << SERVER_MODULE_FUNCTION << fmt::format(args)

diff --git a/internal/core/unittest/test_tracer.cpp b/internal/core/unittest/test_tracer.cpp
@@ -115,3 +115,22 @@ TEST(Tracer, Hex) {
     delete[] ctx->traceID;
     delete[] ctx->spanID;
 }
+
+TEST(Tracer, GetTraceID) {
+    auto trace_id = GetTraceID();
+    ASSERT_TRUE(trace_id.empty());
+
+    auto config = std::make_shared<TraceConfig>();
+    config->exporter = "stdout";
+    config->nodeID = 1;
+    initTelemetry(*config);
+
+    auto span = StartSpan("test");
+    SetRootSpan(span);
+    trace_id = GetTraceID();
+    ASSERT_TRUE(trace_id.size() == 32);
+
+    CloseRootSpan();
+    trace_id = GetTraceID();
+    ASSERT_TRUE(trace_id.empty());
+}