OTel AccessLogger: support log_written/dropped for OTel partial rejected log records #34072

TAOXUY · 2024-05-10T06:08:50Z

This PR makes the OTel access logger to support log_written/log_dropped tracking

failed gRPC requests
partial rejected log entries, which is supported by OTel protocol

Context:

After Change OpenTelemetry grpc access logger to use unary RPCs rather than streaming #24268, OTel AccessLogger uses unary async client.
The current log_written/log_dropped tracked in GrpcAccessLogger doesn't make sense for unary gRPC client, which always increment log_written for each incoming log entry. It couldn't record the 2 cases mentioned above.

What this PR contains:

move grpc access loggers clients to a new file and make them DI for GrpcAccessLogger
for unary async case, move log_written/log_dropped from GrpcAccessLogger to OpenTelemetry::GrpcAccessLoggerImpl while no changes for streaming case.
add an AsyncUnaryRequestCallbacks so that it can record the number of log entries on the fly and record correctly in the callback

Signed-off-by: Xuyang Tao <taoxuy@google.com>

phlax · 2024-05-10T09:22:26Z

could you take a look at the format error please @TAOXUY

ERROR: ./source/extensions/access_loggers/common/grpc_access_logger.h:108: Don't use std::optional; use absl::optional instead

https://dev.azure.com/cncf/envoy/_build/results?buildId=170151&view=logs&j=c7de00aa-b0fb-52ba-707b-da6afd918eda&t=449299ab-9da3-5c6b-afe3-e0c5dbf1dfd1&l=58

Signed-off-by: Xuyang Tao <taoxuy@google.com>

TAOXUY · 2024-05-10T15:13:35Z

could you take a look at the format error please @TAOXUY
ERROR: ./source/extensions/access_loggers/common/grpc_access_logger.h:108: Don't use std::optional; use absl::optional instead
https://dev.azure.com/cncf/envoy/_build/results?buildId=170151&view=logs&j=c7de00aa-b0fb-52ba-707b-da6afd918eda&t=449299ab-9da3-5c6b-afe3-e0c5dbf1dfd1&l=58

Done. Thank!

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov

/wait-any

source/extensions/access_loggers/common/grpc_access_logger_clients.h

wbpcode · 2024-05-14T02:27:07Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

+              [this, &dispatcher]() {
+                // It will be deleted in the callbacks.
+                auto* callback = new OTelLogRequestCallbacks(dispatcher, this->stats_,
+                                                             this->batched_log_entries_);
+                this->batched_log_entries_ = 0;
+                return callback;


Rather then create a self-management request callbacks object, I prefer to manage all these pending requests in the unary client directly. And the unary client should provide a way to let the specific implementation to provide a callbacks.
Then things would be simpler and the lifetime of these objects would be more clear.

Hi @wbpcode , could you please explain which class owns what and how the deletion works in your mind? Thanks

I will assume the unary client will maintains a set of pending requests in a flat_hash_map. The request pointer (returned by the send()) will be used as the key. And the value is a simple wrapper that like current OTelLogRequestCallbacks. The wrapper will delegate the callback calling to the unary client to remove itself from the map and execute some logic that specified by the specific logger.
Then when the unary client self is destroyed, it will cancel all pending requests to ensure no any further logic will be executed. (This is the key difference)

Thanks for the suggestion! DONE!

PTAL @wbpcode @yanavlasov

Thanks for your quick response and hard work. But I think the most important point still doesn't be resolved.

Then when the unary client self is destroyed, it will cancel all pending requests to ensure no any further logic will be executed. (This is the key difference)

See, the pending requests will still be pending when the client is destroyed and the pending requests may use dangling reference to the callbacks objects or dangling reference to the client stats.

Thanks!

You are talking about the potential issues: the ongoing stream access the deleted callback/stats owned under GrpcAccessLoggerImpl.

I think in theory it shouldn't happen because GrpcAccessLoggerImpl as common::GrpcAccessLoggerowns the AsyncClientImpl , holding the AsyncStream. So when GrpcAccessLoggerImpl is destructed, all the active streams should be destructed as well and there won't be callbacks in this case.

I did a quick check to the source code of grpc client. Yeah, all active streams will be destroyed automatically. But seems you still need to call the cancel() explicitly to reset underlying http request, needn't it?
(Will do a deeper check tomorrow in case I miss something)

When AsyncStreamImpl get destructed, it will reset the underlying http stream.

envoy/source/common/grpc/async_client_impl.cc

Lines 35 to 39 in 1ae1aa9

ASSERT(isThreadSafe());

while (!active_streams_.empty()) {

active_streams_.front()->resetStream();

}

}

envoy/source/common/grpc/async_client_impl.cc

Lines 237 to 241 in 1ae1aa9

if (!http_reset_) {

http_reset_ = true;

stream_->reset();

}

Thanks for the confirmation. It makes sense. Seems my previous comments are based on mine incorrect knowledge.

wbpcode · 2024-05-14T02:27:24Z

/wait-any

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov

/wait

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.h

yanavlasov · 2024-05-15T17:35:34Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.h

+      : public Grpc::AsyncRequestCallbacks<
+            opentelemetry::proto::collector::logs::v1::ExportLogsServiceResponse> {
+  public:
+    OTelLogRequestCallbacks(Envoy::Event::Dispatcher& dispatcher,


Is dispatcher still needed?

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.h

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov

/wait

yanavlasov · 2024-05-15T19:32:28Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

+        this->stats_, this->batched_log_entries_,
+        [this](OTelLogRequestCallbacks* p) { this->callbacks_.erase(p); });
+    this->batched_log_entries_ = 0;
+    this->callbacks_.emplace(ptr, ptr);


I think this should crash in non optimized builds. ptr is not a valid iterator position in callbacks_

Hi Yan, I think emplace(ptr, ptr) treats the first argument as the key and the second argument to construct a unique_ptr as value. I don't know why you think it won't work?

Oh sorry. I did not realize you were using hash map. Please disregard.

yanavlasov · 2024-05-15T19:33:52Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

+  return [this]() {
+    OTelLogRequestCallbacks* ptr = new OTelLogRequestCallbacks(
+        this->stats_, this->batched_log_entries_,
+        [this](OTelLogRequestCallbacks* p) { this->callbacks_.erase(p); });


I do not think you can do it this way. You need to first find p in callbacks_ and then delete at the iterator if it was found.

Are you asking about:

this API doesn't work?

or we need to do a sanity check on the existence?

For 1), it should work. absl::flat_hash_map has the api to directly remove the key
For 2), I just added the sanity check in case it is called twice.

yanavlasov · 2024-05-15T19:34:54Z

source/extensions/access_loggers/common/grpc_access_logger_clients.h

+template <typename LogRequest, typename LogResponse>
+class UnaryGrpcAccessLogClient : public GrpcAccessLogClient<LogRequest, LogResponse> {
+public:
+  typedef std::function<Grpc::AsyncRequestCallbacks<LogResponse>*()> AsyncRequestCallbacksFactory;


I think now you can make the factory return std::unique_ptr. This will indicate that there is an owner for the object.

We are letting OpenTelemetry::GrpcAccessLoggerImpl to owns the callback so we only need to return pointer/reference?

Ok, I see how you did it. I would just return reference instead of pointer then to signify that the callback object is owned elsewhere.

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov

LGTM with a few minor comment.

yanavlasov · 2024-05-16T13:35:37Z

source/extensions/access_loggers/common/grpc_access_logger_clients.h

+template <typename LogRequest, typename LogResponse>
+class UnaryGrpcAccessLogClient : public GrpcAccessLogClient<LogRequest, LogResponse> {
+public:
+  typedef std::function<Grpc::AsyncRequestCallbacks<LogResponse>*()> AsyncRequestCallbacksFactory;


Ok, I see how you did it. I would just return reference instead of pointer then to signify that the callback object is owned elsewhere.

yanavlasov · 2024-05-16T13:36:33Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

+        this->stats_, this->batched_log_entries_,
+        [this](OTelLogRequestCallbacks* p) { this->callbacks_.erase(p); });
+    this->batched_log_entries_ = 0;
+    this->callbacks_.emplace(ptr, ptr);


Oh sorry. I did not realize you were using hash map. Please disregard.

yanavlasov · 2024-05-16T13:37:25Z

source/extensions/access_loggers/open_telemetry/grpc_access_log_impl.cc

+std::function<GrpcAccessLoggerImpl::OTelLogRequestCallbacks*()>
+GrpcAccessLoggerImpl::genOTelCallbacksFactory() {
+  return [this]() {
+    OTelLogRequestCallbacks* ptr = new OTelLogRequestCallbacks(


I would use std::make_unique here to make it more idiomatic C++.

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov · 2024-05-16T17:28:06Z

The change does not build: https://source.cloud.google.com/results/invocations/53d8338b-909c-4f57-b0d7-e4bfd267524c

yanavlasov · 2024-05-16T17:28:09Z

/wait

Signed-off-by: Xuyang Tao <taoxuy@google.com>

TAOXUY · 2024-05-16T17:39:30Z

Details

Fixed.

inital code

eebe5a0

Signed-off-by: Xuyang Tao <taoxuy@google.com>

TAOXUY requested review from wbpcode, yanavlasov and zuercher as code owners May 10, 2024 06:08

phlax assigned wbpcode May 10, 2024

fix std::optional

f1905aa

Signed-off-by: Xuyang Tao <taoxuy@google.com>

TAOXUY marked this pull request as draft May 10, 2024 15:16

adjust callback

6becef9

Signed-off-by: Xuyang Tao <taoxuy@google.com>

TAOXUY marked this pull request as ready for review May 10, 2024 17:00

TAOXUY mentioned this pull request May 10, 2024

OTel Access Logger: support additional stat prefix #34091

Merged

yanavlasov reviewed May 10, 2024

View reviewed changes

source/extensions/access_loggers/common/grpc_access_logger_clients.h Outdated Show resolved Hide resolved

repokitteh-read-only bot added waiting:any and removed waiting:any labels May 10, 2024

wbpcode reviewed May 14, 2024

View reviewed changes

repokitteh-read-only bot added waiting:any and removed waiting:any labels May 14, 2024

TAOXUY added 2 commits May 14, 2024 15:53

add destructing

722bd76

Signed-off-by: Xuyang Tao <taoxuy@google.com>

add callbacks_

5522ca8

Signed-off-by: Xuyang Tao <taoxuy@google.com>

yanavlasov self-assigned this May 14, 2024

yanavlasov requested changes May 15, 2024

View reviewed changes

repokitteh-read-only bot added the waiting label May 15, 2024

fix comment

3020e40

Signed-off-by: Xuyang Tao <taoxuy@google.com>

repokitteh-read-only bot removed the waiting label May 15, 2024

yanavlasov requested changes May 15, 2024

View reviewed changes

repokitteh-read-only bot added the waiting label May 15, 2024

fix comment

9b6576f

Signed-off-by: Xuyang Tao <taoxuy@google.com>

repokitteh-read-only bot removed the waiting label May 15, 2024

yanavlasov requested changes May 16, 2024

View reviewed changes

fix comment

bf0c54c

Signed-off-by: Xuyang Tao <taoxuy@google.com>

repokitteh-read-only bot added the waiting label May 16, 2024

fix test

b989125

Signed-off-by: Xuyang Tao <taoxuy@google.com>

repokitteh-read-only bot removed the waiting label May 16, 2024

yanavlasov approved these changes May 16, 2024

View reviewed changes

yanavlasov merged commit f3613b4 into envoyproxy:main May 16, 2024
52 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OTel AccessLogger: support log_written/dropped for OTel partial rejected log records #34072

OTel AccessLogger: support log_written/dropped for OTel partial rejected log records #34072

TAOXUY commented May 10, 2024 •

edited

phlax commented May 10, 2024

TAOXUY commented May 10, 2024

yanavlasov left a comment

wbpcode May 14, 2024

TAOXUY May 14, 2024

wbpcode May 14, 2024

TAOXUY May 14, 2024

wbpcode May 15, 2024

TAOXUY May 15, 2024

wbpcode May 15, 2024

TAOXUY May 15, 2024 •

edited

wbpcode May 16, 2024

wbpcode commented May 14, 2024

yanavlasov left a comment

yanavlasov May 15, 2024

TAOXUY May 15, 2024

yanavlasov left a comment

yanavlasov May 15, 2024

TAOXUY May 15, 2024

yanavlasov May 16, 2024

yanavlasov May 15, 2024

TAOXUY May 15, 2024

yanavlasov May 15, 2024

TAOXUY May 15, 2024

yanavlasov May 16, 2024

TAOXUY May 16, 2024

yanavlasov left a comment

yanavlasov May 16, 2024

yanavlasov May 16, 2024

yanavlasov May 16, 2024

TAOXUY May 16, 2024

yanavlasov commented May 16, 2024

yanavlasov commented May 16, 2024

TAOXUY commented May 16, 2024

	ASSERT(isThreadSafe());
	while (!active_streams_.empty()) {
	active_streams_.front()->resetStream();
	}
	}

OTel AccessLogger: support log_written/dropped for OTel partial rejected log records #34072

OTel AccessLogger: support log_written/dropped for OTel partial rejected log records #34072

Conversation

TAOXUY commented May 10, 2024 • edited

phlax commented May 10, 2024

TAOXUY commented May 10, 2024

yanavlasov left a 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

TAOXUY May 15, 2024 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

wbpcode commented May 14, 2024

yanavlasov left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yanavlasov left a 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

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yanavlasov left a 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

yanavlasov commented May 16, 2024

yanavlasov commented May 16, 2024

TAOXUY commented May 16, 2024

TAOXUY commented May 10, 2024 •

edited

TAOXUY May 15, 2024 •

edited