Commit 25d2845e authored by Jianfeng Wang's avatar Jianfeng Wang Committed by Commit Bot

Adds methods to track the peak mapping

The number of in-flight requests can tell the observed queueing delay in
the next few seconds. The higher count of in-flight requests would cause
a high network queueing delay. Only tracks the peak values to eliminate
the noises in the data.

Adds methods to track the mapping between the peak number of in-flight
requests to the peak observed queueing delay within a measurement
period.

Change-Id: Id7093ffe65ad6cb5f7a0d050a403040d4bda9fa3
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1700280
Commit-Queue: Jianfeng Wang <jfwang@chromium.org>
Reviewed-by: default avatarTarun Bansal <tbansal@chromium.org>
Reviewed-by: default avatarRyan Sturm <ryansturm@chromium.org>
Cr-Commit-Position: refs/heads/master@{#678052}
parent 8f156fc5
......@@ -13,12 +13,32 @@
namespace net {
namespace {
// The threshold for the observed peak queueing delay in milliseconds.
// A peak queueing delay is HIGH if it exceeds this threshold. The value is the
// 98th percentile value of the peak queueing delay observed by all requests.
static constexpr int64_t kHighQueueingDelayMsec = 5000;
// The minimal time interval between two consecutive empty queue observations
// when the number of in-flight requests is relatively low (i.e. 2). This time
// interval is required so that a new measurement period could start.
static constexpr int64_t kMinEmptyQueueObservingTimeMsec = 1500;
} // namespace
namespace nqe {
namespace internal {
NetworkCongestionAnalyzer::NetworkCongestionAnalyzer()
: recent_active_hosts_count_(0u) {}
NetworkCongestionAnalyzer::NetworkCongestionAnalyzer(
const base::TickClock* tick_clock)
: tick_clock_(tick_clock),
recent_active_hosts_count_(0u),
count_inflight_requests_for_peak_queueing_delay_(0u),
peak_count_inflight_requests_measurement_period_(0u) {
DCHECK(tick_clock_);
}
NetworkCongestionAnalyzer::~NetworkCongestionAnalyzer() {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
......@@ -139,6 +159,88 @@ void NetworkCongestionAnalyzer::ComputeRecentQueueingDelay(
}
}
bool NetworkCongestionAnalyzer::ShouldStartNewMeasurement(
const base::TimeDelta& delay,
size_t count_inflight_requests) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
// The queue is not empty if either the queueing delay is high or the number
// of in-flight requests is high.
if (delay > base::TimeDelta::FromMilliseconds(500) ||
count_inflight_requests >= 3) {
observing_empty_queue_timestamp_ = base::nullopt;
return false;
}
// Starts a new measurement period immediately if there is very few number of
// in-flight requests.
if (count_inflight_requests <= 1) {
observing_empty_queue_timestamp_ = base::nullopt;
return true;
}
base::TimeTicks now = tick_clock_->NowTicks();
// Requires a sufficient time interval between consecutive empty queue
// observations to claim the queue is empty.
if (observing_empty_queue_timestamp_.has_value()) {
if (now - observing_empty_queue_timestamp_.value() >=
base::TimeDelta::FromMilliseconds(kMinEmptyQueueObservingTimeMsec)) {
observing_empty_queue_timestamp_ = base::nullopt;
return true;
}
} else {
observing_empty_queue_timestamp_ = now;
}
return false;
}
void NetworkCongestionAnalyzer::UpdatePeakDelayMapping(
const base::TimeDelta& delay,
size_t count_inflight_requests) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
// Discards an abnormal observation. This high queueing delay is likely
// caused by retransmission packets from a previous measurement period.
if (delay >= base::TimeDelta::FromSeconds(20))
return;
if (ShouldStartNewMeasurement(delay, count_inflight_requests)) {
// This is the logic to export the tracked mapping data from the last
// measurement period.
// Updates the count of in-flight requests that would likely cause a high
// network queueing delay later.
if (peak_queueing_delay_ >=
base::TimeDelta::FromMilliseconds(kHighQueueingDelayMsec)) {
count_inflight_requests_causing_high_delay_ =
count_inflight_requests_for_peak_queueing_delay_;
}
// Resets the tracked data for the new measurement period.
peak_queueing_delay_ = delay;
count_inflight_requests_for_peak_queueing_delay_ = count_inflight_requests;
peak_count_inflight_requests_measurement_period_ = count_inflight_requests;
} else {
// This is the logic to update the tracking data.
// First, updates the pending peak count of in-flight requests if a higher
// number of in-flight requests is observed.
// Second, updates the peak queueing delay and the peak count of inflight
// requests if a higher queueing delay is observed. The new peak queueing
// delay should be mapped to the peak count of in-flight requests that are
// observed before within this measurement period.
peak_count_inflight_requests_measurement_period_ =
std::max(peak_count_inflight_requests_measurement_period_,
count_inflight_requests);
if (delay > peak_queueing_delay_) {
// Updates the peak queueing delay and the count of in-flight requests
// that are responsible for the delay.
peak_queueing_delay_ = delay;
count_inflight_requests_for_peak_queueing_delay_ =
peak_count_inflight_requests_measurement_period_;
}
}
}
void NetworkCongestionAnalyzer::set_recent_downlink_throughput_kbps(
const int32_t downlink_kbps) {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
......
......@@ -9,6 +9,7 @@
#include <map>
#include <unordered_map>
#include "base/gtest_prod_util.h"
#include "base/macros.h"
#include "base/optional.h"
#include "base/sequence_checker.h"
......@@ -30,7 +31,7 @@ namespace internal {
// recent downlink throughput.
class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
public:
NetworkCongestionAnalyzer();
explicit NetworkCongestionAnalyzer(const base::TickClock* tick_clock);
~NetworkCongestionAnalyzer();
// Returns the number of hosts that are involved in the last attempt of
......@@ -59,6 +60,13 @@ class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
historical_rtt_stats,
const int32_t downlink_kbps);
// Updates new observations of queueing delay and count of in-flight requests
// in order to track peak queueing delay and peak count of in-flight requests.
// |delay| is a newly observed queueing delay. |count_inflight_requests| is a
// newly observed count of in-flight requests.
void UpdatePeakDelayMapping(const base::TimeDelta& delay,
size_t count_inflight_requests);
base::Optional<float> recent_queue_length() const {
return recent_queue_length_;
}
......@@ -68,6 +76,20 @@ class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
}
private:
FRIEND_TEST_ALL_PREFIXES(NetworkCongestionAnalyzerTest,
TestUpdatePeakDelayMapping);
base::Optional<size_t> count_inflight_requests_causing_high_delay() const {
return count_inflight_requests_causing_high_delay_;
}
// Returns true if a new measurement period should start. A new measurement
// period should start when the observed queueing delay is small and there are
// few in-flight requests. |delay| is a new queueing delay observation.
// |count_inflight_requests| is a new observed count of in-flight requests.
bool ShouldStartNewMeasurement(const base::TimeDelta& delay,
size_t count_inflight_requests);
// Starts tracking the peak queueing delay for |request|.
void TrackPeakQueueingDelayBegin(const URLRequest* request);
......@@ -86,9 +108,13 @@ class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
return recent_downlink_throughput_kbps_;
}
// Guaranteed to be non-null during the lifetime of |this|.
const base::TickClock* tick_clock_;
// Recent downstream throughput estimate. It is the median of most recent
// downstream throughput observations (in kilobits per second).
base::Optional<int32_t> recent_downlink_throughput_kbps_;
// Time of transmitting one 1500-Byte TCP packet under
// |recent_downlink_throughput_kbps_|.
base::Optional<int32_t> recent_downlink_per_packet_time_ms_;
......@@ -96,6 +122,7 @@ class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
// The estimate of packet queue length. Computation is done based on the last
// observed downlink throughput.
base::Optional<float> recent_queue_length_;
// The estimate of queueing delay induced by packet queue.
base::TimeDelta recent_queueing_delay_;
......@@ -112,6 +139,28 @@ class NET_EXPORT_PRIVATE NetworkCongestionAnalyzer {
// recent queueing delay.
size_t recent_active_hosts_count_;
// The peak queueing delay that is observed within the current ongoing
// measurement period.
base::TimeDelta peak_queueing_delay_;
// The peak number of in-flight requests that are responsible for the peak
// queueing delay within the current ongoing measurement period. These
// requests should be in-flight before the peak queueing delay is observed.
size_t count_inflight_requests_for_peak_queueing_delay_;
// The peak number of in-flight requests during the current measurement
// period. It updates the |count_inflight_requests_for_peak_queueing_delay_|
// only if a higher queueing delay is observed later.
size_t peak_count_inflight_requests_measurement_period_;
// Timestamp when the app started observing an empty queue. Resets to nullopt
// if the queue is unlikely to be empty or if a new measurement period starts.
base::Optional<base::TimeTicks> observing_empty_queue_timestamp_;
// The count of in-flight requests that would cause a high network queueing
// delay.
base::Optional<size_t> count_inflight_requests_causing_high_delay_;
SEQUENCE_CHECKER(sequence_checker_);
DISALLOW_COPY_AND_ASSIGN(NetworkCongestionAnalyzer);
......
......@@ -8,6 +8,7 @@
#include "base/macros.h"
#include "base/optional.h"
#include "base/test/simple_test_tick_clock.h"
#include "base/time/time.h"
#include "net/nqe/network_quality.h"
#include "net/nqe/observation_buffer.h"
......@@ -20,12 +21,20 @@ namespace nqe {
namespace internal {
namespace {
constexpr float kEpsilon = 0.001f;
// These values should remain synchronized with the values in
// net/nqe/network_congestion_analyzer.cc.
constexpr int64_t kHighQueueingDelayMsec = 5000;
constexpr int64_t kMinEmptyQueueObservingTimeMsec = 1500;
// Verify that the network queueing delay is computed correctly based on RTT
// and downlink throughput observations.
TEST(NetworkCongestionAnalyzerTest, TestComputingQueueingDelay) {
NetworkCongestionAnalyzer analyzer;
base::SimpleTestTickClock tick_clock;
NetworkCongestionAnalyzer analyzer(&tick_clock);
std::map<uint64_t, CanonicalStats> recent_rtt_stats;
std::map<uint64_t, CanonicalStats> historical_rtt_stats;
int32_t downlink_kbps = nqe::internal::INVALID_RTT_THROUGHPUT;
......@@ -75,6 +84,82 @@ TEST(NetworkCongestionAnalyzerTest, TestComputingQueueingDelay) {
} // namespace
// Verify that the peak queueing delay is correctly mapped to the count of
// in-flight requests that are responsible for that delay.
TEST(NetworkCongestionAnalyzerTest, TestUpdatePeakDelayMapping) {
base::SimpleTestTickClock tick_clock;
NetworkCongestionAnalyzer analyzer(&tick_clock);
EXPECT_EQ(base::nullopt,
analyzer.count_inflight_requests_causing_high_delay());
// Checks that a measurement period starts correctly when an empty queue
// observation shows up.
EXPECT_FALSE(analyzer.ShouldStartNewMeasurement(
base::TimeDelta::FromMilliseconds(500), 2));
EXPECT_TRUE(analyzer.ShouldStartNewMeasurement(
base::TimeDelta::FromMilliseconds(500), 0));
// Checks that a new measurement period starts after waiting for a sufficient
// time interval when the number of in-flight requests is relatively low (=2).
EXPECT_FALSE(analyzer.ShouldStartNewMeasurement(
base::TimeDelta::FromMilliseconds(500), 2));
tick_clock.Advance(
base::TimeDelta::FromMilliseconds(kMinEmptyQueueObservingTimeMsec / 2));
EXPECT_FALSE(analyzer.ShouldStartNewMeasurement(
base::TimeDelta::FromMilliseconds(500), 2));
tick_clock.Advance(
base::TimeDelta::FromMilliseconds(kMinEmptyQueueObservingTimeMsec / 2));
EXPECT_TRUE(analyzer.ShouldStartNewMeasurement(
base::TimeDelta::FromMilliseconds(500), 2));
// Checks that the count of in-flight requests for peak queueing delay is
// correctly recorded.
// Case #1: the peak queueing delay was observed after the max count (7) of
// in-flight requests was observed.
const size_t expected_count_requests_1 = 7;
std::vector<std::pair<base::TimeDelta, size_t>> queueing_delay_samples_1 = {
std::make_pair(base::TimeDelta::FromMilliseconds(10), 1),
std::make_pair(base::TimeDelta::FromMilliseconds(10), 3),
std::make_pair(base::TimeDelta::FromMilliseconds(400), 5),
std::make_pair(base::TimeDelta::FromMilliseconds(800),
expected_count_requests_1),
std::make_pair(base::TimeDelta::FromMilliseconds(kHighQueueingDelayMsec),
5),
std::make_pair(base::TimeDelta::FromMilliseconds(1000), 3),
std::make_pair(base::TimeDelta::FromMilliseconds(700), 3),
std::make_pair(base::TimeDelta::FromMilliseconds(600), 1),
std::make_pair(base::TimeDelta::FromMilliseconds(300), 0),
};
for (const auto& sample : queueing_delay_samples_1) {
analyzer.UpdatePeakDelayMapping(sample.first, sample.second);
}
EXPECT_EQ(expected_count_requests_1,
analyzer.count_inflight_requests_causing_high_delay().value_or(0));
// Case #2: the peak queueing delay is observed before the max count (11) of
// in-flight requests was observed. The 8 requests should be responsible for
// the peak queueing delay.
const size_t expected_count_requests_2 = 10;
std::vector<std::pair<base::TimeDelta, size_t>> queueing_delay_samples_2 = {
std::make_pair(base::TimeDelta::FromMilliseconds(10), 1),
std::make_pair(base::TimeDelta::FromMilliseconds(10), 3),
std::make_pair(base::TimeDelta::FromMilliseconds(400), 5),
std::make_pair(base::TimeDelta::FromMilliseconds(800), 5),
std::make_pair(base::TimeDelta::FromMilliseconds(kHighQueueingDelayMsec),
expected_count_requests_2),
std::make_pair(base::TimeDelta::FromMilliseconds(3000), 11),
std::make_pair(base::TimeDelta::FromMilliseconds(700), 3),
std::make_pair(base::TimeDelta::FromMilliseconds(600), 1),
std::make_pair(base::TimeDelta::FromMilliseconds(300), 0),
};
for (const auto& sample : queueing_delay_samples_2) {
analyzer.UpdatePeakDelayMapping(sample.first, sample.second);
}
EXPECT_EQ(expected_count_requests_2,
analyzer.count_inflight_requests_causing_high_delay().value_or(0));
}
} // namespace internal
} // namespace nqe
......
......@@ -169,6 +169,7 @@ NetworkQualityEstimator::NetworkQualityEstimator(
transport_rtt_observation_count_last_ect_computation_(0),
new_rtt_observations_since_last_ect_computation_(0),
new_throughput_observations_since_last_ect_computation_(0),
network_congestion_analyzer_(tick_clock_),
effective_connection_type_(EFFECTIVE_CONNECTION_TYPE_UNKNOWN),
cached_estimate_applied_(false),
net_log_(NetLogWithSource::Make(
......@@ -774,6 +775,17 @@ void NetworkQualityEstimator::ComputeNetworkQueueingDelay() {
network_congestion_analyzer_.ComputeRecentQueueingDelay(
recent_rtt_stats, historical_rtt_stats, downlink_kbps);
// Gets the total number of inflight requests including hanging GETs. The app
// cannot determine whether a request is hanging or is still in the wire.
size_t count_inflight_requests =
throughput_analyzer_->CountTotalInFlightRequests();
// Tracks the mapping between the peak observed queueing delay to the peak
// count of in-flight requests.
network_congestion_analyzer_.UpdatePeakDelayMapping(
network_congestion_analyzer_.recent_queueing_delay(),
count_inflight_requests);
}
void NetworkQualityEstimator::ComputeEffectiveConnectionType() {
......
......@@ -385,11 +385,16 @@ int64_t ThroughputAnalyzer::GetBitsReceived() const {
return NetworkActivityMonitor::GetInstance()->GetBytesReceived() * 8;
}
size_t ThroughputAnalyzer::CountInFlightRequests() const {
size_t ThroughputAnalyzer::CountActiveInFlightRequests() const {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
return requests_.size();
}
size_t ThroughputAnalyzer::CountTotalInFlightRequests() const {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
return response_content_sizes_.size();
}
int64_t ThroughputAnalyzer::CountTotalContentSizeBytes() const {
DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
......
......@@ -110,7 +110,11 @@ class NET_EXPORT_PRIVATE ThroughputAnalyzer {
// Returns the number of in-flight requests that can be used for computing
// throughput.
size_t CountInFlightRequests() const;
size_t CountActiveInFlightRequests() const;
// Returns the total number of in-flight requests. This also includes hanging
// requests.
size_t CountTotalInFlightRequests() const;
// Returns the sum of expected response content size in bytes for all inflight
// requests. Request with an unknown response content size have the default
......
......@@ -87,7 +87,7 @@ class TestThroughputAnalyzer : public internal::ThroughputAnalyzer {
context->set_host_resolver(&mock_host_resolver_);
}
using internal::ThroughputAnalyzer::CountInFlightRequests;
using internal::ThroughputAnalyzer::CountActiveInFlightRequests;
using internal::ThroughputAnalyzer::
disable_throughput_measurements_for_testing;
using internal::ThroughputAnalyzer::EraseHangingRequests;
......@@ -315,18 +315,18 @@ TEST_F(ThroughputAnalyzerTest, TestHangingRequests) {
if (test.requests_hang_duration >= base::TimeDelta())
base::PlatformThread::Sleep(test.requests_hang_duration);
EXPECT_EQ(num_requests, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(num_requests, throughput_analyzer.CountActiveInFlightRequests());
for (size_t i = 0; i < num_requests; ++i) {
throughput_analyzer.NotifyRequestCompleted(*requests_not_local.at(i));
if (!test.expect_throughput_observation) {
// All in-flight requests should be marked as hanging, and thus should
// be deleted from the set of in-flight requests.
EXPECT_EQ(0u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(0u, throughput_analyzer.CountActiveInFlightRequests());
} else {
// One request should be deleted at one time.
EXPECT_EQ(requests_not_local.size() - i - 1,
throughput_analyzer.CountInFlightRequests());
throughput_analyzer.CountActiveInFlightRequests());
}
}
......@@ -379,35 +379,35 @@ TEST_F(ThroughputAnalyzerTest, TestHangingRequestsCheckedOnlyPeriodically) {
throughput_analyzer.NotifyStartTransaction(*requests_not_local.at(i));
}
EXPECT_EQ(2u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(2u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(3500));
// Current time is t = 5.5 seconds.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(2u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(2u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(1000));
// Current time is t = 6.5 seconds. One request should be marked as hanging.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
// Current time is t = 6.5 seconds. Calling NotifyBytesRead again should not
// run the hanging request checker since the last check was at t=6.5 seconds.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(600));
// Current time is t = 7.1 seconds. Calling NotifyBytesRead again should not
// run the hanging request checker since the last check was at t=6.5 seconds
// (less than 1 second ago).
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(400));
// Current time is t = 7.5 seconds. Calling NotifyBytesRead again should run
// the hanging request checker since the last check was at t=6.5 seconds (at
// least 1 second ago).
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(0u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(0u, throughput_analyzer.CountActiveInFlightRequests());
}
// Tests that the last received time for a request is updated when data is
......@@ -449,19 +449,19 @@ TEST_F(ThroughputAnalyzerTest, TestLastReceivedTimeIsUpdated) {
// Current time is t=4.0 seconds.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
// The request will be marked as hanging at t=9 seconds.
throughput_analyzer.NotifyBytesRead(*request_not_local);
tick_clock.Advance(base::TimeDelta::FromMilliseconds(4000));
// Current time is t=8 seconds.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(2000));
// Current time is t=10 seconds.
throughput_analyzer.EraseHangingRequests(*some_other_request);
EXPECT_EQ(0u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(0u, throughput_analyzer.CountActiveInFlightRequests());
}
// Test that a request that has been hanging for a long time is deleted
......@@ -494,19 +494,19 @@ TEST_F(ThroughputAnalyzerTest, TestRequestDeletedImmediately) {
// Start time for the request is t=0 second. The request will be marked as
// hanging at t=2 seconds.
throughput_analyzer.NotifyStartTransaction(*request_not_local);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
tick_clock.Advance(base::TimeDelta::FromMilliseconds(2900));
// Current time is t=2.9 seconds.
throughput_analyzer.EraseHangingRequests(*request_not_local);
EXPECT_EQ(1u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(1u, throughput_analyzer.CountActiveInFlightRequests());
// |request_not_local| should be deleted since it has been idle for 2.4
// seconds.
tick_clock.Advance(base::TimeDelta::FromMilliseconds(500));
throughput_analyzer.NotifyBytesRead(*request_not_local);
EXPECT_EQ(0u, throughput_analyzer.CountInFlightRequests());
EXPECT_EQ(0u, throughput_analyzer.CountActiveInFlightRequests());
}
// Tests if the throughput observation is taken correctly when local and network
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment