[EXPORTER] Log SSL Connection Information (open-telemetry#3113)

Author: chusitoo

CMakeLists.txt

@@ -215,6 +215,9 @@ option(
   "Whether to include gzip compression for the OTLP http exporter in the SDK"
   OFF)
 
+option(WITH_CURL_LOGGING "Whether to enable select CURL verbosity in OTel logs"
+       OFF)
+
 option(WITH_ZIPKIN "Whether to include the Zipkin exporter in the SDK" OFF)
 
 option(WITH_PROMETHEUS "Whether to include the Prometheus Client in the SDK"

exporters/otlp/src/otlp_http_client.cc

@@ -989,6 +989,7 @@ OtlpHttpClient::createSession(
   request->SetBody(body_vec);
   request->ReplaceHeader("Content-Type", content_type);
   request->ReplaceHeader("User-Agent", options_.user_agent);
+  request->EnableLogging(options_.console_debug);
 
   if (options_.compression == "gzip")
   {

ext/include/opentelemetry/ext/http/client/curl/http_client_curl.h

@@ -102,6 +102,8 @@ class Request : public opentelemetry::ext::http::client::Request
     compression_ = compression;
   }
 
+  void EnableLogging(bool is_log_enabled) noexcept override { is_log_enabled_ = is_log_enabled; }
+
 public:
   opentelemetry::ext::http::client::Method method_;
   opentelemetry::ext::http::client::HttpSslOptions ssl_options_;
@@ -111,6 +113,7 @@ class Request : public opentelemetry::ext::http::client::Request
   std::chrono::milliseconds timeout_ms_{5000};  // ms
   opentelemetry::ext::http::client::Compression compression_{
       opentelemetry::ext::http::client::Compression::kNone};
+  bool is_log_enabled_{false};
 };
 
 class Response : public opentelemetry::ext::http::client::Response

ext/include/opentelemetry/ext/http/client/curl/http_operation_curl.h

@@ -102,6 +102,12 @@ class HttpOperation
 
   static size_t ReadMemoryCallback(char *buffer, size_t size, size_t nitems, void *userp);
 
+  static int CurlLoggerCallback(const CURL * /* handle */,
+                                curl_infotype type,
+                                const char *data,
+                                size_t size,
+                                void * /* clientp */) noexcept;
+
 #if LIBCURL_VERSION_NUM >= 0x075000
   static int PreRequestCallback(void *clientp,
                                 char *conn_primary_ip,
@@ -152,7 +158,8 @@ class HttpOperation
                 // Default connectivity and response size options
                 bool is_raw_response                        = false,
                 std::chrono::milliseconds http_conn_timeout = default_http_conn_timeout,
-                bool reuse_connection                       = false);
+                bool reuse_connection                       = false,
+                bool is_log_enabled                         = false);
 
   /**
    * Destroy CURL instance
@@ -300,6 +307,8 @@ class HttpOperation
 
   const opentelemetry::ext::http::client::Compression &compression_;
 
+  const bool is_log_enabled_;
+
   // Processed response headers and body
   long response_code_;
   std::vector<uint8_t> response_headers_;

ext/include/opentelemetry/ext/http/client/http_client.h

@@ -245,6 +245,8 @@ class Request
 
   virtual void SetCompression(const Compression &compression) noexcept = 0;
 
+  virtual void EnableLogging(bool is_log_enabled) noexcept = 0;
+
   virtual ~Request() = default;
 };
 

ext/src/http/client/curl/CMakeLists.txt

@@ -24,6 +24,11 @@ else()
     PRIVATE ${CURL_LIBRARIES})
 endif()
 
+if(WITH_CURL_LOGGING)
+  target_compile_definitions(opentelemetry_http_client_curl
+                             PRIVATE ENABLE_CURL_LOGGING)
+endif()
+
 if(WITH_OTLP_HTTP_COMPRESSION)
   if(TARGET ZLIB::ZLIB)
     target_link_libraries(

ext/src/http/client/curl/http_client_curl.cc

@@ -116,10 +116,10 @@ void Session::SendRequest(
 #endif
   }
 
-  curl_operation_.reset(new HttpOperation(http_request_->method_, url, http_request_->ssl_options_,
-                                          callback_ptr, http_request_->headers_,
-                                          http_request_->body_, http_request_->compression_, false,
-                                          http_request_->timeout_ms_, reuse_connection));
+  curl_operation_.reset(new HttpOperation(
+      http_request_->method_, url, http_request_->ssl_options_, callback_ptr,
+      http_request_->headers_, http_request_->body_, http_request_->compression_, false,
+      http_request_->timeout_ms_, reuse_connection, http_request_->is_log_enabled_));
   bool success =
       CURLE_OK == curl_operation_->SendAsync(this, [this, callback](HttpOperation &operation) {
         if (operation.WasAborted())

ext/src/http/client/curl/http_operation_curl.cc

@@ -22,6 +22,7 @@
 #include "opentelemetry/ext/http/client/curl/http_client_curl.h"
 #include "opentelemetry/ext/http/client/curl/http_operation_curl.h"
 #include "opentelemetry/ext/http/client/http_client.h"
+#include "opentelemetry/nostd/string_view.h"
 #include "opentelemetry/sdk/common/global_log_handler.h"
 #include "opentelemetry/version.h"
 
@@ -261,7 +262,8 @@ HttpOperation::HttpOperation(opentelemetry::ext::http::client::Method method,
                              // Default connectivity and response size options
                              bool is_raw_response,
                              std::chrono::milliseconds http_conn_timeout,
-                             bool reuse_connection)
+                             bool reuse_connection,
+                             bool is_log_enabled)
     : is_aborted_(false),
       is_finished_(false),
       is_cleaned_(false),
@@ -281,6 +283,7 @@ HttpOperation::HttpOperation(opentelemetry::ext::http::client::Method method,
       request_nwrite_(0),
       session_state_(opentelemetry::ext::http::client::SessionState::Created),
       compression_(compression),
+      is_log_enabled_(is_log_enabled),
       response_code_(0)
 {
   /* get a curl handle */
@@ -569,8 +572,77 @@ CURLcode HttpOperation::SetCurlOffOption(CURLoption option, curl_off_t value)
   return rc;
 }
 
+int HttpOperation::CurlLoggerCallback(const CURL * /* handle */,
+                                      curl_infotype type,
+                                      const char *data,
+                                      size_t size,
+                                      void * /* clientp */) noexcept
+{
+  nostd::string_view text_to_log{data, size};
+
+  if (!text_to_log.empty() && text_to_log[size - 1] == '\n')
+  {
+    text_to_log = text_to_log.substr(0, size - 1);
+  }
+
+  if (type == CURLINFO_TEXT)
+  {
+    static const auto kTlsInfo    = nostd::string_view("SSL connection using");
+    static const auto kFailureMsg = nostd::string_view("Recv failure:");
+
+    if (text_to_log.substr(0, kTlsInfo.size()) == kTlsInfo)
+    {
+      OTEL_INTERNAL_LOG_INFO(text_to_log);
+    }
+    else if (text_to_log.substr(0, kFailureMsg.size()) == kFailureMsg)
+    {
+      OTEL_INTERNAL_LOG_ERROR(text_to_log);
+    }
+// This guard serves as a catch-all block for all other less interesting output that should
+// remain available for maintainer internal use and for debugging purposes only.
+#ifdef OTEL_CURL_DEBUG
+    else
+    {
+      OTEL_INTERNAL_LOG_DEBUG(text_to_log);
+    }
+#endif  // OTEL_CURL_DEBUG
+  }
+// Same as above, this guard is meant only for internal use by maintainers, and should not be used
+// in production (information leak).
+#ifdef OTEL_CURL_DEBUG
+  else if (type == CURLINFO_HEADER_OUT)
+  {
+    static const auto kHeaderSent = nostd::string_view("Send header => ");
+
+    while (!text_to_log.empty() && !std::iscntrl(text_to_log[0]))
+    {
+      const auto pos = text_to_log.find('\n');
+
+      if (pos != nostd::string_view::npos)
+      {
+        OTEL_INTERNAL_LOG_DEBUG(kHeaderSent << text_to_log.substr(0, pos - 1));
+        text_to_log = text_to_log.substr(pos + 1);
+      }
+    }
+  }
+  else if (type == CURLINFO_HEADER_IN)
+  {
+    static const auto kHeaderRecv = nostd::string_view("Recv header => ");
+    OTEL_INTERNAL_LOG_DEBUG(kHeaderRecv << text_to_log);
+  }
+#endif  // OTEL_CURL_DEBUG
+
+  return 0;
+}
+
 CURLcode HttpOperation::Setup()
 {
+#ifdef ENABLE_CURL_LOGGING
+  static constexpr auto kEnableCurlLogging = true;
+#else
+  static constexpr auto kEnableCurlLogging = false;
+#endif  // ENABLE_CURL_LOGGING
+
   if (!curl_resource_.easy_handle)
   {
     return CURLE_FAILED_INIT;
@@ -581,11 +653,28 @@ CURLcode HttpOperation::Setup()
   curl_error_message_[0] = '\0';
   curl_easy_setopt(curl_resource_.easy_handle, CURLOPT_ERRORBUFFER, curl_error_message_);
 
+// Support for custom debug function callback was added in version 7.9.6 so we guard against
+// exposing the default CURL output by keeping verbosity always disabled in lower versions.
+#if LIBCURL_VERSION_NUM < CURL_VERSION_BITS(7, 9, 6)
   rc = SetCurlLongOption(CURLOPT_VERBOSE, 0L);
   if (rc != CURLE_OK)
   {
     return rc;
   }
+#else
+  rc = SetCurlLongOption(CURLOPT_VERBOSE, (is_log_enabled_ && kEnableCurlLogging) ? 1L : 0L);
+  if (rc != CURLE_OK)
+  {
+    return rc;
+  }
+
+  rc = SetCurlPtrOption(CURLOPT_DEBUGFUNCTION,
+                        reinterpret_cast<void *>(&HttpOperation::CurlLoggerCallback));
+  if (rc != CURLE_OK)
+  {
+    return rc;
+  }
+#endif
 
   // Specify target URL
   rc = SetCurlStrOption(CURLOPT_URL, url_.c_str());

test_common/include/opentelemetry/test_common/ext/http/client/nosend/http_client_nosend.h

@@ -69,6 +69,8 @@ class Request : public opentelemetry::ext::http::client::Request
     compression_ = compression;
   }
 
+  void EnableLogging(bool is_log_enabled) noexcept override { is_log_enabled_ = is_log_enabled; }
+
 public:
   opentelemetry::ext::http::client::Method method_;
   opentelemetry::ext::http::client::HttpSslOptions ssl_options_;
@@ -78,6 +80,7 @@ class Request : public opentelemetry::ext::http::client::Request
   std::chrono::milliseconds timeout_ms_{5000};  // ms
   opentelemetry::ext::http::client::Compression compression_{
       opentelemetry::ext::http::client::Compression::kNone};
+  bool is_log_enabled_{false};
 };
 
 class Response : public opentelemetry::ext::http::client::Response