Line data    Source code

       1             : #include "source/extensions/access_loggers/grpc/grpc_access_log_utils.h"
       2             : 
       3             : #include "envoy/data/accesslog/v3/accesslog.pb.h"
       4             : #include "envoy/extensions/access_loggers/grpc/v3/als.pb.h"
       5             : #include "envoy/stream_info/filter_state.h"
       6             : #include "envoy/upstream/upstream.h"
       7             : 
       8             : #include "source/common/network/utility.h"
       9             : #include "source/common/stream_info/utility.h"
      10             : #include "source/common/tracing/custom_tag_impl.h"
      11             : #include "source/common/tracing/http_tracer_impl.h"
      12             : 
      13             : namespace Envoy {
      14             : namespace Extensions {
      15             : namespace AccessLoggers {
      16             : namespace GrpcCommon {
      17             : 
      18             : namespace {
      19             : 
      20             : using namespace envoy::data::accesslog::v3;
      21             : 
      22             : // Helper function to convert from a BoringSSL textual representation of the
      23             : // TLS version to the corresponding enum value used in gRPC access logs.
      24           0 : TLSProperties_TLSVersion tlsVersionStringToEnum(const std::string& tls_version) {
      25           0 :   if (tls_version == "TLSv1") {
      26           0 :     return TLSProperties::TLSv1;
      27           0 :   } else if (tls_version == "TLSv1.1") {
      28           0 :     return TLSProperties::TLSv1_1;
      29           0 :   } else if (tls_version == "TLSv1.2") {
      30           0 :     return TLSProperties::TLSv1_2;
      31           0 :   } else if (tls_version == "TLSv1.3") {
      32           0 :     return TLSProperties::TLSv1_3;
      33           0 :   }
      34             : 
      35           0 :   return TLSProperties::VERSION_UNSPECIFIED;
      36           0 : }
      37             : 
      38             : } // namespace
      39             : 
      40             : void Utility::responseFlagsToAccessLogResponseFlags(
      41             :     envoy::data::accesslog::v3::AccessLogCommon& common_access_log,
      42           0 :     const StreamInfo::StreamInfo& stream_info) {
      43             : 
      44           0 :   static_assert(StreamInfo::ResponseFlag::LastFlag == 0x8000000,
      45           0 :                 "A flag has been added. Fix this code.");
      46             : 
      47           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::FailedLocalHealthCheck)) {
      48           0 :     common_access_log.mutable_response_flags()->set_failed_local_healthcheck(true);
      49           0 :   }
      50             : 
      51           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::NoHealthyUpstream)) {
      52           0 :     common_access_log.mutable_response_flags()->set_no_healthy_upstream(true);
      53           0 :   }
      54             : 
      55           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamRequestTimeout)) {
      56           0 :     common_access_log.mutable_response_flags()->set_upstream_request_timeout(true);
      57           0 :   }
      58             : 
      59           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::LocalReset)) {
      60           0 :     common_access_log.mutable_response_flags()->set_local_reset(true);
      61           0 :   }
      62             : 
      63           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamRemoteReset)) {
      64           0 :     common_access_log.mutable_response_flags()->set_upstream_remote_reset(true);
      65           0 :   }
      66             : 
      67           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamConnectionFailure)) {
      68           0 :     common_access_log.mutable_response_flags()->set_upstream_connection_failure(true);
      69           0 :   }
      70             : 
      71           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamConnectionTermination)) {
      72           0 :     common_access_log.mutable_response_flags()->set_upstream_connection_termination(true);
      73           0 :   }
      74             : 
      75           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamOverflow)) {
      76           0 :     common_access_log.mutable_response_flags()->set_upstream_overflow(true);
      77           0 :   }
      78             : 
      79           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::NoRouteFound)) {
      80           0 :     common_access_log.mutable_response_flags()->set_no_route_found(true);
      81           0 :   }
      82             : 
      83           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::DelayInjected)) {
      84           0 :     common_access_log.mutable_response_flags()->set_delay_injected(true);
      85           0 :   }
      86             : 
      87           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::FaultInjected)) {
      88           0 :     common_access_log.mutable_response_flags()->set_fault_injected(true);
      89           0 :   }
      90             : 
      91           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::RateLimited)) {
      92           0 :     common_access_log.mutable_response_flags()->set_rate_limited(true);
      93           0 :   }
      94             : 
      95           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UnauthorizedExternalService)) {
      96           0 :     common_access_log.mutable_response_flags()->mutable_unauthorized_details()->set_reason(
      97           0 :         envoy::data::accesslog::v3::ResponseFlags::Unauthorized::EXTERNAL_SERVICE);
      98           0 :   }
      99             : 
     100           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::RateLimitServiceError)) {
     101           0 :     common_access_log.mutable_response_flags()->set_rate_limit_service_error(true);
     102           0 :   }
     103             : 
     104           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::DownstreamConnectionTermination)) {
     105           0 :     common_access_log.mutable_response_flags()->set_downstream_connection_termination(true);
     106           0 :   }
     107             : 
     108           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamRetryLimitExceeded)) {
     109           0 :     common_access_log.mutable_response_flags()->set_upstream_retry_limit_exceeded(true);
     110           0 :   }
     111             : 
     112           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::StreamIdleTimeout)) {
     113           0 :     common_access_log.mutable_response_flags()->set_stream_idle_timeout(true);
     114           0 :   }
     115             : 
     116           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::InvalidEnvoyRequestHeaders)) {
     117           0 :     common_access_log.mutable_response_flags()->set_invalid_envoy_request_headers(true);
     118           0 :   }
     119             : 
     120           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::DownstreamProtocolError)) {
     121           0 :     common_access_log.mutable_response_flags()->set_downstream_protocol_error(true);
     122           0 :   }
     123             : 
     124           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamMaxStreamDurationReached)) {
     125           0 :     common_access_log.mutable_response_flags()->set_upstream_max_stream_duration_reached(true);
     126           0 :   }
     127             : 
     128           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::ResponseFromCacheFilter)) {
     129           0 :     common_access_log.mutable_response_flags()->set_response_from_cache_filter(true);
     130           0 :   }
     131             : 
     132           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::NoFilterConfigFound)) {
     133           0 :     common_access_log.mutable_response_flags()->set_no_filter_config_found(true);
     134           0 :   }
     135             : 
     136           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::DurationTimeout)) {
     137           0 :     common_access_log.mutable_response_flags()->set_duration_timeout(true);
     138           0 :   }
     139             : 
     140           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::UpstreamProtocolError)) {
     141           0 :     common_access_log.mutable_response_flags()->set_upstream_protocol_error(true);
     142           0 :   }
     143             : 
     144           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::NoClusterFound)) {
     145           0 :     common_access_log.mutable_response_flags()->set_no_cluster_found(true);
     146           0 :   }
     147             : 
     148           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::OverloadManager)) {
     149           0 :     common_access_log.mutable_response_flags()->set_overload_manager(true);
     150           0 :   }
     151             : 
     152           0 :   if (stream_info.hasResponseFlag(StreamInfo::ResponseFlag::DnsResolutionFailed)) {
     153           0 :     common_access_log.mutable_response_flags()->set_dns_resolution_failure(true);
     154           0 :   }
     155           0 : }
     156             : 
     157             : void Utility::extractCommonAccessLogProperties(
     158             :     envoy::data::accesslog::v3::AccessLogCommon& common_access_log,
     159             :     const Http::RequestHeaderMap& request_header, const StreamInfo::StreamInfo& stream_info,
     160             :     const envoy::extensions::access_loggers::grpc::v3::CommonGrpcAccessLogConfig& config,
     161           0 :     AccessLog::AccessLogType access_log_type) {
     162             :   // TODO(mattklein123): Populate sample_rate field.
     163           0 :   if (stream_info.downstreamAddressProvider().remoteAddress() != nullptr) {
     164           0 :     Network::Utility::addressToProtobufAddress(
     165           0 :         *stream_info.downstreamAddressProvider().remoteAddress(),
     166           0 :         *common_access_log.mutable_downstream_remote_address());
     167           0 :   }
     168           0 :   if (stream_info.downstreamAddressProvider().directRemoteAddress() != nullptr) {
     169           0 :     Network::Utility::addressToProtobufAddress(
     170           0 :         *stream_info.downstreamAddressProvider().directRemoteAddress(),
     171           0 :         *common_access_log.mutable_downstream_direct_remote_address());
     172           0 :   }
     173           0 :   if (stream_info.downstreamAddressProvider().localAddress() != nullptr) {
     174           0 :     Network::Utility::addressToProtobufAddress(
     175           0 :         *stream_info.downstreamAddressProvider().localAddress(),
     176           0 :         *common_access_log.mutable_downstream_local_address());
     177           0 :   }
     178           0 :   if (!stream_info.downstreamAddressProvider().requestedServerName().empty()) {
     179           0 :     common_access_log.mutable_tls_properties()->set_tls_sni_hostname(
     180           0 :         MessageUtil::sanitizeUtf8String(
     181           0 :             stream_info.downstreamAddressProvider().requestedServerName()));
     182           0 :   }
     183           0 :   if (!stream_info.downstreamAddressProvider().ja3Hash().empty()) {
     184           0 :     common_access_log.mutable_tls_properties()->set_ja3_fingerprint(
     185           0 :         std::string(stream_info.downstreamAddressProvider().ja3Hash()));
     186           0 :   }
     187           0 :   if (stream_info.downstreamAddressProvider().sslConnection() != nullptr) {
     188           0 :     auto* tls_properties = common_access_log.mutable_tls_properties();
     189           0 :     const Ssl::ConnectionInfoConstSharedPtr downstream_ssl_connection =
     190           0 :         stream_info.downstreamAddressProvider().sslConnection();
     191             : 
     192           0 :     auto* local_properties = tls_properties->mutable_local_certificate_properties();
     193           0 :     for (const auto& uri_san : downstream_ssl_connection->uriSanLocalCertificate()) {
     194           0 :       auto* local_san = local_properties->add_subject_alt_name();
     195           0 :       local_san->set_uri(MessageUtil::sanitizeUtf8String(uri_san));
     196           0 :     }
     197           0 :     local_properties->set_subject(
     198           0 :         MessageUtil::sanitizeUtf8String(downstream_ssl_connection->subjectLocalCertificate()));
     199             : 
     200           0 :     auto* peer_properties = tls_properties->mutable_peer_certificate_properties();
     201           0 :     for (const auto& uri_san : downstream_ssl_connection->uriSanPeerCertificate()) {
     202           0 :       auto* peer_san = peer_properties->add_subject_alt_name();
     203           0 :       peer_san->set_uri(MessageUtil::sanitizeUtf8String(uri_san));
     204           0 :     }
     205             : 
     206           0 :     peer_properties->set_subject(downstream_ssl_connection->subjectPeerCertificate());
     207           0 :     tls_properties->set_tls_session_id(
     208           0 :         MessageUtil::sanitizeUtf8String(downstream_ssl_connection->sessionId()));
     209           0 :     tls_properties->set_tls_version(
     210           0 :         tlsVersionStringToEnum(downstream_ssl_connection->tlsVersion()));
     211             : 
     212           0 :     auto* local_tls_cipher_suite = tls_properties->mutable_tls_cipher_suite();
     213           0 :     local_tls_cipher_suite->set_value(downstream_ssl_connection->ciphersuiteId());
     214           0 :   }
     215           0 :   common_access_log.mutable_start_time()->MergeFrom(
     216           0 :       Protobuf::util::TimeUtil::NanosecondsToTimestamp(
     217           0 :           std::chrono::duration_cast<std::chrono::nanoseconds>(
     218           0 :               stream_info.startTime().time_since_epoch())
     219           0 :               .count()));
     220             : 
     221           0 :   absl::optional<std::chrono::nanoseconds> dur = stream_info.requestComplete();
     222           0 :   if (dur) {
     223           0 :     common_access_log.mutable_duration()->MergeFrom(
     224           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     225           0 :   }
     226             : 
     227           0 :   StreamInfo::TimingUtility timing(stream_info);
     228           0 :   dur = timing.lastDownstreamRxByteReceived();
     229           0 :   if (dur) {
     230           0 :     common_access_log.mutable_time_to_last_rx_byte()->MergeFrom(
     231           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     232           0 :   }
     233             : 
     234           0 :   dur = timing.firstUpstreamTxByteSent();
     235           0 :   if (dur) {
     236           0 :     common_access_log.mutable_time_to_first_upstream_tx_byte()->MergeFrom(
     237           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     238           0 :   }
     239             : 
     240           0 :   dur = timing.lastUpstreamTxByteSent();
     241           0 :   if (dur) {
     242           0 :     common_access_log.mutable_time_to_last_upstream_tx_byte()->MergeFrom(
     243           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     244           0 :   }
     245             : 
     246           0 :   dur = timing.firstUpstreamRxByteReceived();
     247           0 :   if (dur) {
     248           0 :     common_access_log.mutable_time_to_first_upstream_rx_byte()->MergeFrom(
     249           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     250           0 :   }
     251             : 
     252           0 :   dur = timing.lastUpstreamRxByteReceived();
     253           0 :   if (dur) {
     254           0 :     common_access_log.mutable_time_to_last_upstream_rx_byte()->MergeFrom(
     255           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     256           0 :   }
     257             : 
     258           0 :   dur = timing.firstDownstreamTxByteSent();
     259           0 :   if (dur) {
     260           0 :     common_access_log.mutable_time_to_first_downstream_tx_byte()->MergeFrom(
     261           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     262           0 :   }
     263             : 
     264           0 :   dur = timing.lastDownstreamTxByteSent();
     265           0 :   if (dur) {
     266           0 :     common_access_log.mutable_time_to_last_downstream_tx_byte()->MergeFrom(
     267           0 :         Protobuf::util::TimeUtil::NanosecondsToDuration(dur.value().count()));
     268           0 :   }
     269             : 
     270           0 :   if (stream_info.upstreamInfo().has_value()) {
     271           0 :     const auto& upstream_info = stream_info.upstreamInfo().value().get();
     272           0 :     if (upstream_info.upstreamHost() != nullptr) {
     273           0 :       Network::Utility::addressToProtobufAddress(
     274           0 :           *upstream_info.upstreamHost()->address(),
     275           0 :           *common_access_log.mutable_upstream_remote_address());
     276           0 :       common_access_log.set_upstream_cluster(upstream_info.upstreamHost()->cluster().name());
     277           0 :     }
     278           0 :     if (upstream_info.upstreamLocalAddress() != nullptr) {
     279           0 :       Network::Utility::addressToProtobufAddress(
     280           0 :           *upstream_info.upstreamLocalAddress(),
     281           0 :           *common_access_log.mutable_upstream_local_address());
     282           0 :     }
     283           0 :     if (!upstream_info.upstreamTransportFailureReason().empty()) {
     284           0 :       common_access_log.set_upstream_transport_failure_reason(
     285           0 :           upstream_info.upstreamTransportFailureReason());
     286           0 :     }
     287           0 :   }
     288           0 :   if (!stream_info.getRouteName().empty()) {
     289           0 :     common_access_log.set_route_name(stream_info.getRouteName());
     290           0 :   }
     291           0 :   if (stream_info.attemptCount().has_value()) {
     292           0 :     common_access_log.set_upstream_request_attempt_count(stream_info.attemptCount().value());
     293           0 :   }
     294           0 :   if (stream_info.connectionTerminationDetails().has_value()) {
     295           0 :     common_access_log.set_connection_termination_details(
     296           0 :         stream_info.connectionTerminationDetails().value());
     297           0 :   }
     298             : 
     299           0 :   responseFlagsToAccessLogResponseFlags(common_access_log, stream_info);
     300           0 :   if (stream_info.dynamicMetadata().filter_metadata_size() > 0) {
     301           0 :     common_access_log.mutable_metadata()->MergeFrom(stream_info.dynamicMetadata());
     302           0 :   }
     303             : 
     304           0 :   for (const auto& key : config.filter_state_objects_to_log()) {
     305           0 :     if (!(extractFilterStateData(stream_info.filterState(), key, common_access_log))) {
     306           0 :       if (stream_info.upstreamInfo().has_value() &&
     307           0 :           stream_info.upstreamInfo()->upstreamFilterState() != nullptr) {
     308           0 :         extractFilterStateData(*(stream_info.upstreamInfo()->upstreamFilterState()), key,
     309           0 :                                common_access_log);
     310           0 :       }
     311           0 :     }
     312           0 :   }
     313             : 
     314           0 :   Tracing::ReadOnlyHttpTraceContext trace_context(request_header);
     315           0 :   Tracing::CustomTagContext ctx{trace_context, stream_info};
     316           0 :   for (const auto& custom_tag : config.custom_tags()) {
     317           0 :     const auto tag_applier = Tracing::CustomTagUtility::createCustomTag(custom_tag);
     318           0 :     tag_applier->applyLog(common_access_log, ctx);
     319           0 :   }
     320             : 
     321             :   // If the stream is not complete, then this log entry is intermediate log entry.
     322           0 :   if (!stream_info.requestComplete().has_value()) {
     323           0 :     common_access_log.set_intermediate_log_entry(true); // Deprecated field
     324           0 :   }
     325             : 
     326             :   // Set stream unique id from the stream info.
     327           0 :   if (auto provider = stream_info.getStreamIdProvider(); provider.has_value()) {
     328           0 :     common_access_log.set_stream_id(std::string(provider->toStringView().value_or("")));
     329           0 :   }
     330             : 
     331           0 :   if (const auto& bytes_meter = stream_info.getDownstreamBytesMeter(); bytes_meter != nullptr) {
     332           0 :     common_access_log.set_downstream_wire_bytes_sent(bytes_meter->wireBytesSent());
     333           0 :     common_access_log.set_downstream_wire_bytes_received(bytes_meter->wireBytesReceived());
     334           0 :   }
     335           0 :   if (const auto& bytes_meter = stream_info.getUpstreamBytesMeter(); bytes_meter != nullptr) {
     336           0 :     common_access_log.set_upstream_wire_bytes_sent(bytes_meter->wireBytesSent());
     337           0 :     common_access_log.set_upstream_wire_bytes_received(bytes_meter->wireBytesReceived());
     338           0 :   }
     339             : 
     340           0 :   common_access_log.set_access_log_type(access_log_type);
     341           0 : }
     342             : 
     343             : bool extractFilterStateData(const StreamInfo::FilterState& filter_state, const std::string& key,
     344           0 :                             envoy::data::accesslog::v3::AccessLogCommon& common_access_log) {
     345           0 :   if (auto state = filter_state.getDataReadOnlyGeneric(key); state != nullptr) {
     346           0 :     ProtobufTypes::MessagePtr serialized_proto = state->serializeAsProto();
     347           0 :     if (serialized_proto != nullptr) {
     348           0 :       auto& filter_state_objects = *common_access_log.mutable_filter_state_objects();
     349           0 :       ProtobufWkt::Any& any = filter_state_objects[key];
     350           0 :       if (dynamic_cast<ProtobufWkt::Any*>(serialized_proto.get()) != nullptr) {
     351           0 :         any.Swap(dynamic_cast<ProtobufWkt::Any*>(serialized_proto.get()));
     352           0 :       } else {
     353           0 :         any.PackFrom(*serialized_proto);
     354           0 :       }
     355           0 :     }
     356           0 :     return true;
     357           0 :   }
     358           0 :   return false;
     359           0 : }
     360             : 
     361             : } // namespace GrpcCommon
     362             : } // namespace AccessLoggers
     363             : } // namespace Extensions
     364             : } // namespace Envoy