Skip to content

ext_proc: add serializeAsProto() and serializeAsString() to support access logs #40000

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.

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

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

agrawroh
Copy link
Contributor

@agrawroh agrawroh commented Jun 23, 2025

Description

This PR adds an override for serializeAsProto() and serializeAsString() to support ExtProcLoggingInfo in the access logs. After this change we should be able to do this to log the filter state emitted from ExtProc filter to measure latencies.

access_log:
  - name: envoy.access_loggers.stdout
    typed_config:
      "@type": type.googleapis.com/envoy.extensions.access_loggers.stream.v3.StdoutAccessLog
      log_format:
        json_format:
          ext_proc_plain: "%FILTER_STATE(envoy.filters.http.ext_proc:PLAIN)%"
          ext_proc_typed: "%FILTER_STATE(envoy.filters.http.ext_proc:TYPED)%"
          ext_proc_field: "%FILTER_STATE(envoy.filters.http.ext_proc:FIELD:inbound_header_latency_us)%" 

Fix #39999


Commit Message: ext_proc: add serializeAsProto() and serializeAsString() to support access logs
Additional Description: Added support for logging ExtProcLoggingInfo emitted by ExtProc from access logs
Risk Level: Low
Testing: Added Unit/Integration Tests
Docs Changes: N/A
Release Notes: N/A

Copy link

As a reminder, PRs marked as draft will not be automatically assigned reviewers,
or be handled by maintainer-oncall triage.

Please mark your PR as ready when you want it to be reviewed!

🐱

Caused by: #40000 was opened by agrawroh.

see: more, trace.

@agrawroh agrawroh marked this pull request as ready for review June 24, 2025 01:22
@agrawroh
Copy link
Contributor Author

@yanjunxiang-google May I please get a review from you on this as well?

if (field_name == "inbound_header_latency_us" && inbound.header_stats_) {
return static_cast<int64_t>(inbound.header_stats_->latency_.count());
}
if (field_name == "inbound_header_status" && inbound.header_stats_) {
Copy link
Contributor

Choose a reason for hiding this comment

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

Should this field named as inboud_header_call_status to be more clear?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sure, I can change it. If you have any more feedback I can club that and do a change including everything.

Copy link
Contributor

@yanavlasov yanavlasov left a comment

Choose a reason for hiding this comment

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

/wait-any

@@ -123,6 +123,164 @@ class ExtProcLoggingInfo : public Envoy::StreamInfo::FilterState::Object {
const Envoy::ProtobufWkt::Struct& filterMetadata() const { return filter_metadata_; }
const std::string& httpResponseCodeDetails() const { return http_response_code_details_; }

ProtobufTypes::MessagePtr serializeAsProto() const override {
Copy link
Contributor

Choose a reason for hiding this comment

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

I would move the function body to the .cc file to make class definition more readable.

const auto& inbound = grpcCalls(envoy::config::core::v3::TrafficDirection::INBOUND);
const auto& outbound = grpcCalls(envoy::config::core::v3::TrafficDirection::OUTBOUND);

if (field_name == "inbound_header_latency_us" && inbound.header_stats_) {
Copy link
Contributor

Choose a reason for hiding this comment

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

Are the field names to be used in the access log format? It does not look like they are documented anywhere.

@@ -123,6 +123,164 @@ class ExtProcLoggingInfo : public Envoy::StreamInfo::FilterState::Object {
const Envoy::ProtobufWkt::Struct& filterMetadata() const { return filter_metadata_; }
const std::string& httpResponseCodeDetails() const { return http_response_code_details_; }

ProtobufTypes::MessagePtr serializeAsProto() const override {
auto struct_msg = std::make_unique<ProtobufWkt::Struct>();
const auto& inbound = grpcCalls(envoy::config::core::v3::TrafficDirection::INBOUND);
Copy link
Contributor

Choose a reason for hiding this comment

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

Maybe you can directly use decoding_processor_grpc_calls_ and encoding_processor_grpc_calls_ here instead of inboud, outboud?

const auto& outbound = grpcCalls(envoy::config::core::v3::TrafficDirection::OUTBOUND);

if (inbound.header_stats_) {
(*struct_msg->mutable_fields())["inbound_header_latency_us"].set_number_value(
Copy link
Contributor

Choose a reason for hiding this comment

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

For the naming, maybe call it: request_header_latency_us, and response_header_latency_us to better aligned with naming in other places of this filter? Same as other places below.

static_cast<double>(static_cast<int>(inbound.header_stats_->call_status_)));
}
if (inbound.body_stats_) {
(*struct_msg->mutable_fields())["inbound_body_calls"].set_number_value(
Copy link
Contributor

Choose a reason for hiding this comment

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

naming: request_body_call_count, i.e, to align with the original naming to make it clearer.

static_cast<double>(inbound.body_stats_->total_latency_.count()));
(*struct_msg->mutable_fields())["inbound_body_max_latency_us"].set_number_value(
static_cast<double>(inbound.body_stats_->max_latency_.count()));
(*struct_msg->mutable_fields())["inbound_body_last_status"].set_number_value(
Copy link
Contributor

Choose a reason for hiding this comment

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

request_body_last_call_status

if (inbound.trailer_stats_) {
(*struct_msg->mutable_fields())["inbound_trailer_latency_us"].set_number_value(
static_cast<double>(inbound.trailer_stats_->latency_.count()));
(*struct_msg->mutable_fields())["inbound_trailer_status"].set_number_value(
Copy link
Contributor

Choose a reason for hiding this comment

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

request_trailer_call_status

(*struct_msg->mutable_fields())["inbound_trailer_status"].set_number_value(
static_cast<double>(static_cast<int>(inbound.trailer_stats_->call_status_)));
}
if (outbound.header_stats_) {
Copy link
Contributor

Choose a reason for hiding this comment

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

same as above

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

ExtProc ExtProcLoggingInfo is not available in access logs
3 participants