Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[EXPORTER] Log SSL Connection Information #3113

Open
wants to merge 9 commits into
base: main
Choose a base branch
from
+117 −6
Open

[EXPORTER] Log SSL Connection Information #3113

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
ae15206
Enable curl verbose output and add debug function callback
chusitoo Oct 28, 2024
b2e4069
Fix PR pipeline errors
chusitoo Oct 28, 2024
6c07132
Minor touchup to remove trailing newline
chusitoo Oct 29, 2024
7cdf2d4
Merge branch 'main' into Log_SSL_connection_info
lalitb Oct 31, 2024
ab2c39b
Add runtime flag
chusitoo Nov 1, 2024
3be305e
Add compile-time flag
chusitoo Nov 2, 2024
78f9a0b
Adhere to code and format requirements
chusitoo Nov 2, 2024
d0b8589
Version guard for callback
chusitoo Nov 2, 2024
5dc28ab
Align with naming conventions
chusitoo Nov 2, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 6 additions & 0 deletions ext/include/opentelemetry/ext/http/client/curl/http_operation_curl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
69 changes: 68 additions & 1 deletion ext/src/http/client/curl/http_operation_curl.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"

Expand Down Expand Up @@ -569,6 +570,65 @@ 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);
}
#ifdef CURL_DEBUG
else
{
OTEL_INTERNAL_LOG_DEBUG(text_to_log);
}
#endif // CURL_DEBUG
}
#ifdef CURL_DEBUG
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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 ?

Copy link
Contributor Author

@chusitoo chusitoo Nov 5, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the clarifications.

Do not change any code then, just add a comment that CURL_DEBUG is for maintainers, and should not be used in production (information leak).

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 // CURL_DEBUG

return 0;
}

CURLcode HttpOperation::Setup()
{
if (!curl_resource_.easy_handle)
Expand All @@ -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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes WITH_CURL_LOGGING looks good to me.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

if (rc != CURLE_OK)
{
return rc;
}

rc = SetCurlPtrOption(CURLOPT_DEBUGFUNCTION,
reinterpret_cast<void *>(&HttpOperation::CurlLoggerCallback));
if (rc != CURLE_OK)
{
return rc;
Expand Down
Loading