diff --git a/source/common/http/http1/conn_pool.cc b/source/common/http/http1/conn_pool.cc index 5af1f0181104..5df4c4219c2e 100644 --- a/source/common/http/http1/conn_pool.cc +++ b/source/common/http/http1/conn_pool.cc @@ -155,6 +155,7 @@ void ConnPoolImpl::onConnectionEvent(ActiveClient& client, uint32_t events) { checkForDrained(); } } else if (events & Network::ConnectionEvent::Connected) { + conn_connect_ms_->complete(); processIdleClient(client); } @@ -262,6 +263,8 @@ ConnPoolImpl::ActiveClient::ActiveClient(ConnPoolImpl& parent) connect_timer_(parent_.dispatcher_.createTimer([this]() -> void { onConnectTimeout(); })), remaining_requests_(parent_.host_->cluster().maxRequestsPerConnection()) { + parent_.conn_connect_ms_ = + parent_.host_->cluster().stats().upstream_cx_connect_ms_.allocateSpan(); Upstream::Host::CreateConnectionData data = parent_.host_->createConnection(parent_.dispatcher_); real_host_description_ = data.host_description_; codec_client_ = parent_.createCodecClient(data); diff --git a/source/common/http/http1/conn_pool.h b/source/common/http/http1/conn_pool.h index f4750337ad0f..8059e3ffc029 100644 --- a/source/common/http/http1/conn_pool.h +++ b/source/common/http/http1/conn_pool.h @@ -121,6 +121,7 @@ class ConnPoolImpl : Logger::Loggable<Logger::Id::pool>, public ConnectionPool:: void onResponseComplete(ActiveClient& client); void processIdleClient(ActiveClient& client); + Stats::TimespanPtr conn_connect_ms_; Event::Dispatcher& dispatcher_; Upstream::ConstHostPtr host_; std::list<ActiveClientPtr> ready_clients_; diff --git a/source/common/http/http2/conn_pool.cc b/source/common/http/http2/conn_pool.cc index cdec99a7c1f0..0b3ebdb95d03 100644 --- a/source/common/http/http2/conn_pool.cc +++ b/source/common/http/http2/conn_pool.cc @@ -131,6 +131,10 @@ void ConnPoolImpl::onConnectionEvent(ActiveClient& client, uint32_t events) { } } + if (events & Network::ConnectionEvent::Connected) { + conn_connect_ms_->complete(); + } + if (client.connect_timer_) { client.connect_timer_->disableTimer(); client.connect_timer_.reset(); @@ -206,6 +210,8 @@ ConnPoolImpl::ActiveClient::ActiveClient(ConnPoolImpl& parent) : parent_(parent), connect_timer_(parent_.dispatcher_.createTimer([this]() -> void { onConnectTimeout(); })) { + parent_.conn_connect_ms_ = + parent_.host_->cluster().stats().upstream_cx_connect_ms_.allocateSpan(); Upstream::Host::CreateConnectionData data = parent_.host_->createConnection(parent_.dispatcher_); real_host_description_ = data.host_description_; client_ = parent_.createCodecClient(data); diff --git a/source/common/http/http2/conn_pool.h b/source/common/http/http2/conn_pool.h index 672fa077b1b0..a59d30a38cf1 100644 --- a/source/common/http/http2/conn_pool.h +++ b/source/common/http/http2/conn_pool.h @@ -71,6 +71,7 @@ class ConnPoolImpl : Logger::Loggable<Logger::Id::pool>, public ConnectionPool:: void onStreamDestroy(ActiveClient& client); void onStreamReset(ActiveClient& client, Http::StreamResetReason reason); + Stats::TimespanPtr conn_connect_ms_; Event::Dispatcher& dispatcher_; Upstream::ConstHostPtr host_; Stats::Store& stats_store_; diff --git a/test/common/http/http1/conn_pool_test.cc b/test/common/http/http1/conn_pool_test.cc index 559f33fe3af2..269d75c2de9b 100644 --- a/test/common/http/http1/conn_pool_test.cc +++ b/test/common/http/http1/conn_pool_test.cc @@ -171,6 +171,24 @@ struct ActiveTestRequest { ConnPoolCallbacks callbacks_; }; +/** + * Test all timing stats are set. + */ +TEST_F(Http1ConnPoolImplTest, VerifyTimingStats) { + EXPECT_CALL(cluster_.stats_store_, + deliverTimingToSinks("cluster.fake_cluster.upstream_cx_connect_ms", _)); + EXPECT_CALL(cluster_.stats_store_, + deliverTimingToSinks("cluster.fake_cluster.upstream_cx_length_ms", _)); + + ActiveTestRequest r1(*this, 0, ActiveTestRequest::Type::CreateConnection); + r1.startRequest(); + r1.completeResponse(false); + + EXPECT_CALL(conn_pool_, onClientDestroy()); + conn_pool_.test_clients_[0].connection_->raiseEvents(Network::ConnectionEvent::RemoteClose); + dispatcher_.clearDeferredDeleteList(); +} + /** * Tests a request that generates a new connection, completes, and then a second request that uses * the same connection. diff --git a/test/common/http/http2/conn_pool_test.cc b/test/common/http/http2/conn_pool_test.cc index 27b5a2b0caeb..03738145a813 100644 --- a/test/common/http/http2/conn_pool_test.cc +++ b/test/common/http/http2/conn_pool_test.cc @@ -110,6 +110,25 @@ class ActiveTestRequest { NiceMock<Http::MockStreamEncoder> inner_encoder_; }; +TEST_F(Http2ConnPoolImplTest, VerifyConectionTimingStats) { + expectClientCreate(); + EXPECT_CALL(cluster_.stats_store_, + deliverTimingToSinks("cluster.fake_cluster.upstream_cx_connect_ms", _)); + EXPECT_CALL(cluster_.stats_store_, + deliverTimingToSinks("cluster.fake_cluster.upstream_cx_length_ms", _)); + + ActiveTestRequest r1(*this, 0); + EXPECT_CALL(r1.inner_encoder_, encodeHeaders(_, true)); + r1.callbacks_.outer_encoder_->encodeHeaders(HeaderMapImpl{}, true); + expectClientConnect(0); + EXPECT_CALL(r1.decoder_, decodeHeaders_(_, true)); + r1.inner_decoder_->decodeHeaders(HeaderMapPtr{new HeaderMapImpl{}}, true); + + test_clients_[0].connection_->raiseEvents(Network::ConnectionEvent::RemoteClose); + EXPECT_CALL(*this, onClientDestroy()); + dispatcher_.clearDeferredDeleteList(); +} + TEST_F(Http2ConnPoolImplTest, RequestAndResponse) { InSequence s; diff --git a/test/mocks/stats/mocks.cc b/test/mocks/stats/mocks.cc index 9578ccb8457f..ccabe57954af 100644 --- a/test/mocks/stats/mocks.cc +++ b/test/mocks/stats/mocks.cc @@ -13,4 +13,7 @@ MockTimespan::~MockTimespan() {} MockStore::MockStore() { ON_CALL(*this, counter(_)).WillByDefault(ReturnRef(counter_)); } MockStore::~MockStore() {} +MockIsolatedStatsStore::MockIsolatedStatsStore() {} +MockIsolatedStatsStore::~MockIsolatedStatsStore() {} + } // Stats diff --git a/test/mocks/stats/mocks.h b/test/mocks/stats/mocks.h index d3e32d7a9167..d31c647ab97c 100644 --- a/test/mocks/stats/mocks.h +++ b/test/mocks/stats/mocks.h @@ -1,5 +1,9 @@ +#pragma once + #include "envoy/stats/stats.h" +#include "common/stats/stats_impl.h" + namespace Stats { class MockCounter : public Counter { @@ -42,4 +46,16 @@ class MockStore : public Store { testing::NiceMock<MockCounter> counter_; }; +/** + * With IsolatedStoreImpl it's hard to test timing stats. + * MockIsolatedStatsStore mocks only deliverTimingToSinks for better testing. + */ +class MockIsolatedStatsStore : public IsolatedStoreImpl { +public: + MockIsolatedStatsStore(); + ~MockIsolatedStatsStore(); + + MOCK_METHOD2(deliverTimingToSinks, void(const std::string&, std::chrono::milliseconds)); +}; + } // Stats diff --git a/test/mocks/upstream/mocks.h b/test/mocks/upstream/mocks.h index 0943f37ae785..571e8d74ee2f 100644 --- a/test/mocks/upstream/mocks.h +++ b/test/mocks/upstream/mocks.h @@ -9,6 +9,7 @@ #include "test/mocks/http/mocks.h" #include "test/mocks/runtime/mocks.h" +#include "test/mocks/stats/mocks.h" using testing::NiceMock; @@ -56,7 +57,7 @@ class MockCluster : public Cluster { const std::string alt_stat_name_{"fake_alt_cluster"}; std::list<MemberUpdateCb> callbacks_; uint64_t max_requests_per_connection_{}; - Stats::IsolatedStoreImpl stats_store_; + NiceMock<Stats::MockIsolatedStatsStore> stats_store_; const std::string stat_prefix_{"cluster.fake_cluster."}; ClusterStats stats_; std::unique_ptr<Upstream::ResourceManager> resource_manager_;