Connect tracer with external application's logging facilities (#150)

BUILD.bazel

@@ -8,6 +8,8 @@ cc_library(
         "src/encoder.h",
         "src/limiter.cpp",
         "src/limiter.h",
+        "src/logger.cpp",
+        "src/logger.h",
         "src/opentracing_external.cpp",
         "src/propagation.cpp",
         "src/propagation.h",

include/datadog/opentracing.h

@@ -4,6 +4,7 @@
 #include <opentracing/tracer.h>
 
 #include <cmath>
+#include <iostream>
 #include <map>
 #include <set>
 
@@ -12,6 +13,17 @@ namespace ot = opentracing;
 namespace datadog {
 namespace opentracing {
 
+// Log levels used within the datadog tracer. The numberic values are arbitrary,
+// and the logging function is responsible for mapping these levels to the
+// application-specific logger's levels.
+enum class LogLevel {
+  debug = 1,
+  info = 2,
+  error = 3,
+};
+
+using LogFunc = std::function<void(LogLevel, ot::string_view)>;
+
 // The type of headers that are used for propagating distributed traces.
 // B3 headers only support 64 bit trace IDs.
 enum class PropagationStyle {
@@ -87,6 +99,24 @@ struct TracerOptions {
   // If no scheme is set in the URL, a path to a UNIX domain socket is assumed.
   // Can also be set by the environment variable DD_TRACE_AGENT_URL.
   std::string agent_url = "";
+  // A logging function that is called by the tracer when noteworthy events occur.
+  // The default value uses std::cerr, and applications can inject their own logging function.
+  LogFunc log_func = [](LogLevel level, ot::string_view message) {
+    switch (level) {
+      case LogLevel::debug:
+        std::cerr << "debug: " << message << std::endl;
+        break;
+      case LogLevel::info:
+        std::cerr << "info: " << message << std::endl;
+        break;
+      case LogLevel::error:
+        std::cerr << "error: " << message << std::endl;
+        break;
+      default:
+        std::cerr << "<unknown level>: " << message << std::endl;
+        break;
+    }
+  };
 };
 
 // TraceEncoder exposes the data required to encode and submit traces to the

src/logger.cpp

@@ -0,0 +1,62 @@
+#include "logger.h"
+
+namespace datadog {
+namespace opentracing {
+
+namespace {
+
+std::string format_message(uint64_t trace_id, ot::string_view message) {
+  return std::string("[trace_id: ") + std::to_string(trace_id) + std::string("] ") +
+         std::string(message);
+}
+
+std::string format_message(uint64_t trace_id, uint64_t span_id, ot::string_view message) {
+  return std::string("[trace_id: ") + std::to_string(trace_id) + std::string(", span_id: ") +
+         std::to_string(span_id) + std::string("] ") + std::string(message);
+}
+
+}  // namespace
+
+void StandardLogger::Log(LogLevel level, ot::string_view message) const noexcept {
+  log_func_(level, ot::string_view{message});
+}
+
+void StandardLogger::Log(LogLevel level, uint64_t trace_id, ot::string_view message) const
+    noexcept {
+  log_func_(level, ot::string_view{format_message(trace_id, message)});
+}
+
+void StandardLogger::Log(LogLevel level, uint64_t trace_id, uint64_t span_id,
+                         ot::string_view message) const noexcept {
+  log_func_(level, format_message(trace_id, span_id, message));
+}
+
+void VerboseLogger::Log(LogLevel level, ot::string_view message) const noexcept {
+  log_func_(level, message);
+}
+
+void VerboseLogger::Log(LogLevel level, uint64_t trace_id, ot::string_view message) const
+    noexcept {
+  log_func_(level, format_message(trace_id, message));
+}
+
+void VerboseLogger::Log(LogLevel level, uint64_t trace_id, uint64_t span_id,
+                        ot::string_view message) const noexcept {
+  log_func_(level, format_message(trace_id, span_id, message));
+}
+
+void VerboseLogger::Trace(ot::string_view message) const noexcept {
+  log_func_(LogLevel::debug, message);
+}
+
+void VerboseLogger::Trace(uint64_t trace_id, ot::string_view message) const noexcept {
+  log_func_(LogLevel::debug, format_message(trace_id, message));
+}
+
+void VerboseLogger::Trace(uint64_t trace_id, uint64_t span_id, ot::string_view message) const
+    noexcept {
+  log_func_(LogLevel::debug, format_message(trace_id, span_id, message));
+}
+
+}  // namespace opentracing
+}  // namespace datadog

src/logger.h

@@ -0,0 +1,55 @@
+#ifndef DD_OPENTRACING_LOGGER_H
+#define DD_OPENTRACING_LOGGER_H
+
+#include "datadog/opentracing.h"
+
+namespace datadog {
+namespace opentracing {
+
+class Logger {
+ public:
+  virtual void Log(LogLevel level, ot::string_view message) const noexcept = 0;
+  virtual void Log(LogLevel level, uint64_t trace_id, ot::string_view message) const noexcept = 0;
+  virtual void Log(LogLevel level, uint64_t trace_id, uint64_t span_id,
+                   ot::string_view message) const noexcept = 0;
+  virtual void Trace(ot::string_view message) const noexcept = 0;
+  virtual void Trace(uint64_t trace_id, ot::string_view message) const noexcept = 0;
+  virtual void Trace(uint64_t trace_id, uint64_t span_id, ot::string_view message) const
+      noexcept = 0;
+
+ protected:
+  Logger(LogFunc log_func) : log_func_(log_func) {}
+  virtual ~Logger() = default;
+  LogFunc log_func_;
+};
+
+// The standard logger provides stub implementations of Trace methods, that reduces the
+// performance hit when this level of detail is disabled.
+class StandardLogger final : public Logger {
+ public:
+  StandardLogger(LogFunc log_func) : Logger(log_func) {}
+  void Log(LogLevel level, ot::string_view message) const noexcept override;
+  void Log(LogLevel level, uint64_t trace_id, ot::string_view message) const noexcept override;
+  void Log(LogLevel level, uint64_t trace_id, uint64_t span_id, ot::string_view message) const
+      noexcept override;
+  void Trace(ot::string_view) const noexcept override {}
+  void Trace(uint64_t, ot::string_view) const noexcept override {}
+  void Trace(uint64_t, uint64_t, ot::string_view) const noexcept override {}
+};
+
+class VerboseLogger final : public Logger {
+ public:
+  VerboseLogger(LogFunc log_func) : Logger(log_func) {}
+  void Log(LogLevel level, ot::string_view message) const noexcept override;
+  void Log(LogLevel level, uint64_t trace_id, ot::string_view message) const noexcept override;
+  void Log(LogLevel level, uint64_t trace_id, uint64_t span_id, ot::string_view message) const
+      noexcept override;
+  void Trace(ot::string_view message) const noexcept override;
+  void Trace(uint64_t trace_id, ot::string_view message) const noexcept override;
+  void Trace(uint64_t trace_id, uint64_t span_id, ot::string_view message) const noexcept override;
+};
+
+}  // namespace opentracing
+}  // namespace datadog
+
+#endif  // DD_OPENTRACING_LOGGER_H

src/opentracing_external.cpp

@@ -28,9 +28,8 @@ std::tuple<std::shared_ptr<ot::Tracer>, std::shared_ptr<TraceEncoder>> makeTrace
   TracerOptions opts = maybe_options.value();
 
   auto sampler = std::make_shared<RulesSampler>();
-  auto xwriter = std::make_shared<ExternalWriter>(sampler);
-  auto encoder = xwriter->encoder();
-  std::shared_ptr<Writer> writer = xwriter;
+  auto writer = std::make_shared<ExternalWriter>(sampler);
+  auto encoder = writer->encoder();
   return std::tuple<std::shared_ptr<ot::Tracer>, std::shared_ptr<TraceEncoder>>{
       std::shared_ptr<ot::Tracer>{new Tracer{opts, writer, sampler}}, encoder};
 }

src/propagation.cpp

@@ -117,27 +117,35 @@ OptionalSamplingPriority asSamplingPriority(int i) {
   return std::make_unique<SamplingPriority>(static_cast<SamplingPriority>(i));
 }
 
-SpanContext::SpanContext(uint64_t id, uint64_t trace_id, std::string origin,
+SpanContext::SpanContext(std::shared_ptr<const Logger> logger, uint64_t id, uint64_t trace_id,
+                         std::string origin,
                          std::unordered_map<std::string, std::string> &&baggage)
-    : id_(id), trace_id_(trace_id), origin_(origin), baggage_(std::move(baggage)) {}
+    : logger_(std::move(logger)),
+      id_(id),
+      trace_id_(trace_id),
+      origin_(origin),
+      baggage_(std::move(baggage)) {}
 
 SpanContext SpanContext::NginxOpenTracingCompatibilityHackSpanContext(
-    uint64_t id, uint64_t trace_id, std::unordered_map<std::string, std::string> &&baggage) {
-  SpanContext c = SpanContext{id, trace_id, "", std::move(baggage)};
+    std::shared_ptr<const Logger> logger, uint64_t id, uint64_t trace_id,
+    std::unordered_map<std::string, std::string> &&baggage) {
+  SpanContext c = SpanContext{logger, id, trace_id, "", std::move(baggage)};
   c.nginx_opentracing_compatibility_hack_ = true;
   return c;
 }
 
 SpanContext::SpanContext(SpanContext &&other)
     : nginx_opentracing_compatibility_hack_(other.nginx_opentracing_compatibility_hack_),
-      propagated_sampling_priority_(std::move(other.propagated_sampling_priority_)),
+      logger_(other.logger_),
       id_(other.id_),
       trace_id_(other.trace_id_),
+      propagated_sampling_priority_(std::move(other.propagated_sampling_priority_)),
       origin_(other.origin_),
       baggage_(std::move(other.baggage_)) {}
 
 SpanContext &SpanContext::operator=(SpanContext &&other) {
   std::lock_guard<std::mutex> lock{mutex_};
+  logger_ = other.logger_;
   id_ = other.id_;
   trace_id_ = other.trace_id_;
   origin_ = other.origin_;
@@ -148,7 +156,8 @@ SpanContext &SpanContext::operator=(SpanContext &&other) {
 }
 
 bool SpanContext::operator==(const SpanContext &other) const {
-  if (id_ != other.id_ || trace_id_ != other.trace_id_ || baggage_ != other.baggage_ ||
+  if (logger_ != other.logger_ || id_ != other.id_ || trace_id_ != other.trace_id_ ||
+      baggage_ != other.baggage_ ||
       nginx_opentracing_compatibility_hack_ != other.nginx_opentracing_compatibility_hack_) {
     return false;
   }
@@ -214,7 +223,7 @@ std::string SpanContext::baggageItem(ot::string_view key) const {
 SpanContext SpanContext::withId(uint64_t id) const {
   std::lock_guard<std::mutex> lock{mutex_};
   auto baggage = baggage_;  // (Shallow) copy baggage.
-  SpanContext context{id, trace_id_, origin_, std::move(baggage)};
+  SpanContext context{logger_, id, trace_id_, origin_, std::move(baggage)};
   if (propagated_sampling_priority_ != nullptr) {
     context.propagated_sampling_priority_.reset(
         new SamplingPriority(*propagated_sampling_priority_));
@@ -318,7 +327,8 @@ ot::expected<void> SpanContext::serialize(const ot::TextMapWriter &writer,
   return result;
 }
 
-ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(std::istream &reader) try {
+ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(
+    std::shared_ptr<const Logger> logger, std::istream &reader) try {
   // check istream state
   if (!reader.good()) {
     return ot::make_unexpected(std::make_error_code(std::errc::io_error));
@@ -373,7 +383,8 @@ ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(std::ist
     j.at(json_baggage_key).get_to(baggage);
   }
 
-  auto context = std::make_unique<SpanContext>(parent_id, trace_id, origin, std::move(baggage));
+  auto context =
+      std::make_unique<SpanContext>(logger, parent_id, trace_id, origin, std::move(baggage));
   context->propagated_sampling_priority_ = std::move(sampling_priority);
   return std::unique_ptr<ot::SpanContext>(std::move(context));
 } catch (const json::parse_error &) {
@@ -385,10 +396,11 @@ ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(std::ist
 }
 
 ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(
-    const ot::TextMapReader &reader, std::set<PropagationStyle> styles) try {
+    std::shared_ptr<const Logger> logger, const ot::TextMapReader &reader,
+    std::set<PropagationStyle> styles) try {
   std::unique_ptr<ot::SpanContext> context = nullptr;
   for (PropagationStyle style : styles) {
-    auto result = SpanContext::deserialize(reader, propagation_headers[style]);
+    auto result = SpanContext::deserialize(logger, reader, propagation_headers[style]);
     if (!result) {
       return ot::make_unexpected(result.error());
     }
@@ -408,7 +420,8 @@ ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(
 }
 
 ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(
-    const ot::TextMapReader &reader, const HeadersImpl &headers_impl) {
+    std::shared_ptr<const Logger> logger, const ot::TextMapReader &reader,
+    const HeadersImpl &headers_impl) {
   uint64_t trace_id, parent_id;
   OptionalSamplingPriority sampling_priority = nullptr;
   std::string origin;
@@ -464,7 +477,8 @@ ot::expected<std::unique_ptr<ot::SpanContext>> SpanContext::deserialize(
     // Origin header should only be set if sampling priority is also set.
     return ot::make_unexpected(ot::span_context_corrupted_error);
   }
-  auto context = std::make_unique<SpanContext>(parent_id, trace_id, origin, std::move(baggage));
+  auto context =
+      std::make_unique<SpanContext>(logger, parent_id, trace_id, origin, std::move(baggage));
   context->propagated_sampling_priority_ = std::move(sampling_priority);
   return std::unique_ptr<ot::SpanContext>(std::move(context));
 }

src/propagation.h

@@ -6,6 +6,7 @@
 #include <mutex>
 #include <set>
 #include <unordered_map>
+#include "logger.h"
 
 namespace ot = opentracing;
 
@@ -21,6 +22,7 @@ const ot::string_view baggage_prefix = "ot-baggage-";
 std::vector<ot::string_view> getPropagationHeaderNames(const std::set<PropagationStyle> &styles,
                                                        bool prioritySamplingEnabled);
 
+class Tracer;
 class SpanBuffer;
 struct HeadersImpl;
 
@@ -47,12 +49,13 @@ OptionalSamplingPriority asSamplingPriority(int i);
 
 class SpanContext : public ot::SpanContext {
  public:
-  SpanContext(uint64_t id, uint64_t trace_id, std::string origin,
-              std::unordered_map<std::string, std::string> &&baggage);
+  SpanContext(std::shared_ptr<const Logger> logger, uint64_t id, uint64_t trace_id,
+              std::string origin, std::unordered_map<std::string, std::string> &&baggage);
 
   // Enables a hack, see the comment below on nginx_opentracing_compatibility_hack_.
   static SpanContext NginxOpenTracingCompatibilityHackSpanContext(
-      uint64_t id, uint64_t trace_id, std::unordered_map<std::string, std::string> &&baggage);
+      std::shared_ptr<const Logger> logger, uint64_t id, uint64_t trace_id,
+      std::unordered_map<std::string, std::string> &&baggage);
 
   SpanContext(SpanContext &&other);
   SpanContext &operator=(SpanContext &&other);
@@ -78,9 +81,11 @@ class SpanContext : public ot::SpanContext {
   SpanContext withId(uint64_t id) const;
 
   // Returns a new context from the given reader.
-  static ot::expected<std::unique_ptr<ot::SpanContext>> deserialize(std::istream &reader);
   static ot::expected<std::unique_ptr<ot::SpanContext>> deserialize(
-      const ot::TextMapReader &reader, std::set<PropagationStyle> styles);
+      std::shared_ptr<const Logger> tracer, std::istream &reader);
+  static ot::expected<std::unique_ptr<ot::SpanContext>> deserialize(
+      std::shared_ptr<const Logger> tracer, const ot::TextMapReader &reader,
+      std::set<PropagationStyle> styles);
 
   uint64_t id() const;
   uint64_t traceId() const;
@@ -93,7 +98,8 @@ class SpanContext : public ot::SpanContext {
 
  private:
   static ot::expected<std::unique_ptr<ot::SpanContext>> deserialize(
-      const ot::TextMapReader &reader, const HeadersImpl &headers_impl);
+      std::shared_ptr<const Logger> tracer, const ot::TextMapReader &reader,
+      const HeadersImpl &headers_impl);
   ot::expected<void> serialize(const ot::TextMapWriter &writer,
                                const std::shared_ptr<SpanBuffer> pending_traces,
                                const HeadersImpl &headers_impl,
@@ -117,10 +123,10 @@ class SpanContext : public ot::SpanContext {
   // make it more of a pain to do and less obvious what's happening.
   bool nginx_opentracing_compatibility_hack_ = false;
 
-  OptionalSamplingPriority propagated_sampling_priority_ = nullptr;
-
+  std::shared_ptr<const Logger> logger_;
   uint64_t id_;
   uint64_t trace_id_;
+  OptionalSamplingPriority propagated_sampling_priority_ = nullptr;
   std::string origin_;
 
   mutable std::mutex mutex_;