[EXPORTER] Log SSL Connection Information #3113

chusitoo · 2024-10-28T16:36:22Z

Changes

Enable curl verbose output and add debug function callback to intercept the "interesting" logs.

This functionality is controlled by the compile-time flag/option WITH_CURL_LOGGING=ON but can also be enabled at runtime by setting OtlpHttpExporterOptions::console_debug = true.

By default, all the headers and other information are not available and protected by a compile-time flag since they could contain sensitive information.

An example of info logging related to TLS handshake, available by default:

[Info] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:593 SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / X25519 / RSASSA-PSS

An example of debug logging, enabled via -DCURL_DEBUG:

[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => POST /v1/traces HTTP/2
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => Host: localhost:4318
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => Accept: */*
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => Content-Type: application/x-protobuf
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => User-Agent: OTel-OTLP-Exporter-Cpp/1.17.0
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:613 Send header => Content-Length: 238
[Debug] File: /otel/exporters/otlp/src/otlp_http_client.cc:226 [OTLP HTTP Client] Session state: sending request
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:602 We are completely uploaded and fine
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:620 Recv header => HTTP/2 200
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:620 Recv header => content-type: application/x-protobuf
[Debug] File: /otel/ext/src/http/client/curl/http_operation_curl.cc:620 Recv header => content-length: 2

For significant contributions please make sure you have completed the following items:

CHANGELOG.md updated for non-trivial changes
Unit tests have been added
Changes in public API reviewed

netlify · 2024-10-28T16:36:40Z

✅ Deploy Preview for opentelemetry-cpp-api-docs canceled.

Name	Link
🔨 Latest commit	`5dc28ab`
🔍 Latest deploy log	https://app.netlify.com/sites/opentelemetry-cpp-api-docs/deploys/672643158eff1700080ee94c

codecov · 2024-10-28T23:01:58Z

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 87.88%. Comparing base (497eaf4) to head (5dc28ab).
Report is 151 commits behind head on main.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #3113      +/-   ##
==========================================
+ Coverage   87.12%   87.88%   +0.76%     
==========================================
  Files         200      195       -5     
  Lines        6109     6137      +28     
==========================================
+ Hits         5322     5393      +71     
+ Misses        787      744      -43

see 99 files with indirect coverage changes

lalitb · 2024-10-29T02:22:27Z

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

@@ -581,7 +641,14 @@ CURLcode HttpOperation::Setup()
  curl_error_message_[0] = '\0';
  curl_easy_setopt(curl_resource_.easy_handle, CURLOPT_ERRORBUFFER, curl_error_message_);

-  rc = SetCurlLongOption(CURLOPT_VERBOSE, 0L);
+  rc = SetCurlLongOption(CURLOPT_VERBOSE, 1L);


Setting CURLOPT_VERBOSE to 1L is useful for debugging but not sure if it's best practice to keep enabled in production, as it can significantly impact performance in high-throughput scenarios. Would it make sense to make this optional, controlled by an environment variable, configuration option, or macro?

Agreed, I think that would make sense as the general rule.

If the requirement is to expose the TLS version / cipher information in the logs, then CURLOPT_VERBOSE is absolutely required in order to use a custom debug function callback, as explained in CURLOPT_DEBUGFUNCTION

I haven't found anything obvious in terms of option switches / macros that I could repurpose for this so maybe introducing something like a WITH_CURL_LOGGING flag would be an acceptable approach.

yes WITH_CURL_LOGGING looks good to me.

I agree, we need a compile time flag like WITH_CURL_LOGGING.

A runtime flag as well, to turn the verbose logging on/off would be nice, but this can be a separate discussion and PR.

Apologies for the sudden silence, it's been a busy week so far.

I actually had this similarly implemented with a runtime flag for another project. I think I can have this done in the same PR, just need to run this through the full CI to make sure I didn't miss anything.

If both compile-time and runtime flags are to be supported, the way I see it is that runtime should take precedence as there could be certain cases where this logging info would be useful but, as a general use case, omitting it would fall back to the value set at compile time via WITH_CURL_LOGGING.

marcalff

Great work, thanks for the feature.

Reusing console_debug for this is a good idea.

See some comments or questions, with approval to follow once resolved.

marcalff · 2024-11-04T22:09:28Z

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

  rc = SetCurlLongOption(CURLOPT_VERBOSE, 0L);
  if (rc != CURLE_OK)
  {
    return rc;
  }
+#else
+  rc = SetCurlLongOption(CURLOPT_VERBOSE, static_cast<long>(is_log_enabled_ || kEnableCurlLogging));


Two concerns here:

not sure if casting a boolean to a long will always give 0L / 1L, so a plain if statement to set a verbose local variable will be safer

should it be is_log_enabled && kEnableCurlLogging instead ?

Regarding the explicit cast, it looked fairly safe given that the CURL API seems to only care about the value being 0 (disabled) or otherwise. Will update to a good ol' if statement, as requested.

As for the logic, my impression was that we wanted to have the runtime drive this behavior regardless of what is set at compile-time, but if omitting console_debug, it would still output logs provided WITH_CURL_LOGGING option was set.

If, what is ultimately needed is that the compile-time flag dictate the runtime behavior, then I guess it would need to be AND'ed, instead.

Let me know what is the preferred approach with respect to the above and I will push all the required changes at the same time.

marcalff · 2024-11-04T22:18:16Z

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

+    }
+#endif  // CURL_DEBUG
+  }
+#ifdef CURL_DEBUG


Please clarify (with a comment) the intent of CURL_DEBUG, which is separate from ENABLE_CURL_LOGGING.

As I understand it, ENABLE_CURL_LOGGING is exposed in CMake, to add the new logging feature.

On top of that, CURL_DEBUG seem to be a private developer flag (not exposed in cmake), for a developper to debug the new logging feature itself, if needed.

So, ENABLE_CURL_LOGGING may be used optionally in production, but CURL_DEBUG should not be used in production.

Is this accurate ?

That is correct, CURL_DEBUG is a guard that comes in handy when debugging something, where the full verbosity would be required. However, making it controllable by the user is probably not desirable as it could lead to unintentionally logging too much / sensitive information, such as request body, auth tokens, other sensitive in/out headers, etc.

That said, though, if this is deemed necessary by future requirements, exposing additional logging should be as simple as "punching" a few more holes in the callback function, by simply adding the respective if / else if statements outside this guarded block.

So, in a way, the second use of CURL_DEBUG is to force the developer to have to explicitly opt-in for exposing more logging info from CURL, which hopefully also makes it easy to see what information the callback function is letting out into the wild.

chusitoo changed the title ~~Enable curl verbose output and add debug function callback~~ [EXPORTER] Log SSL Connection Information Oct 28, 2024

chusitoo added 2 commits October 28, 2024 18:36

Enable curl verbose output and add debug function callback

ae15206

Fix PR pipeline errors

b2e4069

chusitoo force-pushed the Log_SSL_connection_info branch from 2b36b33 to b2e4069 Compare October 28, 2024 22:36

chusitoo marked this pull request as ready for review October 29, 2024 00:05

chusitoo requested a review from a team as a code owner October 29, 2024 00:05

Minor touchup to remove trailing newline

6c07132

lalitb reviewed Oct 29, 2024

View reviewed changes

lalitb and others added 6 commits October 31, 2024 10:29

Merge branch 'main' into Log_SSL_connection_info

7cdf2d4

Add runtime flag

ab2c39b

Add compile-time flag

3be305e

Adhere to code and format requirements

78f9a0b

Version guard for callback

d0b8589

Align with naming conventions

5dc28ab

marcalff reviewed Nov 4, 2024

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[EXPORTER] Log SSL Connection Information #3113

[EXPORTER] Log SSL Connection Information #3113

chusitoo commented Oct 28, 2024 •

edited

Loading

netlify bot commented Oct 28, 2024 •

edited

Loading

codecov bot commented Oct 28, 2024 •

edited

Loading

lalitb Oct 29, 2024

chusitoo Oct 29, 2024

lalitb Oct 29, 2024

marcalff Oct 30, 2024

chusitoo Nov 1, 2024

marcalff left a comment

marcalff Nov 4, 2024

chusitoo Nov 5, 2024 •

edited

Loading

marcalff Nov 4, 2024

chusitoo Nov 5, 2024 •

edited

Loading

[EXPORTER] Log SSL Connection Information #3113

Are you sure you want to change the base?

[EXPORTER] Log SSL Connection Information #3113

Conversation

chusitoo commented Oct 28, 2024 • edited Loading

Changes

netlify bot commented Oct 28, 2024 • edited Loading

✅ Deploy Preview for opentelemetry-cpp-api-docs canceled.

codecov bot commented Oct 28, 2024 • edited Loading

Codecov Report

lalitb Oct 29, 2024

Choose a reason for hiding this comment

chusitoo Oct 29, 2024

Choose a reason for hiding this comment

lalitb Oct 29, 2024

Choose a reason for hiding this comment

marcalff Oct 30, 2024

Choose a reason for hiding this comment

chusitoo Nov 1, 2024

Choose a reason for hiding this comment

marcalff left a comment

Choose a reason for hiding this comment

marcalff Nov 4, 2024

Choose a reason for hiding this comment

chusitoo Nov 5, 2024 • edited Loading

Choose a reason for hiding this comment

marcalff Nov 4, 2024

Choose a reason for hiding this comment

chusitoo Nov 5, 2024 • edited Loading

Choose a reason for hiding this comment

chusitoo commented Oct 28, 2024 •

edited

Loading

netlify bot commented Oct 28, 2024 •

edited

Loading

codecov bot commented Oct 28, 2024 •

edited

Loading

chusitoo Nov 5, 2024 •

edited

Loading

chusitoo Nov 5, 2024 •

edited

Loading