Fix: OpenTelemetry access logs: Missing span ID (envoyproxy#33909)

--------- Signed-off-by: Ashish Banerjee <ashish.banerjee@solo.io>
juanmolle · Jun 5, 2024 · ad0a100 · ad0a100
1 parent f3303a5
commit ad0a100
Show file tree

Hide file tree

Showing 22 changed files with 62 additions and 6 deletions.
diff --git a/changelogs/current.yaml b/changelogs/current.yaml
@@ -106,6 +106,9 @@ bug_fixes:
   change: |
     Fix a RELEASE_ASSERT when using :ref:`auto_sni <envoy_v3_api_field_config.core.v3.UpstreamHttpProtocolOptions.auto_sni>`
     if the downstream request ``:authority`` was longer than 255 characters.
+- area: tracing
+  change: |
+    Fix an issue where span id is missing from opentelemetry access log entries.
 - area: ext_authz
   change: |
     Added field

diff --git a/envoy/tracing/trace_driver.h b/envoy/tracing/trace_driver.h
@@ -136,6 +136,12 @@ class Span {
    * @return trace ID
    */
   virtual std::string getTraceId() const PURE;
+
+  /**
+   * Retrieve the span's identifier.
+   * @return span ID as a hex string
+   */
+  virtual std::string getSpanId() const PURE;
 };
 
 /**

diff --git a/source/common/tracing/null_span_impl.h b/source/common/tracing/null_span_impl.h
@@ -25,6 +25,7 @@ class NullSpan : public Span {
   void injectContext(Tracing::TraceContext&, const UpstreamContext&) override {}
   void setBaggage(absl::string_view, absl::string_view) override {}
   std::string getBaggage(absl::string_view) override { return EMPTY_STRING; }
+  std::string getSpanId() const override { return EMPTY_STRING; }
   std::string getTraceId() const override { return EMPTY_STRING; }
   SpanPtr spawnChild(const Config&, const std::string&, SystemTime) override {
     return SpanPtr{new NullSpan()};

diff --git a/source/extensions/access_loggers/open_telemetry/access_log_impl.cc b/source/extensions/access_loggers/open_telemetry/access_log_impl.cc
@@ -102,6 +102,10 @@ void AccessLog::emitLog(const Formatter::HttpFormatterContext& log_context,
     auto trace_id = absl::StrCat(Hex::uint64ToHex(0), trace_id_hex);
     *log_entry.mutable_trace_id() = absl::HexStringToBytes(trace_id);
   }
+  std::string span_id_hex = log_context.activeSpan().getSpanId();
+  if (!span_id_hex.empty()) {
+    *log_entry.mutable_span_id() = absl::HexStringToBytes(span_id_hex);
+  }
 
   tls_slot_->getTyped<ThreadLocalLogger>().logger_->log(std::move(log_entry));
 }

diff --git a/source/extensions/tracers/common/ot/opentracing_driver_impl.h b/source/extensions/tracers/common/ot/opentracing_driver_impl.h
@@ -45,10 +45,11 @@ class OpenTracingSpan : public Tracing::Span, Logger::Loggable<Logger::Id::traci
   std::string getBaggage(absl::string_view key) override;
   void setBaggage(absl::string_view key, absl::string_view value) override;
 
-  // TODO: This method is unimplemented for OpenTracing.
-  // This won't be implemented because OpenTracing was deprecated.
-  // We should remove this method in the future?
+  // TODO(#34412): These two methods are unimplemented for OpenTracing.
+  // They won't be implemented because OpenTracing was deprecated.
+  // Maybe we should remove them in the future?
   std::string getTraceId() const override { return EMPTY_STRING; };
+  std::string getSpanId() const override { return EMPTY_STRING; };
 
 private:
   OpenTracingDriver& driver_;

diff --git a/source/extensions/tracers/datadog/span.cc b/source/extensions/tracers/datadog/span.cc
@@ -128,7 +128,7 @@ void Span::setSampled(bool sampled) {
 
 std::string Span::getBaggage(absl::string_view) {
   // not implemented
-  return std::string{};
+  return EMPTY_STRING;
 }
 
 void Span::setBaggage(absl::string_view, absl::string_view) {
@@ -137,11 +137,16 @@ void Span::setBaggage(absl::string_view, absl::string_view) {
 
 std::string Span::getTraceId() const {
   if (!span_) {
-    return std::string{};
+    return EMPTY_STRING;
   }
   return absl::StrCat(absl::Hex(span_->id()));
 }
 
+std::string Span::getSpanId() const {
+  // TODO(#34412): This method is not yet implemented for Datadog.
+  return EMPTY_STRING;
+}
+
 } // namespace Datadog
 } // namespace Tracers
 } // namespace Extensions

diff --git a/source/extensions/tracers/datadog/span.h b/source/extensions/tracers/datadog/span.h
@@ -48,6 +48,7 @@ class Span : public Tracing::Span {
   std::string getBaggage(absl::string_view key) override;
   void setBaggage(absl::string_view key, absl::string_view value) override;
   std::string getTraceId() const override;
+  std::string getSpanId() const override;
 
 private:
   datadog::tracing::Optional<datadog::tracing::Span> span_;

diff --git a/source/extensions/tracers/opencensus/opencensus_tracer_impl.cc b/source/extensions/tracers/opencensus/opencensus_tracer_impl.cc
@@ -81,6 +81,7 @@ class Span : public Tracing::Span {
   std::string getBaggage(absl::string_view) override { return EMPTY_STRING; };
 
   std::string getTraceId() const override;
+  std::string getSpanId() const override;
 
 private:
   ::opencensus::trace::Span span_;
@@ -236,6 +237,8 @@ void Span::injectContext(Tracing::TraceContext& trace_context, const Tracing::Up
   }
 }
 
+std::string Span::getSpanId() const { return EMPTY_STRING; }
+
 std::string Span::getTraceId() const {
   const auto& ctx = span_.context();
   return ctx.trace_id().ToHex();

diff --git a/source/extensions/tracers/opentelemetry/tracer.h b/source/extensions/tracers/opentelemetry/tracer.h
@@ -119,6 +119,8 @@ class Span : Logger::Loggable<Logger::Id::tracing>, public Tracing::Span {
 
   std::string getTraceId() const override { return absl::BytesToHexString(span_.trace_id()); };
 
+  std::string getSpanId() const override { return absl::BytesToHexString(span_.span_id()); };
+
   OTelSpanKind spankind() const { return span_.kind(); }
 
   /**

diff --git a/source/extensions/tracers/skywalking/tracer.h b/source/extensions/tracers/skywalking/tracer.h
@@ -89,6 +89,7 @@ class Span : public Tracing::Span {
   std::string getBaggage(absl::string_view) override { return EMPTY_STRING; }
   void setBaggage(absl::string_view, absl::string_view) override {}
   std::string getTraceId() const override { return tracing_context_->traceId(); }
+  std::string getSpanId() const override { return EMPTY_STRING; }
 
   const TracingContextPtr tracingContext() { return tracing_context_; }
   const TracingSpanPtr spanEntity() { return span_entity_; }

diff --git a/source/extensions/tracers/xray/tracer.h b/source/extensions/tracers/xray/tracer.h
@@ -230,9 +230,11 @@ class Span : public Tracing::Span, Logger::Loggable<Logger::Id::config> {
   void setBaggage(absl::string_view, absl::string_view) override {}
   std::string getBaggage(absl::string_view) override { return EMPTY_STRING; }
 
-  // TODO: This method is unimplemented for X-Ray.
   std::string getTraceId() const override { return trace_id_; };
 
+  // TODO(#34412): This method is unimplemented for X-Ray.
+  std::string getSpanId() const override { return EMPTY_STRING; };
+
   /**
    * Creates a child span.
    * In X-Ray terms this creates a sub-segment and sets its parent ID to the current span's ID.

diff --git a/source/extensions/tracers/zipkin/zipkin_tracer_impl.h b/source/extensions/tracers/zipkin/zipkin_tracer_impl.h
@@ -85,6 +85,9 @@ class ZipkinSpan : public Tracing::Span {
 
   std::string getTraceId() const override { return span_.traceIdAsHexString(); };
 
+  // TODO(#34412): This method is unimplemented for Zipkin.
+  std::string getSpanId() const override { return EMPTY_STRING; };
+
   /**
    * @return a reference to the Zipkin::Span object.
    */

diff --git a/test/common/tracing/tracer_impl_test.cc b/test/common/tracing/tracer_impl_test.cc
@@ -265,6 +265,7 @@ TEST(NullTracerTest, BasicFunctionality) {
   span_ptr->setBaggage("key", "value");
   ASSERT_EQ("", span_ptr->getBaggage("baggage_key"));
   ASSERT_EQ(span_ptr->getTraceId(), "");
+  ASSERT_EQ(span_ptr->getSpanId(), "");
   span_ptr->injectContext(trace_context, upstream_context);
   span_ptr->log(SystemTime(), "fake_event");
 

diff --git a/test/extensions/access_loggers/open_telemetry/access_log_impl_test.cc b/test/extensions/access_loggers/open_telemetry/access_log_impl_test.cc
@@ -176,7 +176,9 @@ TEST_F(AccessLogTest, TraceId) {
   NiceMock<Tracing::MockSpan> active_span;
 
   EXPECT_CALL(active_span, getTraceId()).WillOnce(Return("404142434445464748494a4b4c4d4e4f"));
+  EXPECT_CALL(active_span, getSpanId()).WillOnce(Return("4041424344454647"));
   expectLog(R"EOF(
+      span_id: "QEFCQ0RFRkc="
       trace_id: "QEFCQ0RFRkdISUpLTE1OTw=="
       time_unix_nano: 3600000000000
     )EOF");

diff --git a/test/extensions/filters/http/ext_proc/tracer_test_filter.cc b/test/extensions/filters/http/ext_proc/tracer_test_filter.cc
@@ -73,6 +73,10 @@ class Span : public Tracing::Span {
     /* not implemented */
     return EMPTY_STRING;
   };
+  std::string getSpanId() const {
+    /* not implemented */
+    return EMPTY_STRING;
+  };
 
   Tracing::SpanPtr spawnChild(const Tracing::Config&, const std::string& operation_name,
                               SystemTime) {

diff --git a/test/extensions/tracers/common/ot/opentracing_driver_impl_test.cc b/test/extensions/tracers/common/ot/opentracing_driver_impl_test.cc
@@ -353,6 +353,8 @@ TEST_F(OpenTracingDriverTest, GetTraceId) {
 
   // This method is unimplemented and a noop.
   ASSERT_EQ(first_span->getTraceId(), "");
+  // This method is unimplemented and a noop.
+  ASSERT_EQ(first_span->getSpanId(), "");
 }
 
 TEST_F(OpenTracingDriverTest, ExtractUsingForeach) {

diff --git a/test/extensions/tracers/datadog/span_test.cc b/test/extensions/tracers/datadog/span_test.cc
@@ -389,6 +389,7 @@ TEST_F(DatadogTracerSpanTest, Baggage) {
 TEST_F(DatadogTracerSpanTest, GetTraceId) {
   Span span{std::move(span_)};
   EXPECT_EQ("cafebabe", span.getTraceId());
+  EXPECT_EQ("", span.getSpanId());
 }
 
 TEST_F(DatadogTracerSpanTest, NoOpMode) {
@@ -430,6 +431,7 @@ TEST_F(DatadogTracerSpanTest, NoOpMode) {
   EXPECT_EQ("", span.getBaggage("foo"));
   span.setBaggage("foo", "bar");
   EXPECT_EQ("", span.getTraceId());
+  EXPECT_EQ("", span.getSpanId());
 }
 
 } // namespace

diff --git a/test/extensions/tracers/opencensus/tracer_test.cc b/test/extensions/tracers/opencensus/tracer_test.cc
@@ -130,6 +130,9 @@ TEST(OpenCensusTracerTest, Span) {
 
     // Trace id is automatically created when no parent context exists.
     ASSERT_NE(span->getTraceId(), "");
+
+    // Span id should be empty since this is not yet supported.
+    ASSERT_EQ(span->getSpanId(), "");
   }
 
   // Retrieve SpanData from the OpenCensus trace exporter.
@@ -222,6 +225,8 @@ void testIncomingHeaders(
     // Check contents via public API.
     // Trace id is set via context propagation headers.
     EXPECT_EQ(span->getTraceId(), "404142434445464748494a4b4c4d4e4f");
+    // TODO(#34412) This method is unimplemented.
+    EXPECT_EQ(span->getSpanId(), "");
   }
 
   // Retrieve SpanData from the OpenCensus trace exporter.

diff --git a/test/extensions/tracers/skywalking/tracer_test.cc b/test/extensions/tracers/skywalking/tracer_test.cc
@@ -90,6 +90,8 @@ TEST_F(TracerTest, TracerTestCreateNewSpanWithNoPropagationHeaders) {
     span->setOperation("FakeStringAndNothingToDo");
     span->setBaggage("FakeStringAndNothingToDo", "FakeStringAndNothingToDo");
     ASSERT_EQ(span->getTraceId(), segment_context->traceId());
+    // This method is unimplemented and a noop.
+    ASSERT_EQ(span->getSpanId(), "");
     // Test whether the basic functions of Span are normal.
     EXPECT_FALSE(span->spanEntity()->skipAnalysis());
     span->setSampled(false);

diff --git a/test/extensions/tracers/xray/tracer_test.cc b/test/extensions/tracers/xray/tracer_test.cc
@@ -388,6 +388,9 @@ TEST_F(XRayTracerTest, GetTraceId) {
 
   // Trace ID is always generated
   EXPECT_NE(span->getTraceId(), "");
+
+  // This method is unimplemented and a noop.
+  EXPECT_EQ(span->getSpanId(), "");
 }
 
 TEST_F(XRayTracerTest, ChildSpanHasParentInfo) {

diff --git a/test/extensions/tracers/zipkin/zipkin_tracer_impl_test.cc b/test/extensions/tracers/zipkin/zipkin_tracer_impl_test.cc
@@ -726,6 +726,7 @@ TEST_F(ZipkinDriverTest, ZipkinSpanTest) {
   Tracing::SpanPtr span6 = driver_->startSpan(config_, request_headers_, stream_info_,
                                               operation_name_, {Tracing::Reason::Sampling, true});
   EXPECT_EQ(span6->getTraceId(), "0000000000000000");
+  EXPECT_EQ(span6->getSpanId(), "");
 }
 
 TEST_F(ZipkinDriverTest, ZipkinSpanContextFromB3HeadersTest) {
@@ -799,6 +800,7 @@ TEST_F(ZipkinDriverTest, ZipkinSpanContextFromB3Headers128TraceIdTest) {
   EXPECT_EQ(parent_id, zipkin_span->span().parentIdAsHexString());
   EXPECT_TRUE(zipkin_span->span().sampled());
   EXPECT_EQ(trace_id, zipkin_span->getTraceId());
+  EXPECT_EQ("", zipkin_span->getSpanId());
 }
 
 TEST_F(ZipkinDriverTest, ZipkinSpanContextFromInvalidTraceIdB3HeadersTest) {

diff --git a/test/mocks/tracing/mocks.h b/test/mocks/tracing/mocks.h
@@ -44,6 +44,7 @@ class MockSpan : public Span {
   MOCK_METHOD(void, setBaggage, (absl::string_view key, absl::string_view value));
   MOCK_METHOD(std::string, getBaggage, (absl::string_view key));
   MOCK_METHOD(std::string, getTraceId, (), (const));
+  MOCK_METHOD(std::string, getSpanId, (), (const));
 
   SpanPtr spawnChild(const Config& config, const std::string& name,
                      SystemTime start_time) override {