diff --git a/changelogs/current.yaml b/changelogs/current.yaml index 84efe985fce46..4422befc21150 100644 --- a/changelogs/current.yaml +++ b/changelogs/current.yaml @@ -5,6 +5,9 @@ behavior_changes: minor_behavior_changes: # *Changes that may cause incompatibilities for some users, but should not for most* +- area: quic + change: | + Access logging is now deferred to the QUIC ack listener, and roundtrip response time is added as a downstream timing metric. New runtime flag ``envoy.reloadable_features.quic_defer_logging_to_ack_listener`` can be used for revert this behavior. - area: healthcheck change: | If active HC is enabled and a host is ejected by outlier detection, a successful active health check unejects the host and consider it healthy. This also clears all the outlier detection counters. This behavior change can be reverted by setting ``envoy.reloadable_features_successful_active_health_check_uneject_host`` to ``false``. diff --git a/docs/root/configuration/observability/access_log/usage.rst b/docs/root/configuration/observability/access_log/usage.rst index f7d3e41476c80..a6fe387aa35b7 100644 --- a/docs/root/configuration/observability/access_log/usage.rst +++ b/docs/root/configuration/observability/access_log/usage.rst @@ -387,6 +387,19 @@ The following command operators are supported: Renders a numeric value in typed JSON logs. +%ROUNDTRIP_DURATION% + HTTP/3 (QUIC) + Total duration in milliseconds of the request from the start time to receiving the final ack from + the downstream. + + HTTP/1 and HTTP/2 + Not implemented ("-"). + + TCP/UDP + Not implemented ("-"). + + Renders a numeric value in typed JSON logs. + %RESPONSE_TX_DURATION% HTTP Total duration in milliseconds of the request from the first byte read from the upstream host to the last diff --git a/envoy/http/BUILD b/envoy/http/BUILD index 5c675b0e44d60..60577927c0a89 100644 --- a/envoy/http/BUILD +++ b/envoy/http/BUILD @@ -46,6 +46,7 @@ envoy_cc_library( ":metadata_interface", ":protocol_interface", ":stream_reset_handler_interface", + "//envoy/access_log:access_log_interface", "//envoy/buffer:buffer_interface", "//envoy/grpc:status", "//envoy/network:address_interface", diff --git a/envoy/http/codec.h b/envoy/http/codec.h index 236a4da6f2504..7a906210ab09d 100644 --- a/envoy/http/codec.h +++ b/envoy/http/codec.h @@ -4,6 +4,7 @@ #include #include +#include "envoy/access_log/access_log.h" #include "envoy/buffer/buffer.h" #include "envoy/common/pure.h" #include "envoy/grpc/status.h" @@ -174,6 +175,22 @@ class ResponseEncoder : public virtual StreamEncoder { * @param decoder new request decoder. */ virtual void setRequestDecoder(RequestDecoder& decoder) PURE; + + /** + * Set headers, trailers, and stream info for deferred logging. This allows HCM to hand off + * stream-level details to the codec for logging after the stream may be destroyed (e.g. on + * receiving the final ack packet from the client). Note that headers and trailers are const + * as they will not be modified after this point. + * @param request_header_map Request headers for this stream. + * @param response_header_map Response headers for this stream. + * @param response_trailer_map Response trailers for this stream. + * @param stream_info Stream info for this stream. + */ + virtual void + setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr request_header_map, + Http::ResponseHeaderMapConstSharedPtr response_header_map, + Http::ResponseTrailerMapConstSharedPtr response_trailer_map, + StreamInfo::StreamInfo& stream_info) PURE; }; /** @@ -211,7 +228,7 @@ class RequestDecoder : public virtual StreamDecoder { * @param headers supplies the decoded headers map. * @param end_stream supplies whether this is a header only request. */ - virtual void decodeHeaders(RequestHeaderMapPtr&& headers, bool end_stream) PURE; + virtual void decodeHeaders(RequestHeaderMapSharedPtr&& headers, bool end_stream) PURE; /** * Called with a decoded trailers frame. This implicitly ends the stream. @@ -236,6 +253,11 @@ class RequestDecoder : public virtual StreamDecoder { * @return StreamInfo::StreamInfo& the stream_info for this stream. */ virtual StreamInfo::StreamInfo& streamInfo() PURE; + + /** + * @return List of shared pointers to access loggers for this stream. + */ + virtual std::list accessLogHandlers() PURE; }; /** diff --git a/envoy/http/header_map.h b/envoy/http/header_map.h index 4f53c91c5696f..0c8ca1c5d706f 100644 --- a/envoy/http/header_map.h +++ b/envoy/http/header_map.h @@ -718,6 +718,8 @@ class RequestHeaderMap INLINE_REQ_NUMERIC_HEADERS(DEFINE_INLINE_NUMERIC_HEADER) }; using RequestHeaderMapPtr = std::unique_ptr; +using RequestHeaderMapSharedPtr = std::shared_ptr; +using RequestHeaderMapConstSharedPtr = std::shared_ptr; using RequestHeaderMapOptRef = OptRef; using RequestHeaderMapOptConstRef = OptRef; @@ -748,6 +750,8 @@ class ResponseHeaderMap INLINE_RESP_NUMERIC_HEADERS(DEFINE_INLINE_NUMERIC_HEADER) }; using ResponseHeaderMapPtr = std::unique_ptr; +using ResponseHeaderMapSharedPtr = std::shared_ptr; +using ResponseHeaderMapConstSharedPtr = std::shared_ptr; using ResponseHeaderMapOptRef = OptRef; using ResponseHeaderMapOptConstRef = OptRef; @@ -757,6 +761,8 @@ class ResponseTrailerMap public HeaderMap, public CustomInlineHeaderBase {}; using ResponseTrailerMapPtr = std::unique_ptr; +using ResponseTrailerMapSharedPtr = std::shared_ptr; +using ResponseTrailerMapConstSharedPtr = std::shared_ptr; using ResponseTrailerMapOptRef = OptRef; using ResponseTrailerMapOptConstRef = OptRef; diff --git a/envoy/stream_info/stream_info.h b/envoy/stream_info/stream_info.h index c4a72b3221fe5..5ce8230c3a8c2 100644 --- a/envoy/stream_info/stream_info.h +++ b/envoy/stream_info/stream_info.h @@ -285,6 +285,9 @@ class DownstreamTiming { absl::optional downstreamHandshakeComplete() const { return downstream_handshake_complete_; } + absl::optional lastDownstreamAckReceived() const { + return last_downstream_ack_received_; + } void onLastDownstreamRxByteReceived(TimeSource& time_source) { ASSERT(!last_downstream_rx_byte_received_); @@ -302,6 +305,10 @@ class DownstreamTiming { // An existing value can be overwritten, e.g. in resumption case. downstream_handshake_complete_ = time_source.monotonicTime(); } + void onLastDownstreamAckReceived(TimeSource& time_source) { + ASSERT(!last_downstream_ack_received_); + last_downstream_ack_received_ = time_source.monotonicTime(); + } private: absl::flat_hash_map timings_; @@ -313,6 +320,8 @@ class DownstreamTiming { absl::optional last_downstream_tx_byte_sent_; // The time the TLS handshake completed. Set at connection level. absl::optional downstream_handshake_complete_; + // The time the final ack was received from the client. + absl::optional last_downstream_ack_received_; }; // Measure the number of bytes sent and received for a stream. diff --git a/mobile/library/common/http/client.h b/mobile/library/common/http/client.h index 4a2d459df034c..1b6329a459680 100644 --- a/mobile/library/common/http/client.h +++ b/mobile/library/common/http/client.h @@ -164,6 +164,10 @@ class Client : public Logger::Loggable { } bool streamErrorOnInvalidHttpMessage() const override { return false; } void setRequestDecoder(RequestDecoder& /*decoder*/) override{}; + void setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr, + Http::ResponseHeaderMapConstSharedPtr, + Http::ResponseTrailerMapConstSharedPtr, + StreamInfo::StreamInfo&) override {} void encodeMetadata(const MetadataMapVector&) override { PANIC("not implemented"); } diff --git a/source/common/formatter/substitution_formatter.cc b/source/common/formatter/substitution_formatter.cc index 5313790f661d6..9f781e31a868b 100644 --- a/source/common/formatter/substitution_formatter.cc +++ b/source/common/formatter/substitution_formatter.cc @@ -487,6 +487,17 @@ SubstitutionFormatParser::getKnownFormatters() { {CommandSyntaxChecker::PARAMS_REQUIRED | CommandSyntaxChecker::LENGTH_ALLOWED, [](const std::string& key, absl::optional& max_length) { return std::make_unique(key, max_length); + }}}, + {"STREAM_INFO_REQ", + {CommandSyntaxChecker::PARAMS_REQUIRED | CommandSyntaxChecker::LENGTH_ALLOWED, + [](const std::string& format, absl::optional& max_length) { + std::string main_header, alternative_header; + + SubstitutionFormatParser::parseSubcommandHeaders(format, main_header, + alternative_header); + + return std::make_unique(main_header, alternative_header, + max_length); }}}}); } @@ -913,6 +924,15 @@ const StreamInfoFormatter::FieldExtractorLookupTbl& StreamInfoFormatter::getKnow return timing.downstreamHandshakeComplete(); }); }}}, + {"ROUNDTRIP_DURATION", + {CommandSyntaxChecker::COMMAND_ONLY, + [](const std::string&, const absl::optional&) { + return std::make_unique( + [](const StreamInfo::StreamInfo& stream_info) { + StreamInfo::TimingUtility timing(stream_info); + return timing.lastDownstreamAckReceived(); + }); + }}}, {"BYTES_RECEIVED", {CommandSyntaxChecker::COMMAND_ONLY, [](const std::string&, const absl::optional&) { @@ -2183,5 +2203,22 @@ ProtobufWkt::Value EnvironmentFormatter::formatValue(const Http::RequestHeaderMa return str_; } +StreamInfoRequestHeaderFormatter::StreamInfoRequestHeaderFormatter( + const std::string& main_header, const std::string& alternative_header, + absl::optional max_length) + : HeaderFormatter(main_header, alternative_header, max_length) {} + +absl::optional StreamInfoRequestHeaderFormatter::format( + const Http::RequestHeaderMap&, const Http::ResponseHeaderMap&, const Http::ResponseTrailerMap&, + const StreamInfo::StreamInfo& stream_info, absl::string_view) const { + return HeaderFormatter::format(*stream_info.getRequestHeaders()); +} + +ProtobufWkt::Value StreamInfoRequestHeaderFormatter::formatValue( + const Http::RequestHeaderMap&, const Http::ResponseHeaderMap&, const Http::ResponseTrailerMap&, + const StreamInfo::StreamInfo& stream_info, absl::string_view) const { + return HeaderFormatter::formatValue(*stream_info.getRequestHeaders()); +} + } // namespace Formatter } // namespace Envoy diff --git a/source/common/formatter/substitution_formatter.h b/source/common/formatter/substitution_formatter.h index fc3be5fac2c6e..9f635f8ac444a 100644 --- a/source/common/formatter/substitution_formatter.h +++ b/source/common/formatter/substitution_formatter.h @@ -661,5 +661,25 @@ class EnvironmentFormatter : public FormatterProvider { ProtobufWkt::Value str_; }; +/** + * FormatterProvider for request headers from StreamInfo (rather than the request_headers param). + * Purely for testing. + */ +class StreamInfoRequestHeaderFormatter : public FormatterProvider, HeaderFormatter { +public: + StreamInfoRequestHeaderFormatter(const std::string& main_header, + const std::string& alternative_header, + absl::optional max_length); + + // FormatterProvider + absl::optional format(const Http::RequestHeaderMap& request_headers, + const Http::ResponseHeaderMap&, + const Http::ResponseTrailerMap&, const StreamInfo::StreamInfo&, + absl::string_view) const override; + ProtobufWkt::Value formatValue(const Http::RequestHeaderMap&, const Http::ResponseHeaderMap&, + const Http::ResponseTrailerMap&, const StreamInfo::StreamInfo&, + absl::string_view) const override; +}; + } // namespace Formatter } // namespace Envoy diff --git a/source/common/http/conn_manager_impl.cc b/source/common/http/conn_manager_impl.cc index 578a6a2222a2d..9fe7619ad619e 100644 --- a/source/common/http/conn_manager_impl.cc +++ b/source/common/http/conn_manager_impl.cc @@ -55,7 +55,7 @@ namespace Envoy { namespace Http { -bool requestWasConnect(const RequestHeaderMapPtr& headers, Protocol protocol) { +bool requestWasConnect(const RequestHeaderMapSharedPtr& headers, Protocol protocol) { if (!headers) { return false; } @@ -278,7 +278,21 @@ void ConnectionManagerImpl::doDeferredStreamDestroy(ActiveStream& stream) { stream.completeRequest(); stream.filter_manager_.onStreamComplete(); - stream.filter_manager_.log(); + + // For HTTP/3, skip access logging here and add deferred logging info + // to stream info for QuicStatsGatherer to use later. + if (codec_ && codec_->protocol() == Protocol::Http3 && + // There was a downstream reset, log immediately. + !stream.filter_manager_.sawDownstreamReset() && + // On recreate stream, log immediately. + stream.response_encoder_ != nullptr && + Runtime::runtimeFeatureEnabled( + "envoy.reloadable_features.quic_defer_logging_to_ack_listener")) { + stream.deferHeadersAndTrailers(); + } else { + // For HTTP/1 and HTTP/2, log here as usual. + stream.filter_manager_.log(); + } stream.filter_manager_.destroyFilters(); @@ -966,7 +980,7 @@ void ConnectionManagerImpl::ActiveStream::maybeEndDecode(bool end_stream) { // can't route select properly without full headers), checking state required to // serve error responses (connection close, head requests, etc), and // modifications which may themselves affect route selection. -void ConnectionManagerImpl::ActiveStream::decodeHeaders(RequestHeaderMapPtr&& headers, +void ConnectionManagerImpl::ActiveStream::decodeHeaders(RequestHeaderMapSharedPtr&& headers, bool end_stream) { ENVOY_STREAM_LOG(debug, "request headers complete (end_stream={}):\n{}", *this, end_stream, *headers); diff --git a/source/common/http/conn_manager_impl.h b/source/common/http/conn_manager_impl.h index 1ca41e30da588..0fc013eed51cc 100644 --- a/source/common/http/conn_manager_impl.h +++ b/source/common/http/conn_manager_impl.h @@ -192,7 +192,7 @@ class ConnectionManagerImpl : Logger::Loggable, void maybeEndDecode(bool end_stream); // Http::RequestDecoder - void decodeHeaders(RequestHeaderMapPtr&& headers, bool end_stream) override; + void decodeHeaders(RequestHeaderMapSharedPtr&& headers, bool end_stream) override; void decodeTrailers(RequestTrailerMapPtr&& trailers) override; StreamInfo::StreamInfo& streamInfo() override { return filter_manager_.streamInfo(); } void sendLocalReply(Code code, absl::string_view body, @@ -201,6 +201,20 @@ class ConnectionManagerImpl : Logger::Loggable, absl::string_view details) override { return filter_manager_.sendLocalReply(code, body, modify_headers, grpc_status, details); } + std::list accessLogHandlers() override { + return filter_manager_.accessLogHandlers(); + } + // Hand off headers/trailers and stream info to the codec's response encoder, for logging later + // (i.e. possibly after this stream has been destroyed). + // + // TODO(paulsohn): Investigate whether we can move the headers/trailers and stream info required + // for logging instead of copying them (as is currently done in the HTTP/3 implementation) or + // using a shared pointer. See + // https://github.com/envoyproxy/envoy/pull/23648#discussion_r1066095564 for more details. + void deferHeadersAndTrailers() { + response_encoder_->setDeferredLoggingHeadersAndTrailers(request_headers_, response_headers_, + response_trailers_, streamInfo()); + } // ScopeTrackedObject void dumpState(std::ostream& os, int indent_level = 0) const override { @@ -371,12 +385,12 @@ class ConnectionManagerImpl : Logger::Loggable, // both locations, then refer to the FM when doing stream logs. const uint64_t stream_id_; - RequestHeaderMapPtr request_headers_; + RequestHeaderMapSharedPtr request_headers_; RequestTrailerMapPtr request_trailers_; ResponseHeaderMapPtr informational_headers_; - ResponseHeaderMapPtr response_headers_; - ResponseTrailerMapPtr response_trailers_; + ResponseHeaderMapSharedPtr response_headers_; + ResponseTrailerMapSharedPtr response_trailers_; // Note: The FM must outlive the above headers, as they are possibly accessed during filter // destruction. diff --git a/source/common/http/filter_manager.h b/source/common/http/filter_manager.h index 0ad753bc15d18..3fc14bfc2c046 100644 --- a/source/common/http/filter_manager.h +++ b/source/common/http/filter_manager.h @@ -670,6 +670,8 @@ class FilterManager : public ScopeTrackedObject, } } + std::list accessLogHandlers() { return access_log_handlers_; } + void onStreamComplete() { for (auto& filter : decoder_filters_) { filter->handle_->onStreamComplete(); @@ -818,6 +820,7 @@ class FilterManager : public ScopeTrackedObject, void contextOnContinue(ScopeTrackedObjectStack& tracked_object_stack); void onDownstreamReset() { state_.saw_downstream_reset_ = true; } + bool sawDownstreamReset() { return state_.saw_downstream_reset_; } protected: struct State { @@ -1119,6 +1122,7 @@ class DownstreamFilterManager : public FilterManager { bool is_head_request, const absl::optional grpc_status); +private: OverridableRemoteConnectionInfoSetterStreamInfo stream_info_; const LocalReply::LocalReply& local_reply_; const bool avoid_reentrant_filter_invocation_during_local_reply_; diff --git a/source/common/http/http1/codec_impl.h b/source/common/http/http1/codec_impl.h index 1e1bd36dc131b..5d3ea37e8c275 100644 --- a/source/common/http/http1/codec_impl.h +++ b/source/common/http/http1/codec_impl.h @@ -155,6 +155,10 @@ class ResponseEncoderImpl : public StreamEncoderImpl, public ResponseEncoder { bool streamErrorOnInvalidHttpMessage() const override { return stream_error_on_invalid_http_message_; } + void setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr, + Http::ResponseHeaderMapConstSharedPtr, + Http::ResponseTrailerMapConstSharedPtr, + StreamInfo::StreamInfo&) override {} // For H/1, ResponseEncoder doesn't hold a pointer to RequestDecoder. // TODO(paulsohn): Enable H/1 codec to get a pointer to the new diff --git a/source/common/http/http2/codec_impl.cc b/source/common/http/http2/codec_impl.cc index 64bc8a7bb5549..fe125600175f6 100644 --- a/source/common/http/http2/codec_impl.cc +++ b/source/common/http/http2/codec_impl.cc @@ -560,7 +560,7 @@ void ConnectionImpl::ClientStreamImpl::decodeTrailers() { } void ConnectionImpl::ServerStreamImpl::decodeHeaders() { - auto& headers = absl::get(headers_or_trailers_); + auto& headers = absl::get(headers_or_trailers_); if (Http::Utility::isH2UpgradeRequest(*headers)) { Http::Utility::transformUpgradeRequestFromH2toH1(*headers); } @@ -1877,8 +1877,8 @@ void ConnectionImpl::ServerStreamImpl::dumpState(std::ostream& os, int indent_le StreamImpl::dumpState(os, indent_level); // Dump header map - if (absl::holds_alternative(headers_or_trailers_)) { - DUMP_DETAILS(absl::get(headers_or_trailers_)); + if (absl::holds_alternative(headers_or_trailers_)) { + DUMP_DETAILS(absl::get(headers_or_trailers_)); } else { DUMP_DETAILS(absl::get(headers_or_trailers_)); } diff --git a/source/common/http/http2/codec_impl.h b/source/common/http/http2/codec_impl.h index fa20d235fb751..abccb83fafcb1 100644 --- a/source/common/http/http2/codec_impl.h +++ b/source/common/http/http2/codec_impl.h @@ -493,8 +493,8 @@ class ConnectionImpl : public virtual Connection, void decodeHeaders() override; void decodeTrailers() override; HeaderMap& headers() override { - if (absl::holds_alternative(headers_or_trailers_)) { - return *absl::get(headers_or_trailers_); + if (absl::holds_alternative(headers_or_trailers_)) { + return *absl::get(headers_or_trailers_); } else { return *absl::get(headers_or_trailers_); } @@ -514,11 +514,15 @@ class ConnectionImpl : public virtual Connection, encodeTrailersBase(trailers); } void setRequestDecoder(Http::RequestDecoder& decoder) override { request_decoder_ = &decoder; } + void setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr, + Http::ResponseHeaderMapConstSharedPtr, + Http::ResponseTrailerMapConstSharedPtr, + StreamInfo::StreamInfo&) override {} // ScopeTrackedObject void dumpState(std::ostream& os, int indent_level) const override; - absl::variant headers_or_trailers_; + absl::variant headers_or_trailers_; bool streamErrorOnInvalidHttpMessage() const override { return parent_.stream_error_on_invalid_http_messaging_; diff --git a/source/common/quic/BUILD b/source/common/quic/BUILD index b53a6b885ddbf..30e56c067d854 100644 --- a/source/common/quic/BUILD +++ b/source/common/quic/BUILD @@ -277,6 +277,7 @@ envoy_cc_library( ":envoy_quic_utils_lib", ":quic_filter_manager_connection_lib", ":quic_stat_names_lib", + ":quic_stats_gatherer", "//source/common/buffer:buffer_lib", "//source/common/common:assert_lib", "//source/common/http:header_map_lib", @@ -590,3 +591,15 @@ envoy_cc_library( "@com_github_google_quiche//:quic_load_balancer_encoder_lib", ], ) + +envoy_cc_library( + name = "quic_stats_gatherer", + srcs = ["quic_stats_gatherer.cc"], + hdrs = ["quic_stats_gatherer.h"], + tags = ["nofips"], + deps = [ + "//envoy/access_log:access_log_interface", + "//source/common/http:header_map_lib", + "@com_github_google_quiche//:quic_core_ack_listener_interface_lib", + ], +) diff --git a/source/common/quic/envoy_quic_server_stream.cc b/source/common/quic/envoy_quic_server_stream.cc index 8f64e1ac6c708..efaba2f90fc18 100644 --- a/source/common/quic/envoy_quic_server_stream.cc +++ b/source/common/quic/envoy_quic_server_stream.cc @@ -11,6 +11,7 @@ #include "source/common/http/header_utility.h" #include "source/common/quic/envoy_quic_server_session.h" #include "source/common/quic/envoy_quic_utils.h" +#include "source/common/quic/quic_stats_gatherer.h" #include "quiche/quic/core/http/quic_header_list.h" #include "quiche/quic/core/quic_session.h" @@ -36,6 +37,9 @@ EnvoyQuicServerStream::EnvoyQuicServerStream( headers_with_underscores_action_(headers_with_underscores_action) { ASSERT(static_cast(GetReceiveWindow().value()) > 8 * 1024, "Send buffer limit should be larger than 8KB."); + + stats_gatherer_ = new QuicStatsGatherer(&connection()->dispatcher().timeSource()); + set_ack_listener(stats_gatherer_); } void EnvoyQuicServerStream::encode1xxHeaders(const Http::ResponseHeaderMap& headers) { @@ -55,6 +59,7 @@ void EnvoyQuicServerStream::encodeHeaders(const Http::ResponseHeaderMap& headers { IncrementalBytesSentTracker tracker(*this, *mutableBytesMeter(), true); size_t bytes_sent = WriteHeaders(envoyHeadersToHttp2HeaderBlock(headers), end_stream, nullptr); + stats_gatherer_->addBytesSent(bytes_sent, end_stream); ENVOY_BUG(bytes_sent != 0, "Failed to encode headers."); } @@ -93,6 +98,7 @@ void EnvoyQuicServerStream::encodeData(Buffer::Instance& data, bool end_stream) { IncrementalBytesSentTracker tracker(*this, *mutableBytesMeter(), false); result = WriteBodySlices(span, end_stream); + stats_gatherer_->addBytesSent(result.bytes_consumed, end_stream); } // QUIC stream must take all. if (result.bytes_consumed == 0 && has_data) { @@ -122,6 +128,7 @@ void EnvoyQuicServerStream::encodeTrailers(const Http::ResponseTrailerMap& trail IncrementalBytesSentTracker tracker(*this, *mutableBytesMeter(), true); size_t bytes_sent = WriteTrailers(envoyHeadersToHttp2HeaderBlock(trailers), nullptr); ENVOY_BUG(bytes_sent != 0, "Failed to encode trailers."); + stats_gatherer_->addBytesSent(bytes_sent, true); } onLocalEndStream(); } @@ -381,6 +388,10 @@ void EnvoyQuicServerStream::OnClose() { return; } clearWatermarkBuffer(); + if (!stats_gatherer_->loggingDone()) { + stats_gatherer_->maybeDoDeferredLog(/* record_ack_timing */ false); + } + stats_gatherer_ = nullptr; } void EnvoyQuicServerStream::clearWatermarkBuffer() { diff --git a/source/common/quic/envoy_quic_server_stream.h b/source/common/quic/envoy_quic_server_stream.h index 3a2ae67c316d2..399f6262f1b5e 100644 --- a/source/common/quic/envoy_quic_server_stream.h +++ b/source/common/quic/envoy_quic_server_stream.h @@ -1,7 +1,9 @@ #pragma once #include "source/common/quic/envoy_quic_stream.h" +#include "source/common/quic/quic_stats_gatherer.h" +#include "quiche/common/platform/api/quiche_reference_counted.h" #include "quiche/quic/core/http/quic_spdy_server_stream_base.h" namespace Envoy { @@ -18,7 +20,11 @@ class EnvoyQuicServerStream : public quic::QuicSpdyServerStreamBase, envoy::config::core::v3::HttpProtocolOptions::HeadersWithUnderscoresAction headers_with_underscores_action); - void setRequestDecoder(Http::RequestDecoder& decoder) override { request_decoder_ = &decoder; } + void setRequestDecoder(Http::RequestDecoder& decoder) override { + request_decoder_ = &decoder; + stats_gatherer_->setAccessLogHandlers(request_decoder_->accessLogHandlers()); + } + QuicStatsGatherer* statsGatherer() { return stats_gatherer_.get(); } // Http::StreamEncoder void encode1xxHeaders(const Http::ResponseHeaderMap& headers) override; @@ -33,6 +39,23 @@ class EnvoyQuicServerStream : public quic::QuicSpdyServerStreamBase, return http3_options_.override_stream_error_on_invalid_http_message().value(); } + // Accept headers/trailers and stream info from HCM for deferred logging. We pass on the + // header/trailer shared pointers, but copy the non-shared stream info to avoid lifetime issues if + // the stream is destroyed before logging is complete. + void + setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr request_header_map, + Http::ResponseHeaderMapConstSharedPtr response_header_map, + Http::ResponseTrailerMapConstSharedPtr response_trailer_map, + StreamInfo::StreamInfo& stream_info) override { + std::unique_ptr new_stream_info = + std::make_unique( + filterManagerConnection()->dispatcher().timeSource(), + filterManagerConnection()->connectionInfoProviderSharedPtr()); + new_stream_info->setFrom(stream_info, request_header_map.get()); + stats_gatherer_->setDeferredLoggingHeadersAndTrailers( + request_header_map, response_header_map, response_trailer_map, std::move(new_stream_info)); + }; + // Http::Stream void resetStream(Http::StreamResetReason reason) override; @@ -85,6 +108,8 @@ class EnvoyQuicServerStream : public quic::QuicSpdyServerStreamBase, Http::RequestDecoder* request_decoder_{nullptr}; envoy::config::core::v3::HttpProtocolOptions::HeadersWithUnderscoresAction headers_with_underscores_action_; + + quiche::QuicheReferenceCountedPointer stats_gatherer_; }; } // namespace Quic diff --git a/source/common/quic/quic_stats_gatherer.cc b/source/common/quic/quic_stats_gatherer.cc new file mode 100644 index 0000000000000..be4b83ba70b32 --- /dev/null +++ b/source/common/quic/quic_stats_gatherer.cc @@ -0,0 +1,33 @@ +#include "source/common/quic/quic_stats_gatherer.h" + +#include + +namespace Envoy { +namespace Quic { + +void QuicStatsGatherer::OnPacketAcked(int acked_bytes, + quic::QuicTime::Delta /* delta_largest_observed */) { + bytes_outstanding_ -= acked_bytes; + if (bytes_outstanding_ == 0 && fin_sent_ && !logging_done_) { + maybeDoDeferredLog(); + } +} + +void QuicStatsGatherer::maybeDoDeferredLog(bool record_ack_timing) { + logging_done_ = true; + if (stream_info_ == nullptr) { + return; + } + if (time_source_ != nullptr && record_ack_timing) { + stream_info_->downstreamTiming().onLastDownstreamAckReceived(*time_source_); + } + const Http::RequestHeaderMap* request_headers = request_header_map_.get(); + const Http::ResponseHeaderMap* response_headers = response_header_map_.get(); + const Http::ResponseTrailerMap* response_trailers = response_trailer_map_.get(); + for (const AccessLog::InstanceSharedPtr& log_handler : access_log_handlers_) { + log_handler->log(request_headers, response_headers, response_trailers, *stream_info_); + } +} + +} // namespace Quic +} // namespace Envoy diff --git a/source/common/quic/quic_stats_gatherer.h b/source/common/quic/quic_stats_gatherer.h new file mode 100644 index 0000000000000..9708ab07f5ccd --- /dev/null +++ b/source/common/quic/quic_stats_gatherer.h @@ -0,0 +1,64 @@ +#pragma once + +#include + +#include "envoy/access_log/access_log.h" +#include "envoy/http/codec.h" +#include "envoy/http/header_map.h" +#include "envoy/stream_info/stream_info.h" + +#include "quiche/quic/core/quic_ack_listener_interface.h" + +namespace Envoy { +namespace Quic { + +// Ack listener that stores access logging information and performs +// logging after the final ack. +class QuicStatsGatherer : public quic::QuicAckListenerInterface { +public: + explicit QuicStatsGatherer(Envoy::TimeSource* time_source) : time_source_(time_source) {} + + // QuicAckListenerInterface + void OnPacketAcked(int acked_bytes, quic::QuicTime::Delta delta_largest_observed) override; + void OnPacketRetransmitted(int /* retransmitted_bytes */) override {} + + // Add bytes sent for this stream, for internal tracking of bytes acked. + void addBytesSent(uint64_t bytes_sent, bool end_stream) { + bytes_outstanding_ += bytes_sent; + fin_sent_ = end_stream; + } + // Log this stream using available stream info and access loggers. + void maybeDoDeferredLog(bool record_ack_timing = true); + // Set list of pointers to access loggers. + void setAccessLogHandlers(std::list handlers) { + access_log_handlers_ = handlers; + } + // Set headers, trailers, and stream info used for deferred logging. + void + setDeferredLoggingHeadersAndTrailers(Http::RequestHeaderMapConstSharedPtr request_header_map, + Http::ResponseHeaderMapConstSharedPtr response_header_map, + Http::ResponseTrailerMapConstSharedPtr response_trailer_map, + std::unique_ptr stream_info) { + request_header_map_ = request_header_map; + response_header_map_ = response_header_map; + response_trailer_map_ = response_trailer_map; + stream_info_ = std::move(stream_info); + } + bool loggingDone() { return logging_done_; } + uint64_t bytesOutstanding() { return bytes_outstanding_; } + +private: + uint64_t bytes_outstanding_ = 0; + bool fin_sent_ = false; + std::list access_log_handlers_{}; + Http::RequestHeaderMapConstSharedPtr request_header_map_; + Http::ResponseHeaderMapConstSharedPtr response_header_map_; + Http::ResponseTrailerMapConstSharedPtr response_trailer_map_; + // nullptr indicates that deferred logging should be skipped. + std::unique_ptr stream_info_; + Envoy::TimeSource* time_source_ = nullptr; + bool logging_done_ = false; +}; + +} // namespace Quic +} // namespace Envoy diff --git a/source/common/runtime/runtime_features.cc b/source/common/runtime/runtime_features.cc index 338357d838931..6344baa28188a 100644 --- a/source/common/runtime/runtime_features.cc +++ b/source/common/runtime/runtime_features.cc @@ -58,6 +58,7 @@ RUNTIME_GUARD(envoy_reloadable_features_no_full_scan_certs_on_sni_mismatch); RUNTIME_GUARD(envoy_reloadable_features_oauth_header_passthrough_fix); RUNTIME_GUARD(envoy_reloadable_features_original_dst_rely_on_idle_timeout); RUNTIME_GUARD(envoy_reloadable_features_postpone_h3_client_connect_to_next_loop); +RUNTIME_GUARD(envoy_reloadable_features_quic_defer_logging_to_ack_listener); RUNTIME_GUARD(envoy_reloadable_features_quic_defer_send_in_response_to_packet); RUNTIME_GUARD(envoy_reloadable_features_reject_require_client_certificate_with_quic); RUNTIME_GUARD(envoy_reloadable_features_skip_dns_lookup_for_proxied_requests); diff --git a/source/common/stream_info/BUILD b/source/common/stream_info/BUILD index 1dc253ab6c5fe..417a23230b101 100644 --- a/source/common/stream_info/BUILD +++ b/source/common/stream_info/BUILD @@ -13,6 +13,7 @@ envoy_cc_library( hdrs = ["stream_info_impl.h"], deps = [ ":filter_state_lib", + ":stream_id_provider_lib", "//envoy/http:request_id_extension_interface", "//envoy/stream_info:stream_info_interface", "//source/common/common:assert_lib", diff --git a/source/common/stream_info/stream_info_impl.h b/source/common/stream_info/stream_info_impl.h index 9cf98fa380120..b84c575444e4e 100644 --- a/source/common/stream_info/stream_info_impl.h +++ b/source/common/stream_info/stream_info_impl.h @@ -17,6 +17,7 @@ #include "source/common/common/utility.h" #include "source/common/network/socket_impl.h" #include "source/common/stream_info/filter_state_impl.h" +#include "source/common/stream_info/stream_id_provider_impl.h" #include "absl/strings/str_replace.h" @@ -336,6 +337,41 @@ struct StreamInfoImpl : public StreamInfo { start_time_monotonic_ = info.startTimeMonotonic(); } + // This function is used to copy over every field exposed in the StreamInfo interface, with a + // couple of exceptions noted below. Note that setFromForRecreateStream is reused here. + // * request_headers_ is a raw pointer; to avoid pointer lifetime issues, a request header pointer + // is required to be passed in here. + // * downstream_connection_info_provider_ is always set in the ctor. + void setFrom(StreamInfo& info, const Http::RequestHeaderMap* request_headers) { + setFromForRecreateStream(info); + route_name_ = info.getRouteName(); + virtual_cluster_name_ = info.virtualClusterName(); + response_code_ = info.responseCode(); + response_code_details_ = info.responseCodeDetails(); + connection_termination_details_ = info.connectionTerminationDetails(); + upstream_info_ = info.upstreamInfo(); + if (info.requestComplete().has_value()) { + // derive final time from other info's complete duration and start time. + final_time_ = info.startTimeMonotonic() + info.requestComplete().value(); + } + response_flags_ = info.responseFlags(); + health_check_request_ = info.healthCheck(); + route_ = info.route(); + metadata_ = info.dynamicMetadata(); + filter_state_ = info.filterState(); + request_headers_ = request_headers; + upstream_cluster_info_ = info.upstreamClusterInfo(); + auto stream_id_provider = info.getStreamIdProvider(); + if (stream_id_provider.has_value() && stream_id_provider->toStringView().has_value()) { + std::string id{stream_id_provider->toStringView().value()}; + stream_id_provider_ = std::make_shared(std::move(id)); + } + trace_reason_ = info.traceReason(); + filter_chain_name_ = info.filterChainName(); + attempt_count_ = info.attemptCount(); + upstream_bytes_meter_ = info.getUpstreamBytesMeter(); + } + void setIsShadow(bool is_shadow) { is_shadow_ = is_shadow; } bool isShadow() const override { return is_shadow_; } diff --git a/source/common/stream_info/utility.cc b/source/common/stream_info/utility.cc index 5b8cebb2d30ad..9d25b0e5dd47c 100644 --- a/source/common/stream_info/utility.cc +++ b/source/common/stream_info/utility.cc @@ -130,6 +130,14 @@ absl::optional TimingUtility::downstreamHandshakeCompl return duration(timing.value().get().downstreamHandshakeComplete(), stream_info_); } +absl::optional TimingUtility::lastDownstreamAckReceived() { + OptRef timing = stream_info_.downstreamTiming(); + if (!timing) { + return absl::nullopt; + } + return duration(timing.value().get().lastDownstreamAckReceived(), stream_info_); +} + const std::string& Utility::formatDownstreamAddressNoPort(const Network::Address::Instance& address) { if (address.type() == Network::Address::Type::Ip) { diff --git a/source/common/stream_info/utility.h b/source/common/stream_info/utility.h index f4526fbb6fbfa..ab6db6c23ff0a 100644 --- a/source/common/stream_info/utility.h +++ b/source/common/stream_info/utility.h @@ -98,6 +98,7 @@ class TimingUtility { absl::optional lastDownstreamTxByteSent(); absl::optional lastDownstreamRxByteReceived(); absl::optional downstreamHandshakeComplete(); + absl::optional lastDownstreamAckReceived(); private: const StreamInfo& stream_info_; diff --git a/test/common/formatter/substitution_formatter_fuzz_test.dict b/test/common/formatter/substitution_formatter_fuzz_test.dict index 4886e898c93f3..637faeacff65f 100644 --- a/test/common/formatter/substitution_formatter_fuzz_test.dict +++ b/test/common/formatter/substitution_formatter_fuzz_test.dict @@ -11,6 +11,7 @@ "%RESPONSE_DURATION%" "%RESPONSE_FLAGS%" "%RESPONSE_TX_DURATION%" +"%ROUNDTRIP_DURATION%" "%DOWNSTREAM_HANDSHAKE_DURATION%" "%ROUTE_NAME%" "%UPSTREAM_HOST%" diff --git a/test/common/formatter/substitution_formatter_test.cc b/test/common/formatter/substitution_formatter_test.cc index 69d2bd7cab229..0202af5b5ae00 100644 --- a/test/common/formatter/substitution_formatter_test.cc +++ b/test/common/formatter/substitution_formatter_test.cc @@ -326,6 +326,31 @@ TEST(SubstitutionFormatterTest, streamInfoFormatter) { ProtoEq(ValueUtil::numberValue(25.0))); } + { + StreamInfoFormatter roundtrip_duration_format("ROUNDTRIP_DURATION"); + + EXPECT_EQ(absl::nullopt, + roundtrip_duration_format.format(request_headers, response_headers, response_trailers, + stream_info, body)); + EXPECT_THAT(roundtrip_duration_format.formatValue(request_headers, response_headers, + response_trailers, stream_info, body), + ProtoEq(ValueUtil::nullValue())); + } + + { + StreamInfoFormatter roundtrip_duration_format("ROUNDTRIP_DURATION"); + + EXPECT_CALL(time_system, monotonicTime) + .WillOnce(Return(MonotonicTime(std::chrono::nanoseconds(25000000)))); + stream_info.downstream_timing_.onLastDownstreamAckReceived(time_system); + + EXPECT_EQ("25", roundtrip_duration_format.format(request_headers, response_headers, + response_trailers, stream_info, body)); + EXPECT_THAT(roundtrip_duration_format.formatValue(request_headers, response_headers, + response_trailers, stream_info, body), + ProtoEq(ValueUtil::numberValue(25.0))); + } + { StreamInfoFormatter bytes_received_format("BYTES_RECEIVED"); EXPECT_CALL(stream_info, bytesReceived()).WillRepeatedly(Return(1)); diff --git a/test/common/http/http1/codec_impl_test.cc b/test/common/http/http1/codec_impl_test.cc index 8749feff7f7e0..f74b30f5e0a16 100644 --- a/test/common/http/http1/codec_impl_test.cc +++ b/test/common/http/http1/codec_impl_test.cc @@ -376,11 +376,12 @@ void Http1ServerConnectionImplTest::testServerAllowChunkedContentLength(uint32_t #ifdef ENVOY_ENABLE_UHV // Header validation is done by the HCM when header map is fully parsed. EXPECT_CALL(decoder, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapPtr& headers, bool) -> void { - auto result = header_validator_->validateRequestHeaderMap(*headers); - EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); - ASSERT_TRUE(result.ok()); - })); + .WillOnce( + Invoke([this, &expected_headers](RequestHeaderMapSharedPtr& headers, bool) -> void { + auto result = header_validator_->validateRequestHeaderMap(*headers); + EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); + ASSERT_TRUE(result.ok()); + })); #else EXPECT_CALL(decoder, decodeHeaders_(HeaderMapEqual(&expected_headers), false)); #endif @@ -393,16 +394,17 @@ void Http1ServerConnectionImplTest::testServerAllowChunkedContentLength(uint32_t // sendLocalReply and closes network connection (based on the // stream_error_on_invalid_http_message flag, which in this test is assumed to equal false). EXPECT_CALL(decoder, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &response_encoder](RequestHeaderMapPtr& headers, bool) -> void { - auto result = header_validator_->validateRequestHeaderMap(*headers); - ASSERT_FALSE(result.ok()); - response_encoder->encodeHeaders(TestResponseHeaderMapImpl{{":status", "400"}, - {"connection", "close"}, - {"content-length", "0"}}, - true); - response_encoder->getStream().resetStream(StreamResetReason::LocalReset); - connection_.state_ = Network::Connection::State::Closing; - })); + .WillOnce( + Invoke([this, &response_encoder](RequestHeaderMapSharedPtr& headers, bool) -> void { + auto result = header_validator_->validateRequestHeaderMap(*headers); + ASSERT_FALSE(result.ok()); + response_encoder->encodeHeaders(TestResponseHeaderMapImpl{{":status", "400"}, + {"connection", "close"}, + {"content-length", "0"}}, + true); + response_encoder->getStream().resetStream(StreamResetReason::LocalReset); + connection_.state_ = Network::Connection::State::Closing; + })); ON_CALL(connection_, write(_, _)).WillByDefault(AddBufferToString(&response)); #else EXPECT_CALL(decoder, decodeHeaders_(_, _)).Times(0); @@ -544,7 +546,7 @@ TEST_P(Http1ServerConnectionImplTest, ContentLengthAllBitsSet) { TestRequestHeaderMapImpl expected_headers{ {"content-length", "3"}, {":path", "/"}, {":method", "POST"}}; EXPECT_CALL(decoder, decodeHeaders_(HeaderMapEqual(&expected_headers), false)) - .WillOnce(Invoke([&](Http::RequestHeaderMapPtr&, bool) -> void { + .WillOnce(Invoke([&](Http::RequestHeaderMapSharedPtr&, bool) -> void { connection_.state_ = Network::Connection::State::Closing; })); EXPECT_CALL(decoder, decodeData(_, _)).Times(0); @@ -1280,7 +1282,7 @@ TEST_P(Http1ServerConnectionImplTest, HeaderNameWithUnderscoreAllowed) { #ifdef ENVOY_ENABLE_UHV // Header validation is done by the HCM when header map is fully parsed. EXPECT_CALL(decoder, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); ASSERT_TRUE(result.ok()); @@ -1313,7 +1315,7 @@ TEST_P(Http1ServerConnectionImplTest, HeaderNameWithUnderscoreAreDropped) { #ifdef ENVOY_ENABLE_UHV // Header validation is done by the HCM when header map is fully parsed. EXPECT_CALL(decoder, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); ASSERT_TRUE(result.ok()); @@ -1350,7 +1352,7 @@ TEST_P(Http1ServerConnectionImplTest, HeaderNameWithUnderscoreCauseRequestReject // sendLocalReply and closes network connection (based on the // stream_error_on_invalid_http_message flag, which in this test is assumed to equal false). EXPECT_CALL(decoder, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &response_encoder](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this, &response_encoder](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); ASSERT_FALSE(result.ok()); response_encoder->encodeHeaders(TestResponseHeaderMapImpl{{":status", "400"}, @@ -1489,7 +1491,7 @@ TEST_P(Http1ServerConnectionImplTest, CloseDuringHeadersComplete) { TestRequestHeaderMapImpl expected_headers{ {"content-length", "5"}, {":path", "/"}, {":method", "POST"}}; EXPECT_CALL(decoder, decodeHeaders_(HeaderMapEqual(&expected_headers), false)) - .WillOnce(Invoke([&](Http::RequestHeaderMapPtr&, bool) -> void { + .WillOnce(Invoke([&](Http::RequestHeaderMapSharedPtr&, bool) -> void { connection_.state_ = Network::Connection::State::Closing; })); EXPECT_CALL(decoder, decodeData(_, _)).Times(0); diff --git a/test/common/http/http2/codec_impl_test.cc b/test/common/http/http2/codec_impl_test.cc index 361b297783ad2..f1cec41153cef 100644 --- a/test/common/http/http2/codec_impl_test.cc +++ b/test/common/http/http2/codec_impl_test.cc @@ -1364,7 +1364,7 @@ TEST_P(Http2CodecImplTest, ShouldDumpActiveStreamsWithoutAllocatingMemory) { EXPECT_THAT(ostream.contents(), HasSubstr("local_end_stream_: 1")); EXPECT_THAT(ostream.contents(), HasSubstr("pending_trailers_to_encode_: null\n" - " absl::get(headers_or_trailers_): \n" + " absl::get(headers_or_trailers_): \n" " ':scheme', 'http'\n" " ':method', 'GET'\n" " ':authority', 'host'\n" @@ -2685,7 +2685,7 @@ TEST_P(Http2CodecImplTest, HeaderNameWithUnderscoreAreDropped) { #ifdef ENVOY_ENABLE_UHV // Header validation is done by the HCM when header map is fully parsed. EXPECT_CALL(request_decoder_, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); ASSERT_TRUE(result.ok()); @@ -2714,7 +2714,7 @@ TEST_P(Http2CodecImplTest, HeaderNameWithUnderscoreAreRejected) { // sendLocalReply and closes network connection (based on the // stream_error_on_invalid_http_message flag, which in this test is assumed to equal false). EXPECT_CALL(request_decoder_, decodeHeaders_(_, _)) - .WillOnce(Invoke([this](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); ASSERT_FALSE(result.ok()); response_encoder_->encodeHeaders(TestResponseHeaderMapImpl{{":status", "400"}, @@ -2748,7 +2748,7 @@ TEST_P(Http2CodecImplTest, HeaderNameWithUnderscoreAllowed) { #ifdef ENVOY_ENABLE_UHV // Header validation is done by the HCM when header map is fully parsed. EXPECT_CALL(request_decoder_, decodeHeaders_(_, _)) - .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapPtr& headers, bool) -> void { + .WillOnce(Invoke([this, &expected_headers](RequestHeaderMapSharedPtr& headers, bool) -> void { auto result = header_validator_->validateRequestHeaderMap(*headers); EXPECT_THAT(headers, HeaderMapEqualIgnoreOrder(&expected_headers)); ASSERT_TRUE(result.ok()); diff --git a/test/common/quic/envoy_quic_server_session_test.cc b/test/common/quic/envoy_quic_server_session_test.cc index e77c2ce5146bf..266ed03c6920b 100644 --- a/test/common/quic/envoy_quic_server_session_test.cc +++ b/test/common/quic/envoy_quic_server_session_test.cc @@ -294,6 +294,7 @@ TEST_F(EnvoyQuicServerSessionTest, NewStream) { Http::MockRequestDecoder request_decoder; EXPECT_CALL(http_connection_callbacks_, newStream(_, false)) .WillOnce(testing::ReturnRef(request_decoder)); + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStreamId stream_id = 4u; auto stream = reinterpret_cast(envoy_quic_session_.GetOrCreateStream(stream_id)); @@ -311,7 +312,7 @@ TEST_F(EnvoyQuicServerSessionTest, NewStream) { headers.OnHeaderBlockEnd(/*uncompressed_header_bytes=*/0, /*compressed_header_bytes=*/0); // Request headers should be propagated to decoder. EXPECT_CALL(request_decoder, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); @@ -355,6 +356,7 @@ TEST_F(EnvoyQuicServerSessionTest, OnResetFrameIetfQuic) { Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()).Times(3); auto stream1 = dynamic_cast(createNewStream(request_decoder, stream_callbacks)); // Receiving RESET_STREAM alone should only close read side. @@ -438,6 +440,7 @@ TEST_F(EnvoyQuicServerSessionTest, ConnectionCloseWithActiveStream) { Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); EXPECT_CALL(*quic_connection_, SendConnectionClosePacket(quic::QUIC_NO_ERROR, _, "Closed by application")); @@ -453,6 +456,7 @@ TEST_F(EnvoyQuicServerSessionTest, RemoteConnectionCloseWithActiveStream) { Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); EXPECT_CALL(network_connection_callbacks_, onEvent(Network::ConnectionEvent::RemoteClose)); EXPECT_CALL(stream_callbacks, onResetStream(Http::StreamResetReason::ConnectionFailure, _)); @@ -470,6 +474,7 @@ TEST_F(EnvoyQuicServerSessionTest, NoFlushWithDataToWrite) { Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); envoy_quic_session_.MarkConnectionLevelWriteBlocked(stream->id()); EXPECT_CALL(*quic_connection_, @@ -487,6 +492,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlushCloseWithDataToWrite) { installReadFilter(); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); envoy_quic_session_.MarkConnectionLevelWriteBlocked(stream->id()); @@ -526,6 +532,7 @@ TEST_F(EnvoyQuicServerSessionTest, WriteUpdatesDelayCloseTimer) { envoy_quic_session_.setDelayedCloseTimeout(std::chrono::milliseconds(100)); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); // Create a stream and write enough data to make it blocked. auto stream = dynamic_cast(createNewStream(request_decoder, stream_callbacks)); @@ -540,7 +547,7 @@ TEST_F(EnvoyQuicServerSessionTest, WriteUpdatesDelayCloseTimer) { request_headers.OnHeaderBlockEnd(/*uncompressed_header_bytes=*/0, /*compressed_header_bytes=*/0); // Request headers should be propagated to decoder. EXPECT_CALL(request_decoder, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); @@ -625,6 +632,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlushCloseNoTimeout) { Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); // Create a stream and write enough data to make it blocked. auto stream = dynamic_cast(createNewStream(request_decoder, stream_callbacks)); @@ -639,7 +647,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlushCloseNoTimeout) { request_headers.OnHeaderBlockEnd(/*uncompressed_header_bytes=*/0, /*compressed_header_bytes=*/0); // Request headers should be propagated to decoder. EXPECT_CALL(request_decoder, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); @@ -687,6 +695,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlushCloseWithTimeout) { envoy_quic_session_.setDelayedCloseTimeout(std::chrono::milliseconds(100)); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); envoy_quic_session_.MarkConnectionLevelWriteBlocked(stream->id()); @@ -718,6 +727,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlushAndWaitForCloseWithTimeout) { envoy_quic_session_.setDelayedCloseTimeout(std::chrono::milliseconds(100)); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); envoy_quic_session_.MarkConnectionLevelWriteBlocked(stream->id()); @@ -748,6 +758,7 @@ TEST_F(EnvoyQuicServerSessionTest, FlusWriteTransitToFlushWriteWithDelay) { envoy_quic_session_.setDelayedCloseTimeout(std::chrono::milliseconds(100)); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); quic::QuicStream* stream = createNewStream(request_decoder, stream_callbacks); envoy_quic_session_.MarkConnectionLevelWriteBlocked(stream->id()); @@ -864,6 +875,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { installReadFilter(); Http::MockRequestDecoder request_decoder; Http::MockStreamCallbacks stream_callbacks; + EXPECT_CALL(request_decoder, accessLogHandlers()); EXPECT_CALL(http_connection_callbacks_, newStream(_, false)) .WillOnce(Invoke([&request_decoder, &stream_callbacks](Http::ResponseEncoder& encoder, bool) -> Http::RequestDecoder& { @@ -884,7 +896,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { request_headers.OnHeaderBlockEnd(/*uncompressed_header_bytes=*/0, /*compressed_header_bytes=*/0); // Request headers should be propagated to decoder. EXPECT_CALL(request_decoder, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); @@ -907,6 +919,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { // send buffer watermark. Http::MockRequestDecoder request_decoder2; Http::MockStreamCallbacks stream_callbacks2; + EXPECT_CALL(request_decoder2, accessLogHandlers()); EXPECT_CALL(http_connection_callbacks_, newStream(_, false)) .WillOnce(Invoke([&request_decoder2, &stream_callbacks2](Http::ResponseEncoder& encoder, bool) -> Http::RequestDecoder& { @@ -916,7 +929,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { auto stream2 = dynamic_cast(envoy_quic_session_.GetOrCreateStream(stream_id + 4)); EXPECT_CALL(request_decoder2, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); @@ -937,6 +950,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { // high watermark reached upon creation. Http::MockRequestDecoder request_decoder3; Http::MockStreamCallbacks stream_callbacks3; + EXPECT_CALL(request_decoder3, accessLogHandlers()); EXPECT_CALL(http_connection_callbacks_, newStream(_, false)) .WillOnce(Invoke([&request_decoder3, &stream_callbacks3](Http::ResponseEncoder& encoder, bool) -> Http::RequestDecoder& { @@ -947,7 +961,7 @@ TEST_F(EnvoyQuicServerSessionTest, SendBufferWatermark) { auto stream3 = dynamic_cast(envoy_quic_session_.GetOrCreateStream(stream_id + 8)); EXPECT_CALL(request_decoder3, decodeHeaders_(_, /*end_stream=*/true)) - .WillOnce(Invoke([&host](const Http::RequestHeaderMapPtr& decoded_headers, bool) { + .WillOnce(Invoke([&host](const Http::RequestHeaderMapSharedPtr& decoded_headers, bool) { EXPECT_EQ(host, decoded_headers->getHostValue()); EXPECT_EQ("/", decoded_headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, decoded_headers->getMethodValue()); diff --git a/test/common/quic/envoy_quic_server_stream_test.cc b/test/common/quic/envoy_quic_server_stream_test.cc index 32ae20d03947d..99cdfbec9232f 100644 --- a/test/common/quic/envoy_quic_server_stream_test.cc +++ b/test/common/quic/envoy_quic_server_stream_test.cc @@ -11,9 +11,11 @@ #include "source/server/active_listener_base.h" #include "test/common/quic/test_utils.h" +#include "test/mocks/access_log/mocks.h" #include "test/mocks/http/mocks.h" #include "test/mocks/http/stream_decoder.h" #include "test/mocks/network/mocks.h" +#include "test/test_common/test_time.h" #include "test/test_common/utility.h" #include "gmock/gmock.h" @@ -52,6 +54,7 @@ class EnvoyQuicServerStreamTest : public testing::Test { envoy::config::core::v3::HttpProtocolOptions::ALLOW)), response_headers_{{":status", "200"}, {"response-key", "response-value"}}, response_trailers_{{"trailer-key", "trailer-value"}} { + EXPECT_CALL(stream_decoder_, accessLogHandlers()); quic_stream_->setRequestDecoder(stream_decoder_); quic_stream_->addCallbacks(stream_callbacks_); quic_stream_->getStream().setFlushTimeout(std::chrono::milliseconds(30000)); @@ -102,7 +105,7 @@ class EnvoyQuicServerStreamTest : public testing::Test { size_t receiveRequest(const std::string& payload, bool fin, size_t decoder_buffer_high_watermark) { EXPECT_CALL(stream_decoder_, decodeHeaders_(_, /*end_stream=*/false)) - .WillOnce(Invoke([this](const Http::RequestHeaderMapPtr& headers, bool) { + .WillOnce(Invoke([this](const Http::RequestHeaderMapSharedPtr& headers, bool) { EXPECT_EQ(host_, headers->getHostValue()); EXPECT_EQ("/", headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Post, headers->getMethodValue()); @@ -126,7 +129,7 @@ class EnvoyQuicServerStreamTest : public testing::Test { size_t receiveRequestHeaders(bool end_stream) { EXPECT_CALL(stream_decoder_, decodeHeaders_(_, end_stream)) - .WillOnce(Invoke([this](const Http::RequestHeaderMapPtr& headers, bool) { + .WillOnce(Invoke([this](const Http::RequestHeaderMapSharedPtr& headers, bool) { EXPECT_EQ(host_, headers->getHostValue()); EXPECT_EQ("/", headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Post, headers->getMethodValue()); @@ -193,7 +196,7 @@ class EnvoyQuicServerStreamTest : public testing::Test { TEST_F(EnvoyQuicServerStreamTest, GetRequestAndResponse) { EXPECT_CALL(stream_decoder_, decodeHeaders_(_, /*end_stream=*/false)) - .WillOnce(Invoke([this](const Http::RequestHeaderMapPtr& headers, bool) { + .WillOnce(Invoke([this](const Http::RequestHeaderMapSharedPtr& headers, bool) { EXPECT_EQ(host_, headers->getHostValue()); EXPECT_EQ("/", headers->getPathValue()); EXPECT_EQ(Http::Headers::get().MethodValues.Get, headers->getMethodValue()); @@ -454,8 +457,9 @@ TEST_F(EnvoyQuicServerStreamTest, ReadDisableAndReEnableImmediately) { TEST_F(EnvoyQuicServerStreamTest, ReadDisableUponHeaders) { std::string payload(1024, 'a'); EXPECT_CALL(stream_decoder_, decodeHeaders_(_, /*end_stream=*/false)) - .WillOnce(Invoke( - [this](const Http::RequestHeaderMapPtr&, bool) { quic_stream_->readDisable(true); })); + .WillOnce(Invoke([this](const Http::RequestHeaderMapSharedPtr&, bool) { + quic_stream_->readDisable(true); + })); EXPECT_CALL(stream_decoder_, decodeData(_, _)); std::string data = absl::StrCat(spdyHeaderToHttp3StreamPayload(spdy_request_headers_), bodyToHttp3StreamPayload(payload)); @@ -750,6 +754,30 @@ TEST_F(EnvoyQuicServerStreamTest, ConnectionCloseAfterEndStreamEncoded) { quic_stream_->encodeHeaders(response_headers_, /*end_stream=*/true); } +// Tests that when stream is cleaned up, QuicStatsGatherer executes any pending logs. +TEST_F(EnvoyQuicServerStreamTest, StatsGathererLogsOnStreamDestruction) { + + // Set up QuicStatsGatherer with required access logger, stream info, headers and trailers. + std::shared_ptr mock_logger(new NiceMock()); + std::list loggers = {mock_logger}; + Event::GlobalTimeSystem test_time_; + Envoy::StreamInfo::StreamInfoImpl stream_info{Http::Protocol::Http2, test_time_.timeSystem(), + nullptr}; + quic_stream_->statsGatherer()->setAccessLogHandlers(loggers); + quic_stream_->setDeferredLoggingHeadersAndTrailers(nullptr, nullptr, nullptr, stream_info); + + receiveRequest(request_body_, false, request_body_.size() * 2); + quic_stream_->encodeHeaders(response_headers_, /*end_stream=*/true); + EXPECT_CALL(quic_session_, MaybeSendStopSendingFrame(_, _)); + EXPECT_CALL(stream_callbacks_, onResetStream(Http::StreamResetReason::LocalReset, _)); + // The stats gatherer has outstanding bytes that have not been acked. + EXPECT_GT(quic_stream_->statsGatherer()->bytesOutstanding(), 0); + // Close the stream; incoming acks will no longer invoke the stats gatherer but + // the stats gatherer should log on stream close despite not receiving final downstream ack. + EXPECT_CALL(*mock_logger, log(_, _, _, _)); + quic_stream_->resetStream(Http::StreamResetReason::LocalRefusedStreamReset); +} + TEST_F(EnvoyQuicServerStreamTest, MetadataNotSupported) { Http::MetadataMap metadata_map = {{"key", "value"}}; Http::MetadataMapPtr metadata_map_ptr = std::make_unique(metadata_map); diff --git a/test/common/stream_info/stream_info_impl_test.cc b/test/common/stream_info/stream_info_impl_test.cc index 87fd10117d7b8..e2c136528d6ae 100644 --- a/test/common/stream_info/stream_info_impl_test.cc +++ b/test/common/stream_info/stream_info_impl_test.cc @@ -6,6 +6,7 @@ #include "envoy/upstream/host_description.h" #include "source/common/common/fmt.h" +#include "source/common/network/address_impl.h" #include "source/common/protobuf/utility.h" #include "source/common/stream_info/stream_id_provider_impl.h" #include "source/common/stream_info/stream_info_impl.h" @@ -35,6 +36,13 @@ std::chrono::nanoseconds checkDuration(std::chrono::nanoseconds last, class StreamInfoImplTest : public testing::Test { protected: + void assertStreamInfoSize(StreamInfoImpl stream_info) { + ASSERT_TRUE(sizeof(stream_info) == 800 || sizeof(stream_info) == 816 || + sizeof(stream_info) == 840) + << "If adding fields to StreamInfoImpl, please check to see if you " + "need to add them to setFromForRecreateStream or setFrom! Current size " + << sizeof(stream_info); + } DangerousDeprecatedTestTime test_time_; }; @@ -84,6 +92,10 @@ TEST_F(StreamInfoImplTest, TimingTest) { info.downstreamTiming().onDownstreamHandshakeComplete(test_time_.timeSystem()); dur = checkDuration(dur, timing.downstreamHandshakeComplete()); + EXPECT_FALSE(timing.lastDownstreamAckReceived()); + info.downstreamTiming().onLastDownstreamAckReceived(test_time_.timeSystem()); + dur = checkDuration(dur, timing.lastDownstreamAckReceived()); + EXPECT_FALSE(info.requestComplete()); info.onRequestComplete(); dur = checkDuration(dur, info.requestComplete()); @@ -224,7 +236,7 @@ TEST_F(StreamInfoImplTest, MiscSettersAndGetters) { } } -TEST_F(StreamInfoImplTest, SetFrom) { +TEST_F(StreamInfoImplTest, SetFromForRecreateStream) { StreamInfoImpl s1(Http::Protocol::Http2, test_time_.timeSystem(), nullptr); s1.addBytesReceived(1); @@ -233,10 +245,7 @@ TEST_F(StreamInfoImplTest, SetFrom) { #ifdef __clang__ #if defined(__linux__) #if defined(__has_feature) && !(__has_feature(thread_sanitizer)) - ASSERT_TRUE(sizeof(s1) == 784 || sizeof(s1) == 800 || sizeof(s1) == 808 || sizeof(s1) == 824) - << "If adding fields to StreamInfoImpl, please check to see if you " - "need to add them to setFromForRecreateStream! Current size " - << sizeof(s1); + assertStreamInfoSize(s1); #endif #endif #endif @@ -252,6 +261,90 @@ TEST_F(StreamInfoImplTest, SetFrom) { EXPECT_EQ(s1.getDownstreamBytesMeter(), s2.getDownstreamBytesMeter()); } +TEST_F(StreamInfoImplTest, SetFrom) { + StreamInfoImpl s1(Http::Protocol::Http2, test_time_.timeSystem(), nullptr); + + // setFromForRecreateStream + s1.addBytesReceived(1); + s1.downstreamTiming().onLastDownstreamRxByteReceived(test_time_.timeSystem()); + + // setFrom + s1.setRouteName("foo"); + s1.setVirtualClusterName(absl::optional("bar")); + s1.setResponseCode(200); + s1.setResponseCodeDetails("OK"); + s1.setConnectionTerminationDetails("baz"); + s1.setUpstreamInfo(std::make_shared()); + s1.upstreamInfo()->upstreamTiming().onLastUpstreamTxByteSent(test_time_.timeSystem()); + s1.onRequestComplete(); + s1.setResponseFlag(FailedLocalHealthCheck); + s1.healthCheck(true); + s1.route_ = std::make_shared>(); + s1.setDynamicMetadata("com.test", MessageUtil::keyValueStruct("test_key", "test_value")); + s1.filterState()->setData("test", std::make_unique(1), + FilterState::StateType::ReadOnly, FilterState::LifeSpan::FilterChain); + Http::TestRequestHeaderMapImpl headers1; + s1.setRequestHeaders(headers1); + Upstream::ClusterInfoConstSharedPtr cluster_info(new NiceMock()); + s1.setUpstreamClusterInfo(cluster_info); + s1.setStreamIdProvider( + std::make_shared("a121e9e1-feae-4136-9e0e-6fac343d56c9")); + s1.setTraceReason(Tracing::Reason::ClientForced); + s1.setFilterChainName("foobar"); + s1.setAttemptCount(5); + +#ifdef __clang__ +#if defined(__linux__) +#if defined(__has_feature) && !(__has_feature(thread_sanitizer)) + assertStreamInfoSize(s1); +#endif +#endif +#endif + + StreamInfoImpl s2(Http::Protocol::Http11, test_time_.timeSystem(), nullptr); + Http::TestRequestHeaderMapImpl headers2; + s2.setFrom(s1, &headers2); + + // Copied by setFromForRecreateStream + EXPECT_EQ(s1.startTime(), s2.startTime()); + EXPECT_EQ(s1.startTimeMonotonic(), s2.startTimeMonotonic()); + EXPECT_EQ(s1.downstreamTiming().lastDownstreamRxByteReceived(), + s2.downstreamTiming().lastDownstreamRxByteReceived()); + EXPECT_EQ(s1.protocol(), s2.protocol()); + EXPECT_EQ(s1.bytesReceived(), s2.bytesReceived()); + EXPECT_EQ(s1.getDownstreamBytesMeter(), s2.getDownstreamBytesMeter()); + + // Copied by setFrom + EXPECT_EQ(s1.getRouteName(), s2.getRouteName()); + EXPECT_EQ(s1.virtualClusterName(), s2.virtualClusterName()); + EXPECT_EQ(s1.responseCode(), s2.responseCode()); + EXPECT_EQ(s1.responseCodeDetails(), s2.responseCodeDetails()); + EXPECT_EQ(s1.connectionTerminationDetails(), s2.connectionTerminationDetails()); + EXPECT_EQ(s1.upstreamInfo()->upstreamTiming().last_upstream_tx_byte_sent_, + s2.upstreamInfo()->upstreamTiming().last_upstream_tx_byte_sent_); + EXPECT_EQ(s1.requestComplete(), s2.requestComplete()); + EXPECT_EQ(s1.responseFlags(), s2.responseFlags()); + EXPECT_EQ(s1.healthCheck(), s2.healthCheck()); + EXPECT_NE(s1.route(), nullptr); + EXPECT_EQ(s1.route(), s2.route()); + EXPECT_EQ( + Config::Metadata::metadataValue(&s1.dynamicMetadata(), "com.test", "test_key").string_value(), + Config::Metadata::metadataValue(&s2.dynamicMetadata(), "com.test", "test_key") + .string_value()); + EXPECT_EQ(s1.filterState()->getDataReadOnly("test")->access(), + s2.filterState()->getDataReadOnly("test")->access()); + EXPECT_EQ(*s1.getRequestHeaders(), headers1); + EXPECT_EQ(*s2.getRequestHeaders(), headers2); + EXPECT_TRUE(s2.upstreamClusterInfo().has_value()); + EXPECT_EQ(s1.upstreamClusterInfo(), s2.upstreamClusterInfo()); + EXPECT_EQ(s1.getStreamIdProvider().value().get().toStringView().value(), + s2.getStreamIdProvider().value().get().toStringView().value()); + EXPECT_EQ(s1.traceReason(), s2.traceReason()); + EXPECT_EQ(s1.filterChainName(), s2.filterChainName()); + EXPECT_EQ(s1.attemptCount(), s2.attemptCount()); + EXPECT_EQ(s1.getUpstreamBytesMeter(), s2.getUpstreamBytesMeter()); +} + TEST_F(StreamInfoImplTest, DynamicMetadataTest) { StreamInfoImpl stream_info(Http::Protocol::Http2, test_time_.timeSystem(), nullptr); diff --git a/test/integration/BUILD b/test/integration/BUILD index dfb107a828c03..ff1424bd727e2 100644 --- a/test/integration/BUILD +++ b/test/integration/BUILD @@ -1145,9 +1145,11 @@ envoy_cc_test( "redirect_integration_test.cc", ], shard_count = 4, + tags = ["nofips"], deps = [ ":http_protocol_integration_lib", "//source/common/http:header_map_lib", + "//test/integration/filters:pause_filter_for_quic_lib", "//test/test_common:utility_lib", "@envoy_api//envoy/config/route/v3:pkg_cc_proto", "@envoy_api//envoy/extensions/filters/network/http_connection_manager/v3:pkg_cc_proto", diff --git a/test/integration/base_integration_test.cc b/test/integration/base_integration_test.cc index fca24404e4632..f966437defa0d 100644 --- a/test/integration/base_integration_test.cc +++ b/test/integration/base_integration_test.cc @@ -510,7 +510,9 @@ void BaseIntegrationTest::useListenerAccessLog(absl::string_view format) { } std::string BaseIntegrationTest::waitForAccessLog(const std::string& filename, uint32_t entry, - bool allow_excess_entries) { + bool allow_excess_entries, + Network::ClientConnection* client_connection) { + // Wait a max of 1s for logs to flush to disk. std::string contents; for (int i = 0; i < 1000; ++i) { @@ -525,6 +527,11 @@ std::string BaseIntegrationTest::waitForAccessLog(const std::string& filename, u << contents; return entries[entry]; } + if (i % 25 == 0 && client_connection != nullptr) { + // The QUIC default delayed ack timer is 25ms. Wait for any pending ack timers to expire, + // then run dispatcher to send any pending acks. + client_connection->dispatcher().run(Envoy::Event::Dispatcher::RunType::NonBlock); + } absl::SleepFor(absl::Milliseconds(1)); } RELEASE_ASSERT(0, absl::StrCat("Timed out waiting for access log. Found: '", contents, "'")); diff --git a/test/integration/base_integration_test.h b/test/integration/base_integration_test.h index 3a7daa23ed7ac..d7e24678daf21 100644 --- a/test/integration/base_integration_test.h +++ b/test/integration/base_integration_test.h @@ -159,8 +159,10 @@ class BaseIntegrationTest : protected Logger::Loggable { void useListenerAccessLog(absl::string_view format = ""); // Returns all log entries after the nth access log entry, defaulting to log entry 0. // By default will trigger an expect failure if more than one entry is returned. + // If client_connection is provided, flush pending acks to enable deferred logging. std::string waitForAccessLog(const std::string& filename, uint32_t entry = 0, - bool allow_excess_entries = false); + bool allow_excess_entries = false, + Network::ClientConnection* client_connection = nullptr); std::string listener_access_log_name_; diff --git a/test/integration/fake_upstream.cc b/test/integration/fake_upstream.cc index 783439df3d2a7..159a9d030535f 100644 --- a/test/integration/fake_upstream.cc +++ b/test/integration/fake_upstream.cc @@ -44,7 +44,7 @@ FakeStream::FakeStream(FakeHttpConnection& parent, Http::ResponseEncoder& encode encoder.getStream().addCallbacks(*this); } -void FakeStream::decodeHeaders(Http::RequestHeaderMapPtr&& headers, bool end_stream) { +void FakeStream::decodeHeaders(Http::RequestHeaderMapSharedPtr&& headers, bool end_stream) { absl::MutexLock lock(&lock_); headers_ = std::move(headers); setEndStream(end_stream); diff --git a/test/integration/fake_upstream.h b/test/integration/fake_upstream.h index cd72f44e528bf..6f3f92a64dfd2 100644 --- a/test/integration/fake_upstream.h +++ b/test/integration/fake_upstream.h @@ -219,12 +219,15 @@ class FakeStream : public Http::RequestDecoder, void decodeMetadata(Http::MetadataMapPtr&& metadata_map_ptr) override; // Http::RequestDecoder - void decodeHeaders(Http::RequestHeaderMapPtr&& headers, bool end_stream) override; + void decodeHeaders(Http::RequestHeaderMapSharedPtr&& headers, bool end_stream) override; void decodeTrailers(Http::RequestTrailerMapPtr&& trailers) override; StreamInfo::StreamInfo& streamInfo() override { RELEASE_ASSERT(false, "initialize if this is needed"); return *stream_info_; } + std::list accessLogHandlers() override { + return access_log_handlers_; + } // Http::StreamCallbacks void onResetStream(Http::StreamResetReason reason, @@ -243,7 +246,7 @@ class FakeStream : public Http::RequestDecoder, protected: absl::Mutex lock_; - Http::RequestHeaderMapPtr headers_ ABSL_GUARDED_BY(lock_); + Http::RequestHeaderMapSharedPtr headers_ ABSL_GUARDED_BY(lock_); Buffer::OwnedImpl body_ ABSL_GUARDED_BY(lock_); FakeHttpConnection& parent_; @@ -258,7 +261,8 @@ class FakeStream : public Http::RequestDecoder, Event::TestTimeSystem& time_system_; Http::MetadataMap metadata_map_; absl::node_hash_map duplicated_metadata_key_count_; - std::unique_ptr stream_info_; + std::shared_ptr stream_info_; + std::list access_log_handlers_; bool received_data_{false}; bool grpc_stream_started_{false}; }; diff --git a/test/integration/http_integration.h b/test/integration/http_integration.h index 9b71dfa6e4f08..8bf48ff28c987 100644 --- a/test/integration/http_integration.h +++ b/test/integration/http_integration.h @@ -144,6 +144,15 @@ class HttpIntegrationTest : public BaseIntegrationTest { protected: void useAccessLog(absl::string_view format = "", std::vector formatters = {}); + std::string waitForAccessLog(const std::string& filename, uint32_t entry = 0, + bool allow_excess_entries = false, + Network::ClientConnection* client_connection = nullptr) { + if (client_connection == nullptr && codec_client_) { + client_connection = codec_client_->connection(); + } + return BaseIntegrationTest::waitForAccessLog(filename, entry, allow_excess_entries, + client_connection); + }; IntegrationCodecClientPtr makeHttpConnection(uint32_t port); // Makes a http connection object without checking its connected state. diff --git a/test/integration/quic_http_integration_test.cc b/test/integration/quic_http_integration_test.cc index 7072bd8c86de3..8a3407ce28c88 100644 --- a/test/integration/quic_http_integration_test.cc +++ b/test/integration/quic_http_integration_test.cc @@ -1182,6 +1182,207 @@ TEST_P(QuicHttpIntegrationTest, MultipleNetworkFilters) { codec_client_->close(); } +TEST_P(QuicHttpIntegrationTest, DeferredLogging) { + useAccessLog( + "%PROTOCOL%,%ROUNDTRIP_DURATION%,%REQUEST_DURATION%,%RESPONSE_DURATION%,%RESPONSE_" + "CODE%,%BYTES_RECEIVED%,%ROUTE_NAME%,%VIRTUAL_CLUSTER_NAME%,%RESPONSE_CODE_DETAILS%,%" + "CONNECTION_TERMINATION_DETAILS%,%START_TIME%,%UPSTREAM_HOST%,%DURATION%,%BYTES_SENT%,%" + "RESPONSE_FLAGS%,%DOWNSTREAM_LOCAL_ADDRESS%,%UPSTREAM_CLUSTER%,%STREAM_ID%,%DYNAMIC_" + "METADATA(" + "udp.proxy.session:bytes_sent)%,%REQ(:path)%,%STREAM_INFO_REQ(:path)%"); + initialize(); + codec_client_ = makeHttpConnection(makeClientConnection(lookupPort("http"))); + sendRequestAndWaitForResponse(default_request_headers_, /*request_size=*/0, + default_response_headers_, + /*response_size=*/0, + /*upstream_index=*/0, TestUtility::DefaultTimeout); + codec_client_->close(); + + std::string log = waitForAccessLog(access_log_name_); + + std::vector metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 21); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + EXPECT_GT(/* ROUNDTRIP_DURATION */ std::stoi(metrics.at(1)), 0); + EXPECT_GE(/* REQUEST_DURATION */ std::stoi(metrics.at(2)), 0); + EXPECT_GE(/* RESPONSE_DURATION */ std::stoi(metrics.at(3)), 0); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "200"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + // Ensure that request headers from top-level access logger parameter and stream info are + // consistent. + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); +} + +TEST_P(QuicHttpIntegrationTest, DeferredLoggingDisabled) { + config_helper_.addRuntimeOverride("envoy.reloadable_features.quic_defer_logging_to_ack_listener", + "false"); + useAccessLog( + "%PROTOCOL%,%ROUNDTRIP_DURATION%,%REQUEST_DURATION%,%RESPONSE_DURATION%,%RESPONSE_" + "CODE%,%BYTES_RECEIVED%,%ROUTE_NAME%,%VIRTUAL_CLUSTER_NAME%,%RESPONSE_CODE_DETAILS%,%" + "CONNECTION_TERMINATION_DETAILS%,%START_TIME%,%UPSTREAM_HOST%,%DURATION%,%BYTES_SENT%,%" + "RESPONSE_FLAGS%,%DOWNSTREAM_LOCAL_ADDRESS%,%UPSTREAM_CLUSTER%,%STREAM_ID%,%DYNAMIC_" + "METADATA(" + "udp.proxy.session:bytes_sent)%,%REQ(:path)%,%STREAM_INFO_REQ(:path)%"); + initialize(); + codec_client_ = makeHttpConnection(makeClientConnection(lookupPort("http"))); + sendRequestAndWaitForResponse(default_request_headers_, /*request_size=*/0, + default_response_headers_, + /*response_size=*/0, + /*upstream_index=*/0, TestUtility::DefaultTimeout); + codec_client_->close(); + + // Do not flush client acks. + std::string log = waitForAccessLog(access_log_name_, 0, false, nullptr); + std::vector metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 21); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + EXPECT_EQ(/* ROUNDTRIP_DURATION */ metrics.at(1), "-"); + EXPECT_GE(/* REQUEST_DURATION */ std::stoi(metrics.at(2)), 0); + EXPECT_GE(/* RESPONSE_DURATION */ std::stoi(metrics.at(3)), 0); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "200"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); +} + +TEST_P(QuicHttpIntegrationTest, DeferredLoggingWithReset) { + useAccessLog( + "%PROTOCOL%,%ROUNDTRIP_DURATION%,%REQUEST_DURATION%,%RESPONSE_DURATION%,%RESPONSE_" + "CODE%,%BYTES_RECEIVED%,%ROUTE_NAME%,%VIRTUAL_CLUSTER_NAME%,%RESPONSE_CODE_DETAILS%,%" + "CONNECTION_TERMINATION_DETAILS%,%START_TIME%,%UPSTREAM_HOST%,%DURATION%,%BYTES_SENT%,%" + "RESPONSE_FLAGS%,%DOWNSTREAM_LOCAL_ADDRESS%,%UPSTREAM_CLUSTER%,%STREAM_ID%,%DYNAMIC_" + "METADATA(" + "udp.proxy.session:bytes_sent)%,%REQ(:path)%,%STREAM_INFO_REQ(:path)%"); + initialize(); + codec_client_ = makeHttpConnection(makeClientConnection(lookupPort("http"))); + auto response = codec_client_->makeHeaderOnlyRequest(default_request_headers_); + waitForNextUpstreamRequest(0); + codec_client_->close(); + ASSERT_TRUE(response->waitForReset()); + EXPECT_FALSE(response->complete()); + + std::string log = waitForAccessLog(access_log_name_); + std::vector metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 21); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + EXPECT_EQ(/* ROUNDTRIP_DURATION */ metrics.at(1), "-"); + EXPECT_GE(/* REQUEST_DURATION */ std::stoi(metrics.at(2)), 0); + EXPECT_EQ(/* RESPONSE_DURATION */ metrics.at(3), "-"); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "0"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); +} + +TEST_P(QuicHttpIntegrationTest, DeferredLoggingWithQuicReset) { + useAccessLog( + "%PROTOCOL%,%ROUNDTRIP_DURATION%,%REQUEST_DURATION%,%RESPONSE_DURATION%,%RESPONSE_" + "CODE%,%BYTES_RECEIVED%,%ROUTE_NAME%,%VIRTUAL_CLUSTER_NAME%,%RESPONSE_CODE_DETAILS%,%" + "CONNECTION_TERMINATION_DETAILS%,%START_TIME%,%UPSTREAM_HOST%,%DURATION%,%BYTES_SENT%,%" + "RESPONSE_FLAGS%,%DOWNSTREAM_LOCAL_ADDRESS%,%UPSTREAM_CLUSTER%,%STREAM_ID%,%DYNAMIC_" + "METADATA(" + "udp.proxy.session:bytes_sent)%,%REQ(:path)%,%STREAM_INFO_REQ(:path)%"); + initialize(); + codec_client_ = makeHttpConnection(lookupPort("http")); + + // omit required authority header to invoke EnvoyQuicServerStream::resetStream + auto encoder_decoder = codec_client_->startRequest(Http::TestRequestHeaderMapImpl{ + {":method", "GET"}, {":path", "/dynamo/url"}, {":scheme", "http"}}); + request_encoder_ = &encoder_decoder.first; + auto response = std::move(encoder_decoder.second); + + ASSERT_TRUE(response->waitForEndStream()); + codec_client_->close(); + ASSERT_TRUE(response->complete()); + + std::string log = waitForAccessLog(access_log_name_); + std::vector metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 21); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + EXPECT_EQ(/* ROUNDTRIP_DURATION */ metrics.at(1), "-"); + EXPECT_EQ(/* REQUEST_DURATION */ metrics.at(2), "-"); + EXPECT_EQ(/* RESPONSE_DURATION */ metrics.at(3), "-"); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "400"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); +} + +TEST_P(QuicHttpIntegrationTest, DeferredLoggingWithInternalRedirect) { + useAccessLog( + "%PROTOCOL%,%ROUNDTRIP_DURATION%,%REQUEST_DURATION%,%RESPONSE_DURATION%,%RESPONSE_" + "CODE%,%BYTES_RECEIVED%,%ROUTE_NAME%,%VIRTUAL_CLUSTER_NAME%,%RESPONSE_CODE_DETAILS%,%" + "CONNECTION_TERMINATION_DETAILS%,%START_TIME%,%UPSTREAM_HOST%,%DURATION%,%BYTES_SENT%,%" + "RESPONSE_FLAGS%,%DOWNSTREAM_LOCAL_ADDRESS%,%UPSTREAM_CLUSTER%,%STREAM_ID%,%DYNAMIC_" + "METADATA(" + "udp.proxy.session:bytes_sent)%,%REQ(:path)%,%STREAM_INFO_REQ(:path)%,%RESP(test-header)%"); + auto handle = config_helper_.createVirtualHost("handle.internal.redirect"); + handle.mutable_routes(0)->set_name("redirect"); + handle.mutable_routes(0)->mutable_route()->mutable_internal_redirect_policy(); + config_helper_.addVirtualHost(handle); + initialize(); + + codec_client_ = makeHttpConnection(lookupPort("http")); + + default_request_headers_.setHost("handle.internal.redirect"); + IntegrationStreamDecoderPtr response = + codec_client_->makeHeaderOnlyRequest(default_request_headers_); + + waitForNextUpstreamRequest(); + + Http::TestResponseHeaderMapImpl redirect_response{{":status", "302"}, + {"content-length", "0"}, + {"location", "http://authority2/new/url"}, + // Test header added to confirm that response + // headers are populated for internal redirects + {"test-header", "test-header-value"}}; + + upstream_request_->encodeHeaders(redirect_response, true); + std::string log = waitForAccessLog(access_log_name_, 0); + std::vector metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 22); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + // no roundtrip duration for internal redirect. + EXPECT_EQ(/* ROUNDTRIP_DURATION */ metrics.at(1), "-"); + EXPECT_GE(/* REQUEST_DURATION */ std::stoi(metrics.at(2)), 0); + EXPECT_GE(/* RESPONSE_DURATION */ std::stoi(metrics.at(3)), 0); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "302"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); + EXPECT_EQ(/* RESPONSE_CODE_DETAILS */ metrics.at(8), "internal_redirect"); + EXPECT_EQ(/* RESP(test-header) */ metrics.at(21), "test-header-value"); + + waitForNextUpstreamRequest(); + ASSERT(upstream_request_->headers().EnvoyOriginalUrl() != nullptr); + EXPECT_EQ("http://handle.internal.redirect/test/long/url", + upstream_request_->headers().getEnvoyOriginalUrlValue()); + EXPECT_EQ("/new/url", upstream_request_->headers().getPathValue()); + EXPECT_EQ("authority2", upstream_request_->headers().getHostValue()); + + upstream_request_->encodeHeaders(default_response_headers_, true); + + ASSERT_TRUE(response->waitForEndStream()); + ASSERT_TRUE(response->complete()); + EXPECT_EQ("200", response->headers().getStatusValue()); + EXPECT_EQ(1, test_server_->counter("cluster.cluster_0.upstream_internal_redirect_succeeded_total") + ->value()); + // 302 was never returned downstream + EXPECT_EQ(0, test_server_->counter("http.config_test.downstream_rq_3xx")->value()); + EXPECT_EQ(1, test_server_->counter("http.config_test.downstream_rq_2xx")->value()); + + log = waitForAccessLog(access_log_name_, 1); + metrics = absl::StrSplit(log, ","); + ASSERT_EQ(metrics.size(), 22); + EXPECT_EQ(/* PROTOCOL */ metrics.at(0), "HTTP/3"); + // roundtrip duration populated on final log. + EXPECT_GT(/* ROUNDTRIP_DURATION */ std::stoi(metrics.at(1)), 0); + EXPECT_GE(/* REQUEST_DURATION */ std::stoi(metrics.at(2)), 0); + EXPECT_GE(/* RESPONSE_DURATION */ std::stoi(metrics.at(3)), 0); + EXPECT_EQ(/* RESPONSE_CODE */ metrics.at(4), "200"); + EXPECT_EQ(/* BYTES_RECEIVED */ metrics.at(5), "0"); + EXPECT_EQ(/* request headers */ metrics.at(19), metrics.at(20)); + EXPECT_EQ(/* RESPONSE_CODE_DETAILS */ metrics.at(8), "via_upstream"); + // no test header + EXPECT_EQ(/* RESP(test-header) */ metrics.at(21), "-"); +} + class QuicInplaceLdsIntegrationTest : public QuicHttpIntegrationTest { public: void inplaceInitialize(bool add_default_filter_chain = false) { diff --git a/test/integration/redirect_integration_test.cc b/test/integration/redirect_integration_test.cc index d746e00979766..bb187b731d297 100644 --- a/test/integration/redirect_integration_test.cc +++ b/test/integration/redirect_integration_test.cc @@ -219,8 +219,7 @@ TEST_P(RedirectIntegrationTest, BasicInternalRedirectDownstreamBytesCount) { upstream_request_->encodeHeaders(redirect_response_, true); expectDownstreamBytesSentAndReceived(BytesCountExpectation(0, 63, 0, 31), BytesCountExpectation(0, 42, 0, 42), - BytesCountExpectation(0, 42, 0, 42), 0); - + BytesCountExpectation(0, 8, 0, 6), 0); waitForNextUpstreamRequest(); upstream_request_->encodeHeaders(default_response_headers_, true); @@ -228,7 +227,7 @@ TEST_P(RedirectIntegrationTest, BasicInternalRedirectDownstreamBytesCount) { ASSERT_TRUE(response->complete()); expectDownstreamBytesSentAndReceived(BytesCountExpectation(140, 63, 121, 31), BytesCountExpectation(77, 42, 77, 42), - BytesCountExpectation(77, 42, 77, 42), 1); + BytesCountExpectation(9, 8, 9, 6), 1); } TEST_P(RedirectIntegrationTest, BasicInternalRedirectUpstreamBytesCount) { @@ -611,9 +610,15 @@ TEST_P(RedirectIntegrationTest, InternalRedirectToDestinationWithResponseBody) { config_helper_.addConfigModifier( [](envoy::extensions::filters::network::http_connection_manager::v3::HttpConnectionManager& hcm) { hcm.set_via("via_value"); }); - config_helper_.prependFilter(R"EOF( + if (downstreamProtocol() == Http::CodecType::HTTP3) { + config_helper_.prependFilter(R"EOF( + name: pause-filter-for-quic + )EOF"); + } else { + config_helper_.prependFilter(R"EOF( name: pause-filter )EOF"); + } initialize(); codec_client_ = makeHttpConnection(lookupPort("http")); @@ -707,7 +712,10 @@ TEST_P(RedirectIntegrationTest, InternalRedirectHandledByDirectResponse) { } INSTANTIATE_TEST_SUITE_P(Protocols, RedirectIntegrationTest, - testing::ValuesIn(HttpProtocolIntegrationTest::getProtocolTestParams()), + testing::ValuesIn(HttpProtocolIntegrationTest::getProtocolTestParams( + {Http::CodecType::HTTP1, Http::CodecType::HTTP2, + Http::CodecType::HTTP3}, + {Http::CodecType::HTTP1, Http::CodecType::HTTP2})), HttpProtocolIntegrationTest::protocolTestParamsToString); } // namespace Envoy diff --git a/test/mocks/http/stream_decoder.cc b/test/mocks/http/stream_decoder.cc index 76145b6dc43f6..ae778dff5c886 100644 --- a/test/mocks/http/stream_decoder.cc +++ b/test/mocks/http/stream_decoder.cc @@ -7,11 +7,12 @@ namespace Envoy { namespace Http { MockRequestDecoder::MockRequestDecoder() { - ON_CALL(*this, decodeHeaders_(_, _)).WillByDefault(Invoke([](RequestHeaderMapPtr& headers, bool) { - // Check to see that method is not-null. Path can be null for CONNECT and authority can be null - // at the codec level. - ASSERT_NE(nullptr, headers->Method()); - })); + ON_CALL(*this, decodeHeaders_(_, _)) + .WillByDefault(Invoke([](RequestHeaderMapSharedPtr& headers, bool) { + // Check to see that method is not-null. Path can be null for CONNECT and authority can be + // null at the codec level. + ASSERT_NE(nullptr, headers->Method()); + })); } MockRequestDecoder::~MockRequestDecoder() = default; diff --git a/test/mocks/http/stream_decoder.h b/test/mocks/http/stream_decoder.h index 8bf5e5305d4fd..30e2ccf8a5a9f 100644 --- a/test/mocks/http/stream_decoder.h +++ b/test/mocks/http/stream_decoder.h @@ -23,14 +23,15 @@ class MockRequestDecoder : public RequestDecoder { absl::string_view details)); MOCK_METHOD(StreamInfo::StreamInfo&, streamInfo, ()); - void decodeHeaders(RequestHeaderMapPtr&& headers, bool end_stream) override { + void decodeHeaders(RequestHeaderMapSharedPtr&& headers, bool end_stream) override { decodeHeaders_(headers, end_stream); } void decodeTrailers(RequestTrailerMapPtr&& trailers) override { decodeTrailers_(trailers); } // Http::RequestDecoder - MOCK_METHOD(void, decodeHeaders_, (RequestHeaderMapPtr & headers, bool end_stream)); + MOCK_METHOD(void, decodeHeaders_, (RequestHeaderMapSharedPtr & headers, bool end_stream)); MOCK_METHOD(void, decodeTrailers_, (RequestTrailerMapPtr & trailers)); + MOCK_METHOD(std::list, accessLogHandlers, ()); }; class MockResponseDecoder : public ResponseDecoder { diff --git a/test/mocks/http/stream_encoder.h b/test/mocks/http/stream_encoder.h index efe3626af3ab7..e8ce13c2b698a 100644 --- a/test/mocks/http/stream_encoder.h +++ b/test/mocks/http/stream_encoder.h @@ -49,6 +49,11 @@ class MockResponseEncoder : public ResponseEncoder { MOCK_METHOD(void, encodeHeaders, (const ResponseHeaderMap& headers, bool end_stream)); MOCK_METHOD(void, encodeTrailers, (const ResponseTrailerMap& trailers)); MOCK_METHOD(void, setRequestDecoder, (RequestDecoder & decoder)); + MOCK_METHOD(void, setDeferredLoggingHeadersAndTrailers, + (Http::RequestHeaderMapConstSharedPtr request_header_map, + Http::ResponseHeaderMapConstSharedPtr response_header_map, + Http::ResponseTrailerMapConstSharedPtr response_trailer_map, + StreamInfo::StreamInfo& stream_info)); // Http::StreamEncoder MOCK_METHOD(void, encodeData, (Buffer::Instance & data, bool end_stream)); diff --git a/tools/spelling/spelling_dictionary.txt b/tools/spelling/spelling_dictionary.txt index 2ba06fbfb2824..53f2b5d13586f 100644 --- a/tools/spelling/spelling_dictionary.txt +++ b/tools/spelling/spelling_dictionary.txt @@ -1136,6 +1136,7 @@ responder restarter resync ret +retransmitted retransmitting retriable retriggers