Added changes for async callback mechanism from Processor to Exporter #1252

DebajitDas · 2022-03-09T07:34:46Z

…porters

Fixes # (#1239)

Changes

Includes changes related to interface between processor to exporter such that async callback can be handled in the processor.

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

…porters

linux-foundation-easycla · 2022-03-09T07:34:49Z

The committers listed above are authorized under a signed CLA.

✅ login: DebajitDas / name: DEBAJIT DAS (29b3db7)

esigo · 2022-03-09T15:23:40Z

@DebajitDas, Thanks for the PR.
Could you please fix the CLA issue.
EDIT:
Sorry my bad it's already done.

esigo · 2022-03-09T15:27:03Z

you may use ./ci/run_docker.sh tools/format.sh for fixing the format.

codecov · 2022-03-09T16:03:17Z

Codecov Report

Merging #1252 (e99263a) into main (c96a3e3) will decrease coverage by 0.07%.
The diff coverage is 83.50%.

@@            Coverage Diff             @@
##             main    #1252      +/-   ##
==========================================
- Coverage   92.31%   92.24%   -0.06%     
==========================================
  Files         198      202       +4     
  Lines        7281     7422     +141     
==========================================
+ Hits         6721     6846     +125     
- Misses        560      576      +16

Impacted Files	Coverage Δ
...lemetry/exporters/memory/in_memory_span_exporter.h	`75.00% <0.00%> (-16.30%)`	⬇️
...de/opentelemetry/exporters/ostream/span_exporter.h	`100.00% <ø> (ø)`
exporters/ostream/src/span_exporter.cc	`87.26% <0.00%> (-3.56%)`	⬇️
...nclude/opentelemetry/ext/http/client/http_client.h	`93.34% <ø> (ø)`
sdk/include/opentelemetry/sdk/trace/exporter.h	`100.00% <ø> (ø)`
sdk/test/trace/simple_processor_test.cc	`77.42% <0.00%> (-8.29%)`	⬇️
...include/opentelemetry/sdk/trace/simple_processor.h	`86.96% <57.15%> (-13.04%)`	⬇️
...ntelemetry/ext/http/client/curl/http_client_curl.h	`92.31% <75.00%> (ø)`
sdk/src/trace/batch_span_processor.cc	`93.58% <95.84%> (+0.56%)`	⬆️
ext/test/http/curl_http_test.cc	`95.09% <100.00%> (-0.07%)`	⬇️
... and 9 more

lalitb · 2022-03-10T00:14:28Z

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

@@ -143,19 +143,19 @@ class Session : public opentelemetry::ext::http::client::Session
  }

  virtual void SendRequest(
-      opentelemetry::ext::http::client::EventHandler &callback) noexcept override
+      std::shared_ptr<opentelemetry::ext::http::client::EventHandler> callback) noexcept override


Can we transfer the callback ownership to http_client using unique_ptr, if that helps avoid shared_ptr during the hot path of request processing?

Moving the callback ownership to http_client, would involve storing the unique_ptr to some kind of map (similar to session) and clearing the entry in the map when the async thread completes. But I could not figure out the simplest way to let know http_client that the async thread is completed and map needs to be cleaned. However, cleanup could be achieved by running a separate cleanup thread which cleans up on getting notified by async thread.

Do you have anything else in mind?

The other approach I was thinking was to move the ownership to the lambda function defined in Session::SendRequest, because this lambda function would run in async thread and callback should be valid till lambda function ends. This could have been doable in C++14 as it supports std::move in lambda capture. But I could not think of achieving the same in C++11.

Also, since we have maintained two versions of Export implementation in es_log_exporter.cc, the scope of Export outlives the async thread and in another version the async thread outlives the scope of Export, unique_ptr needs to outlive both of them.

Let me know your thoughts.

I was thinking whether to add a background thread for curl::HttpClient to deal with resources of async HTTP call before we have a global event loop.
We will also need a thread to call curl_multi_perform when I start to implement the real async version of curl::Session::SendRequest.
With a background worker thread. I think we can allocate the unique_ptr on stack in sync Export and move it into the background worker thread in the async Export.

This could have been doable in C++14 as it supports std::move in lambda capture. But I could not think of achieving the same in C++11.

We can use parameter to move unique_ptr in C++11. Here is a example https://godbolt.org/z/T5sG7K9fn

We can use parameter to move unique_ptr in C++11. Here is a example https://godbolt.org/z/T5sG7K9fn

Thanks @owent for sharing this.

Also, since we have maintained two versions of Export implementation in es_log_exporter.cc, the scope of Export outlives the async thread and in another version the async thread outlives the scope of Export, unique_ptr needs to outlive both of them.

@owent But according to above reasoning, I think we can start with shared_ptr for now.

lalitb · 2022-03-10T00:18:06Z

exporters/zipkin/src/zipkin_exporter.cc

+  nostd::function_ref<bool(sdk::common::ExportResult)> result_callback)
+  noexcept
+{
+


For exporters not supporting async, we can internally have these methods call sync interface along with logging a warning. Something like:

void ZipkinExporter::Export( const nostd::span<std::unique_ptr<sdk::trace::Recordable>> &spans, nostd::function_ref<bool(sdk::common::ExportResult)> result_callback) noexcept { log_warning("async not supported. Making sync interface call"); auto status = Export(spans); result_callback(status); }

Added as per review comments.

lalitb · 2022-03-11T07:45:28Z

sdk/src/logs/batch_log_processor.cc

@@ -151,19 +153,28 @@ void BatchLogProcessor::Export(const bool was_force_flush_called)
                      return true;
                    });
                  });
+  if (is_export_async_ == false || was_force_flush_called == true) {


I think async export should also be called in case of force flush. The callback should do the notify in that case?

Agreed on force flush. What is your thoughts in case of Shutdown?
Since shutdown is called during destructor, do we need use async export during shutdown.

Since shutdown is called during destructor, do we need use async export during shutdown.

Yes, we should do async export always if the user has selected that option irrespective of shutdown or force-flush. Do you see any issue doing that?

Shouldn't we wait util all data to be exported when we call ForceFlush or Shutdown when in async mode?

Agreed @owent, we should wait.

I have create #1274 to merge "Cocurrency otlp http session" into async-changes .

Hi @owent, I have raised #1275, but how do we want to proceed? Shall I go merge my changes first?

@lalitb Could you please review #1274 or #1275 and merge any of them into async-changes first. And then we can continue to rebase the other one.
@DebajitDas I think it's fine to merge any of these two PRs first.

Sure, have merged #1274. Looks like need to fix the conflict for #1275 to merge that.

Resolved conflict on #1275. Please let me know if this can be merged. @lalitb

lalitb · 2022-03-11T07:49:03Z

sdk/include/opentelemetry/sdk/trace/batch_span_processor.h

+   * Determines whether the export happens asynchronously.
+   * Default implementation is synchronous.
+   */
+  bool is_export_async = false;


Should the async interface also added for simple_span_processor/simple_log_processor?

Agreed on this, will make the change.

owent · 2022-03-13T06:05:38Z

exporters/elasticsearch/src/es_log_exporter.cc

+        break;
+      case http_client::SessionState::NetworkError:
+        OTEL_INTERNAL_LOG_ERROR("[ES Trace Exporter] Network error to elasticsearch");
+        break;


Missing CreateFailed and Cancelled ? Should we add default: break; to avoid warnings?

Sure, will add this today

owent · 2022-03-13T06:11:17Z

exporters/otlp/src/otlp_http_client.cc

-  std::unique_ptr<ResponseHandler> handler(new ResponseHandler(options_.console_debug));
-  session->SendRequest(*handler);
+  auto handler = std::make_shared<ResponseHandler>(options_.console_debug);
+  session->SendRequest(handler);


This is good enough by now. The async version of OtlpHttpClient is already finished in #1209 . I will rebase from this PR when it's merged.
There are also some other problems when OtlpHttpClient run on multiple threads and they are also fixed in #1209 .

ThomsonTan · 2022-03-14T17:38:55Z

exporters/elasticsearch/src/es_log_exporter.cc

+
+    // Store the body of the request
+    body_ = std::string(response.GetBody().begin(), response.GetBody().end());
+    if (body_.find("\"failed\" : 0") == std::string::npos)


Could we check response code instead of searching string to detect failure here?

I think this part of code is actually called when the response is a success ( 200 OK). The original implementor of this exporter knows best what error it is further trying to catch from the response body ( or need to look into elastic search API details). :)

ThomsonTan · 2022-03-14T17:47:30Z

exporters/elasticsearch/src/es_log_exporter.cc

+    if (body_.find("\"failed\" : 0") == std::string::npos)
+    {
+      OTEL_INTERNAL_LOG_ERROR(
+          "[ES Trace Exporter] Logs were not written to Elasticsearch correctly, response body: "


Suggested change

"[ES Trace Exporter] Logs were not written to Elasticsearch correctly, response body: "

"[ES Log Exporter] Logs were not written to Elasticsearch correctly, response body: "

Sure, will incorporate this change.

ThomsonTan · 2022-03-14T17:48:48Z

exporters/elasticsearch/src/es_log_exporter.cc

+    switch (state)
+    {
+      case http_client::SessionState::ConnectFailed:
+        OTEL_INTERNAL_LOG_ERROR("[ES Trace Exporter] Connection to elasticsearch failed");


Suggested change

OTEL_INTERNAL_LOG_ERROR("[ES Trace Exporter] Connection to elasticsearch failed");

OTEL_INTERNAL_LOG_ERROR("[ES Log Exporter] Connection to Elasticsearch failed");

And similar cases on this switch statement.

Sure, will incorporate this change.

ThomsonTan · 2022-03-14T18:39:05Z

exporters/elasticsearch/src/es_log_exporter.cc

+  nostd::function_ref<bool(opentelemetry::sdk::common::ExportResult)> result_callback_;
+
+  // A string to store the response body
+  std::string body_ = "";


Suggested change

std::string body_ = "";

std::string body_;

Utilize the default ctor which creates empty string as well.

Sure, will make the change.

ThomsonTan · 2022-03-14T18:45:35Z

exporters/elasticsearch/src/es_log_exporter.cc

+  {
+    // Append {"index":{}} before JSON body, which tells Elasticsearch to write to index specified
+    // in URI
+    body += "{\"index\" : {}}\n";


Could al the records share a single {"index":{}}?

This part of code was copied from the other Export function. The original implementer would be in better position to answer this.

owent · 2022-03-22T06:59:15Z

sdk/src/trace/batch_span_processor.cc

+  else
+  {
+    exporter_->Export(nostd::span<std::unique_ptr<Recordable>>(spans_arr.data(), spans_arr.size()),
+                      [this, was_force_flush_called](sdk::common::ExportResult result) {


Should we declare async Export of LogExporter and SpanExporter as void Export(const nostd::span<std::unique_ptr<Recordable>> &records, std::function<bool(ExportResult)>&& result_callback) noexcept override ?
These codes capture some data and this lambda object can not be destroyed before result_callback be called. We need store this result_callback some where and call it later, but with function_ref, we can not move it.

@lalitb @DebajitDas

As metioned in http://open-std.org/JTC1/SC22/WG21/docs/papers/2019/p0792r5.html , function_ref is designed as a parameter, but not for storage.

yes good point. we can't transfer ownership of function_ref.
std::function<bool(ExportResult)>&& result_callback would be right callback to use.

@DebajitDas Could you please raise another PR to modify the type of result_callback and push to async-changes? I will rebase from it merge the async version of OtlpHttpClient::Export then.

@owent Do you want me to have the storage logic also in this PR? I can do only the type change by EOD.

Raised this PR #1278 which has the changes for type change

Raised this PR #1278 which has the changes for type change

Thanks I have raise #1281 to implement async OtlpHttpExporter and OtlpHttpLogExporter. Both async and sync unit tests are also added for these two exporters.

DebajitDas · 2022-03-24T04:32:28Z

Closing this PR as the same has been merged to feature branch async-changes

[WIP] Added changes for async callback mechanism from Processor to Ex…

29b3db7

…porters

DebajitDas requested a review from a team March 9, 2022 07:34

DebajitDas added 2 commits March 9, 2022 16:32

Added otlp files

a746a98

Added batch processor changes

7e8ac32

lalitb reviewed Mar 10, 2022

View reviewed changes

Incorporated first level of review comments

c58f0cd

DebajitDas changed the title ~~[WIP] Added changes for async callback mechanism from Processor to Ex…~~ Added changes for async callback mechanism from Processor to Exporter Mar 10, 2022

lalitb reviewed Mar 11, 2022

View reviewed changes

DebajitDas mentioned this pull request Mar 11, 2022

REQUEST: New membership for <DebajitDas> open-telemetry/community#999

Closed

6 tasks

owent reviewed Mar 13, 2022

View reviewed changes

DebajitDas added 3 commits March 14, 2022 14:36

Incorporated Review Comments, Added wait on shutdown and force flush

14f0e7e

Fixing the format issue

e6ea337

Update minor nit

e99263a

ThomsonTan reviewed Mar 14, 2022

View reviewed changes

lalitb mentioned this pull request Mar 22, 2022

Add owent as an Approver #1276

Merged

3 tasks

owent reviewed Mar 22, 2022

View reviewed changes

DebajitDas closed this Mar 24, 2022

	"[ES Trace Exporter] Logs were not written to Elasticsearch correctly, response body: "
	"[ES Log Exporter] Logs were not written to Elasticsearch correctly, response body: "

	OTEL_INTERNAL_LOG_ERROR("[ES Trace Exporter] Connection to elasticsearch failed");
	OTEL_INTERNAL_LOG_ERROR("[ES Log Exporter] Connection to Elasticsearch failed");

Added changes for async callback mechanism from Processor to Exporter #1252

Added changes for async callback mechanism from Processor to Exporter #1252

Conversation

DebajitDas commented Mar 9, 2022 • edited Loading

Changes

linux-foundation-easycla bot commented Mar 9, 2022 • edited Loading

esigo commented Mar 9, 2022 • edited Loading

esigo commented Mar 9, 2022

codecov bot commented Mar 9, 2022 • edited Loading

Codecov Report

lalitb Mar 10, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

owent Mar 13, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Mar 10, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Mar 11, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Mar 11, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

owent Mar 21, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Mar 11, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Mar 14, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

owent Mar 22, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DebajitDas Mar 22, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DebajitDas commented Mar 24, 2022

DebajitDas commented Mar 9, 2022 •

edited

Loading

linux-foundation-easycla bot commented Mar 9, 2022 •

edited

Loading

esigo commented Mar 9, 2022 •

edited

Loading

codecov bot commented Mar 9, 2022 •

edited

Loading

lalitb Mar 10, 2022 •

edited

Loading

owent Mar 13, 2022 •

edited

Loading

lalitb Mar 10, 2022 •

edited

Loading

lalitb Mar 11, 2022 •

edited

Loading

lalitb Mar 11, 2022 •

edited

Loading

owent Mar 21, 2022 •

edited

Loading

lalitb Mar 11, 2022 •

edited

Loading

lalitb Mar 14, 2022 •

edited

Loading

owent Mar 22, 2022 •

edited

Loading

DebajitDas Mar 22, 2022 •

edited

Loading