diff options
Diffstat (limited to 'chromium/components/network_time')
3 files changed, 275 insertions, 196 deletions
diff --git a/chromium/components/network_time/network_time_tracker.cc b/chromium/components/network_time/network_time_tracker.cc index 0a3651c9ca5..0a7cdec62c5 100644 --- a/chromium/components/network_time/network_time_tracker.cc +++ b/chromium/components/network_time/network_time_tracker.cc @@ -206,14 +206,14 @@ NetworkTimeTracker::NetworkTimeTracker( tick_clock_(std::move(tick_clock)), pref_service_(pref_service), time_query_completed_(false) { - const base::Value* time_mapping = - pref_service_->GetDictionary(prefs::kNetworkTimeMapping); - absl::optional<double> time_js = time_mapping->FindDoubleKey(kPrefTime); - absl::optional<double> ticks_js = time_mapping->FindDoubleKey(kPrefTicks); + const base::Value::Dict& time_mapping = + pref_service_->GetValueDict(prefs::kNetworkTimeMapping); + absl::optional<double> time_js = time_mapping.FindDouble(kPrefTime); + absl::optional<double> ticks_js = time_mapping.FindDouble(kPrefTicks); absl::optional<double> uncertainty_js = - time_mapping->FindDoubleKey(kPrefUncertainty); + time_mapping.FindDouble(kPrefUncertainty); absl::optional<double> network_time_js = - time_mapping->FindDoubleKey(kPrefNetworkTime); + time_mapping.FindDouble(kPrefNetworkTime); if (time_js && ticks_js && uncertainty_js && network_time_js) { time_at_last_measurement_ = base::Time::FromJsTime(*time_js); ticks_at_last_measurement_ = @@ -279,15 +279,18 @@ void NetworkTimeTracker::UpdateNetworkTime(base::Time network_time, resolution + latency + kNumTimeMeasurements * base::Milliseconds(kTicksResolutionMs); - base::DictionaryValue time_mapping; - time_mapping.SetDouble(kPrefTime, time_at_last_measurement_.ToJsTime()); - time_mapping.SetDouble(kPrefTicks, static_cast<double>( - ticks_at_last_measurement_.ToInternalValue())); - time_mapping.SetDouble(kPrefUncertainty, static_cast<double>( - network_time_uncertainty_.ToInternalValue())); - time_mapping.SetDouble(kPrefNetworkTime, - network_time_at_last_measurement_.ToJsTime()); - pref_service_->Set(prefs::kNetworkTimeMapping, time_mapping); + base::Value::Dict time_mapping; + time_mapping.Set(kPrefTime, time_at_last_measurement_.ToJsTime()); + time_mapping.Set( + kPrefTicks, + static_cast<double>(ticks_at_last_measurement_.ToInternalValue())); + time_mapping.Set( + kPrefUncertainty, + static_cast<double>(network_time_uncertainty_.ToInternalValue())); + time_mapping.Set(kPrefNetworkTime, + network_time_at_last_measurement_.ToJsTime()); + pref_service_->Set(prefs::kNetworkTimeMapping, + base::Value(std::move(time_mapping))); } bool NetworkTimeTracker::AreTimeFetchesEnabled() const { @@ -488,6 +491,7 @@ void NetworkTimeTracker::CheckTime(CheckTimeType check_type) { resource_request->load_flags = net::LOAD_BYPASS_CACHE | net::LOAD_DISABLE_CACHE; resource_request->credentials_mode = network::mojom::CredentialsMode::kOmit; + resource_request->enable_load_timing = true; // This cancels any outstanding fetch. time_fetcher_ = network::SimpleURLLoader::Create(std::move(resource_request), traffic_annotation); @@ -498,8 +502,6 @@ void NetworkTimeTracker::CheckTime(CheckTimeType check_type) { base::Unretained(this), check_type), max_response_size_); - fetch_started_ = tick_clock_->NowTicks(); - timer_.Stop(); // Restarted in OnURLLoaderComplete(). } @@ -537,14 +539,13 @@ bool NetworkTimeTracker::UpdateTimeFromResponse( RecordFetchValidHistogram(false); return false; } - const base::DictionaryValue* dict; - if (!value->GetAsDictionary(&dict)) { + if (!value->is_dict()) { DVLOG(1) << "not a dictionary"; RecordFetchValidHistogram(false); return false; } absl::optional<double> current_time_millis = - dict->FindDoubleKey("current_time_millis"); + value->GetDict().FindDouble("current_time_millis"); if (!current_time_millis) { DVLOG(1) << "no current_time_millis"; RecordFetchValidHistogram(false); @@ -561,7 +562,9 @@ bool NetworkTimeTracker::UpdateTimeFromResponse( // Record histograms for the latency of the time query and the time delta // between time fetches. - base::TimeDelta latency = tick_clock_->NowTicks() - fetch_started_; + base::TimeDelta latency = + time_fetcher_->ResponseInfo()->load_timing.receive_headers_start - + time_fetcher_->ResponseInfo()->load_timing.send_end; LOCAL_HISTOGRAM_TIMES("NetworkTimeTracker.TimeQueryLatency", latency); if (!last_fetched_time_.is_null()) { diff --git a/chromium/components/network_time/network_time_tracker.h b/chromium/components/network_time/network_time_tracker.h index 01c4a04ef4d..7671af9d680 100644 --- a/chromium/components/network_time/network_time_tracker.h +++ b/chromium/components/network_time/network_time_tracker.h @@ -234,7 +234,6 @@ class NetworkTimeTracker { base::RepeatingTimer timer_; scoped_refptr<network::SharedURLLoaderFactory> url_loader_factory_; std::unique_ptr<network::SimpleURLLoader> time_fetcher_; - base::TimeTicks fetch_started_; std::unique_ptr<client_update_protocol::Ecdsa> query_signer_; // The |Clock| and |TickClock| are used to sanity-check one another, allowing diff --git a/chromium/components/network_time/network_time_tracker_unittest.cc b/chromium/components/network_time/network_time_tracker_unittest.cc index 5435c882522..37b08d75db3 100644 --- a/chromium/components/network_time/network_time_tracker_unittest.cc +++ b/chromium/components/network_time/network_time_tracker_unittest.cc @@ -9,6 +9,7 @@ #include <utility> #include "base/bind.h" +#include "base/callback_forward.h" #include "base/compiler_specific.h" #include "base/memory/raw_ptr.h" #include "base/run_loop.h" @@ -25,7 +26,13 @@ #include "net/http/http_response_headers.h" #include "net/test/embedded_test_server/embedded_test_server.h" #include "net/test/embedded_test_server/http_response.h" +#include "services/network/public/cpp/resource_request.h" +#include "services/network/public/cpp/url_loader_completion_status.h" +#include "services/network/public/cpp/weak_wrapper_shared_url_loader_factory.h" +#include "services/network/public/mojom/url_response_head.mojom.h" #include "services/network/test/test_shared_url_loader_factory.h" +#include "services/network/test/test_url_loader_factory.h" +#include "services/network/test/test_utils.h" #include "testing/gtest/include/gtest/gtest.h" namespace network_time { @@ -42,6 +49,20 @@ const char kWallClockBackwardsHistogram[] = "NetworkTimeTracker.WallClockRanBackwards"; const char kTimeBetweenFetchesHistogram[] = "NetworkTimeTracker.TimeBetweenFetches"; + +// Latencies simulated by the fake network responses for the network times. This +// array should have the same length as `kGoodTimeResponseBody`. +const base::TimeDelta kGoodTimeResponseLatency[] = { + base::Milliseconds(500), base::Milliseconds(520), base::Milliseconds(450), + base::Milliseconds(550), base::Milliseconds(480), +}; + +struct MockedResponse { + network::mojom::URLResponseHeadPtr head; + std::string body; + network::URLLoaderCompletionStatus status; +}; + } // namespace class NetworkTimeTrackerTest : public ::testing::Test { @@ -53,8 +74,7 @@ class NetworkTimeTrackerTest : public ::testing::Test { base::test::SingleThreadTaskEnvironment::MainThreadType::IO), field_trial_test_(new FieldTrialTest()), clock_(new base::SimpleTestClock), - tick_clock_(new base::SimpleTestTickClock), - test_server_(new net::EmbeddedTestServer) { + tick_clock_(new base::SimpleTestTickClock) { NetworkTimeTracker::RegisterPrefs(pref_service_.registry()); field_trial_test_->SetFeatureParams( @@ -62,13 +82,14 @@ class NetworkTimeTrackerTest : public ::testing::Test { NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, NetworkTimeTracker::ClockDriftSamples::NO_SAMPLES); - shared_url_loader_factory_ = - base::MakeRefCounted<network::TestSharedURLLoaderFactory>(); + url_loader_factory_.SetInterceptor(base::BindRepeating( + &NetworkTimeTrackerTest::Intercept, weak_ptr_factory_.GetWeakPtr())); tracker_ = std::make_unique<NetworkTimeTracker>( std::unique_ptr<base::Clock>(clock_), std::unique_ptr<const base::TickClock>(tick_clock_), &pref_service_, - shared_url_loader_factory_); + base::MakeRefCounted<network::WeakWrapperSharedURLLoaderFactory>( + &url_loader_factory_)); // Do this to be sure that |is_null| returns false. clock_->Advance(base::Days(111)); @@ -80,6 +101,13 @@ class NetworkTimeTrackerTest : public ::testing::Test { adjustment_ = 7 * base::Milliseconds(kTicksResolutionMs); } + // Sets `response_handler` as handler for all requests made through + // `url_loader_factory_`. + void SetResponseHandler( + base::RepeatingCallback<MockedResponse()> response_handler) { + response_handler_ = std::move(response_handler); + } + // Replaces |tracker_| with a new object, while preserving the // testing clocks. void Reset() { @@ -92,53 +120,58 @@ class NetworkTimeTrackerTest : public ::testing::Test { tracker_ = std::make_unique<NetworkTimeTracker>( std::unique_ptr<base::Clock>(clock_), std::unique_ptr<const base::TickClock>(tick_clock_), &pref_service_, - shared_url_loader_factory_); + base::MakeRefCounted<network::WeakWrapperSharedURLLoaderFactory>( + &url_loader_factory_)); } // Good signature over invalid data, though made with a non-production key. - static std::unique_ptr<net::test_server::HttpResponse> BadDataResponseHandler( - const net::test_server::HttpRequest& request) { - net::test_server::BasicHttpResponse* response = - new net::test_server::BasicHttpResponse(); - response->set_code(net::HTTP_OK); - response->set_content( + static MockedResponse BadDataResponseHandler() { + network::mojom::URLResponseHeadPtr head = + network::CreateURLResponseHead(net::HTTP_OK); + std::string body = ")]}'\n" - "{\"current_time_millis\":NaN,\"server_nonce\":9.420921002039447E182}"); - response->AddCustomHeader( + "{\"current_time_millis\":NaN,\"server_nonce\":9.420921002039447E182}"; + head->headers->AddHeader( "x-cup-server-proof", "3046022100a07aa437b24f1f6bb7ff6f6d1e004dd4bcb717c93e21d6bae5ef8d6d984c" "86a7022100e423419ff49fae37b421ef6cdeab348b45c63b236ab365f36f4cd3b4d4d6" "d852:" "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b85" "5"); - return std::unique_ptr<net::test_server::HttpResponse>(response); + return MockedResponse{std::move(head), std::move(body)}; + } + + static MockedResponse GoodTimeResponseHandler() { + network::mojom::URLResponseHeadPtr head = + network::CreateURLResponseHead(net::HTTP_OK); + head->headers->AddHeader("x-cup-server-proof", + kGoodTimeResponseServerProofHeader[0]); + return MockedResponse{std::move(head), kGoodTimeResponseBody[0]}; } - static std::unique_ptr<net::test_server::HttpResponse> - BadSignatureResponseHandler(const net::test_server::HttpRequest& request) { - net::test_server::BasicHttpResponse* response = - new net::test_server::BasicHttpResponse(); - response->set_code(net::HTTP_OK); - response->set_content( + static MockedResponse BadSignatureResponseHandler() { + network::mojom::URLResponseHeadPtr head = + network::CreateURLResponseHead(net::HTTP_OK); + std::string body = ")]}'\n" "{\"current_time_millis\":1461621971825,\"server_nonce\":-6." - "006853099049523E85}"); - response->AddCustomHeader("x-cup-server-proof", "dead:beef"); - return std::unique_ptr<net::test_server::HttpResponse>(response); + "006853099049523E85}"; + head->headers->AddHeader("x-cup-server-proof", "dead:beef"); + return MockedResponse{std::move(head), std::move(body)}; } - static std::unique_ptr<net::test_server::HttpResponse> - ServerErrorResponseHandler(const net::test_server::HttpRequest& request) { - net::test_server::BasicHttpResponse* response = - new net::test_server::BasicHttpResponse(); - response->set_code(net::HTTP_INTERNAL_SERVER_ERROR); - return std::unique_ptr<net::test_server::HttpResponse>(response); + static MockedResponse ServerErrorResponseHandler() { + network::mojom::URLResponseHeadPtr head = + network::CreateURLResponseHead(net::HTTP_INTERNAL_SERVER_ERROR); + return MockedResponse{std::move(head), ""}; } - static std::unique_ptr<net::test_server::HttpResponse> - NetworkErrorResponseHandler(const net::test_server::HttpRequest& request) { - return std::unique_ptr<net::test_server::HttpResponse>( - new net::test_server::RawHttpResponse("", "")); + static MockedResponse NetworkErrorResponseHandler() { + network::mojom::URLResponseHeadPtr head = + network::mojom::URLResponseHead::New(); + return MockedResponse{ + std::move(head), "", + network::URLLoaderCompletionStatus(net::ERR_EMPTY_RESPONSE)}; } // Updates the notifier's time with the specified parameters. @@ -167,8 +200,20 @@ class NetworkTimeTrackerTest : public ::testing::Test { raw_ptr<base::SimpleTestTickClock> tick_clock_; TestingPrefServiceSimple pref_service_; std::unique_ptr<NetworkTimeTracker> tracker_; - std::unique_ptr<net::EmbeddedTestServer> test_server_; - scoped_refptr<network::TestSharedURLLoaderFactory> shared_url_loader_factory_; + network::TestURLLoaderFactory url_loader_factory_; + base::RepeatingCallback<MockedResponse()> response_handler_; + + private: + void Intercept(const network::ResourceRequest& request) { + CHECK(response_handler_); + MockedResponse response = response_handler_.Run(); + // status.decoded_body_length = response.body.size(); + url_loader_factory_.AddResponse(request.url, std::move(response.head), + std::move(response.body), + std::move(response.status)); + } + + base::WeakPtrFactory<NetworkTimeTrackerTest> weak_ptr_factory_{this}; }; TEST_F(NetworkTimeTrackerTest, Uninitialized) { @@ -396,16 +441,16 @@ TEST_F(NetworkTimeTrackerTest, DeserializeOldFormat) { EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE, tracker_->GetNetworkTime(&out_network_time, nullptr)); absl::optional<double> local, network; - const base::Value* saved_prefs = - pref_service_.GetDictionary(prefs::kNetworkTimeMapping); - local = saved_prefs->FindDoubleKey("local"); - network = saved_prefs->FindDoubleKey("network"); + const base::Value::Dict& saved_prefs = + pref_service_.GetValueDict(prefs::kNetworkTimeMapping); + local = saved_prefs.FindDouble("local"); + network = saved_prefs.FindDouble("network"); ASSERT_TRUE(local); ASSERT_TRUE(network); - base::DictionaryValue prefs; - prefs.SetDouble("local", *local); - prefs.SetDouble("network", *network); - pref_service_.Set(prefs::kNetworkTimeMapping, prefs); + base::Value::Dict prefs; + prefs.Set("local", *local); + prefs.Set("network", *network); + pref_service_.Set(prefs::kNetworkTimeMapping, base::Value(std::move(prefs))); Reset(); EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_NO_SYNC_ATTEMPT, tracker_->GetNetworkTime(&out_network_time, nullptr)); @@ -468,18 +513,19 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetwork) { // First query should happen soon. EXPECT_EQ(base::Minutes(0), tracker_->GetTimerDelayForTesting()); - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE, tracker_->GetNetworkTime(&out_network_time, nullptr)); - EXPECT_EQ(base::Time::UnixEpoch() + - base::Milliseconds((uint64_t)kGoodTimeResponseHandlerJsTime[0]), - out_network_time); + + // Enabling load timing for the resource requests seems to increase accuracy + // beyond milliseconds. Accuracy of GoodTimeResponseHandler is + // milliseconds, any difference below 1 ms can therefore be ignored. + EXPECT_LT(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[0]) - + out_network_time, + base::Milliseconds(1)); // Should see no backoff in the success case. EXPECT_EQ(base::Minutes(60), tracker_->GetTimerDelayForTesting()); @@ -489,10 +535,7 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetwork) { } TEST_F(NetworkTimeTrackerTest, StartTimeFetch) { - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); base::Time out_network_time; EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_NO_SYNC_ATTEMPT, @@ -505,9 +548,12 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetch) { EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE, tracker_->GetNetworkTime(&out_network_time, nullptr)); - EXPECT_EQ(base::Time::UnixEpoch() + - base::Milliseconds((uint64_t)kGoodTimeResponseHandlerJsTime[0]), - out_network_time); + // Enabling load timing for the resource requests seems to increase accuracy + // beyond milliseconds. Accuracy of GoodTimeResponseHandler is milliseconds, + // any difference below 1 ms can therefore be ignored. + EXPECT_LT(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[0]) - + out_network_time, + base::Milliseconds(1)); // Should see no backoff in the success case. EXPECT_EQ(base::Minutes(60), tracker_->GetTimerDelayForTesting()); } @@ -515,10 +561,7 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetch) { // Tests that when StartTimeFetch() is called with a query already in // progress, it calls the callback when that query completes. TEST_F(NetworkTimeTrackerTest, StartTimeFetchWithQueryInProgress) { - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); base::Time out_network_time; EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_NO_SYNC_ATTEMPT, @@ -533,9 +576,12 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetchWithQueryInProgress) { EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_AVAILABLE, tracker_->GetNetworkTime(&out_network_time, nullptr)); - EXPECT_EQ(base::Time::UnixEpoch() + - base::Milliseconds((uint64_t)kGoodTimeResponseHandlerJsTime[0]), - out_network_time); + // Enabling load timing for the resource requests seems to increase accuracy + // beyond milliseconds. Accuracy of GoodTimeResponseHandler is milliseconds, + // any difference below 1 ms can therefore be ignored. + EXPECT_LT(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[0]) - + out_network_time, + base::Milliseconds(1)); // Should see no backoff in the success case. EXPECT_EQ(base::Minutes(60), tracker_->GetTimerDelayForTesting()); } @@ -543,10 +589,7 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetchWithQueryInProgress) { // Tests that StartTimeFetch() returns false if called while network // time is available. TEST_F(NetworkTimeTrackerTest, StartTimeFetchWhileSynced) { - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); base::Time in_network_time = clock_->Now(); UpdateNetworkTime(in_network_time, resolution_, latency_, @@ -563,10 +606,7 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetchWithoutVariationsParam) { field_trial_test_->SetFeatureParams( true, 0.0, NetworkTimeTracker::FETCHES_IN_BACKGROUND_ONLY, NetworkTimeTracker::ClockDriftSamples::NO_SAMPLES); - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); base::Time out_network_time; EXPECT_EQ(NetworkTimeTracker::NETWORK_TIME_NO_SYNC_ATTEMPT, @@ -577,10 +617,7 @@ TEST_F(NetworkTimeTrackerTest, StartTimeFetchWithoutVariationsParam) { } TEST_F(NetworkTimeTrackerTest, NoNetworkQueryWhileSynced) { - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); field_trial_test_->SetFeatureParams( true, 0.0, NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, @@ -615,6 +652,7 @@ TEST_F(NetworkTimeTrackerTest, NoNetworkQueryWhileFeatureDisabled) { field_trial_test_->SetFeatureParams( true, 0.0, NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, NetworkTimeTracker::ClockDriftSamples::NO_SAMPLES); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); } @@ -624,10 +662,7 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkBadSignature) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler(base::BindRepeating( - &NetworkTimeTrackerTest::BadSignatureResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&BadSignatureResponseHandler)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); @@ -656,13 +691,11 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkBadData) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&NetworkTimeTrackerTest::BadDataResponseHandler)); - EXPECT_TRUE(test_server_->Start()); base::StringPiece key = {reinterpret_cast<const char*>(kDevKeyPubBytes), sizeof(kDevKeyPubBytes)}; tracker_->SetPublicKeyForTesting(key); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); base::Time out_network_time; @@ -680,10 +713,8 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkServerError) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&NetworkTimeTrackerTest::ServerErrorResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); @@ -713,10 +744,8 @@ TEST_F(NetworkTimeTrackerTest, MAYBE_UpdateFromNetworkNetworkError) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler(base::BindRepeating( + SetResponseHandler(base::BindRepeating( &NetworkTimeTrackerTest::NetworkErrorResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); @@ -737,10 +766,7 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkLargeResponse) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler( - base::BindRepeating(&GoodTimeResponseHandler)); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); + SetResponseHandler(base::BindRepeating(&GoodTimeResponseHandler)); base::Time out_network_time; @@ -769,13 +795,11 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkFirstSyncPending) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&NetworkTimeTrackerTest::BadDataResponseHandler)); - EXPECT_TRUE(test_server_->Start()); base::StringPiece key = {reinterpret_cast<const char*>(kDevKeyPubBytes), sizeof(kDevKeyPubBytes)}; tracker_->SetPublicKeyForTesting(key); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); // Do not wait for the fetch to complete; ask for the network time @@ -794,13 +818,11 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkSubseqeuntSyncPending) { histograms.ExpectTotalCount(kFetchFailedHistogram, 0); histograms.ExpectTotalCount(kFetchValidHistogram, 0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&NetworkTimeTrackerTest::BadDataResponseHandler)); - EXPECT_TRUE(test_server_->Start()); base::StringPiece key = {reinterpret_cast<const char*>(kDevKeyPubBytes), sizeof(kDevKeyPubBytes)}; tracker_->SetPublicKeyForTesting(key); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); @@ -823,7 +845,8 @@ TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkSubseqeuntSyncPending) { namespace { // NetworkTimeTrackerTest.TimeBetweenFetchesHistogram needs to make several time -// queries that return different times. MultipleGoodTimeResponseHandler is like +// queries that return different times. +// MultipleGoodTimeResponseHandler::ResponseHandler is like // GoodTimeResponseHandler, but returning different times on each of three // requests that happen in sequence. // @@ -839,8 +862,7 @@ class MultipleGoodTimeResponseHandler { ~MultipleGoodTimeResponseHandler() {} - std::unique_ptr<net::test_server::HttpResponse> ResponseHandler( - const net::test_server::HttpRequest& request); + MockedResponse ResponseHandler(); // Returns the time that is returned in the (i-1)'th response handled by // ResponseHandler(), or null base::Time() if too many responses have been @@ -854,24 +876,26 @@ class MultipleGoodTimeResponseHandler { unsigned int next_time_index_ = 0; }; -std::unique_ptr<net::test_server::HttpResponse> -MultipleGoodTimeResponseHandler::ResponseHandler( - const net::test_server::HttpRequest& request) { - net::test_server::BasicHttpResponse* response = - new net::test_server::BasicHttpResponse(); - +MockedResponse MultipleGoodTimeResponseHandler::ResponseHandler() { if (next_time_index_ >= std::size(kGoodTimeResponseBody)) { - response->set_code(net::HTTP_BAD_REQUEST); - return std::unique_ptr<net::test_server::HttpResponse>(response); + return MockedResponse{network::CreateURLResponseHead(net::HTTP_BAD_REQUEST), + ""}; } - response->set_code(net::HTTP_OK); - response->set_content(kGoodTimeResponseBody[next_time_index_]); - response->AddCustomHeader( + network::mojom::URLResponseHeadPtr head = + network::CreateURLResponseHead(net::HTTP_OK); + head->headers->AddHeader( "x-cup-server-proof", kGoodTimeResponseServerProofHeader[next_time_index_]); + + // Simulate response latency. + head->load_timing.send_end = base::TimeTicks::Now(); + head->load_timing.receive_headers_start = + head->load_timing.send_end + kGoodTimeResponseLatency[next_time_index_]; + MockedResponse response{std::move(head), + kGoodTimeResponseBody[next_time_index_]}; next_time_index_++; - return std::unique_ptr<net::test_server::HttpResponse>(response); + return response; } base::Time MultipleGoodTimeResponseHandler::GetTimeAtIndex(unsigned int i) { @@ -887,11 +911,9 @@ TEST_F(NetworkTimeTrackerTest, TimeBetweenFetchesHistogram) { base::HistogramTester histograms; histograms.ExpectTotalCount(kTimeBetweenFetchesHistogram, 0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting()); tracker_->WaitForFetchForTesting(123123123); @@ -924,58 +946,106 @@ TEST_F(NetworkTimeTrackerTest, ClockSkewHistograms) { NetworkTimeTracker::ClockDriftSamples::NO_SAMPLES); MultipleGoodTimeResponseHandler response_handler; - base::HistogramTester histograms; + base::HistogramTester histograms_first; + base::TimeDelta mean_latency = base::Seconds(0); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); clock_->SetNow( base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[0] + 3500)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); - // Simulate 1s latency. - tick_clock_->Advance(base::Seconds(1)); tracker_->WaitForFetchForTesting(123123123); - - histograms.ExpectUniqueTimeSample( - "PrivacyBudget.ClockSkew.Magnitude.Positive", base::Seconds(3), 1); - histograms.ExpectTotalCount("PrivacyBudget.ClockSkew.Magnitude.Negative", 0); - histograms.ExpectUniqueTimeSample("PrivacyBudget.ClockSkew.FetchLatency", - base::Seconds(1), 1); - histograms.ExpectTotalCount("PrivacyBudget.ClockSkew.FetchLatencyJitter", 0); + base::TimeDelta latency1 = kGoodTimeResponseLatency[0]; + mean_latency += latency1; + + std::unique_ptr<base::HistogramSamples> samples_positive( + histograms_first.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Positive")); + EXPECT_EQ(1, samples_positive->GetCount( + (base::Seconds(3.5) - latency1 / 2).InMilliseconds())); + EXPECT_EQ(1, samples_positive->TotalCount()); + + std::unique_ptr<base::HistogramSamples> samples_negative( + histograms_first.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Negative")); + EXPECT_EQ(0, samples_negative->TotalCount()); + + std::unique_ptr<base::HistogramSamples> samples_latency( + histograms_first.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatency")); + EXPECT_EQ(1, samples_latency->TotalCount()); + EXPECT_EQ(1, samples_latency->GetCount(latency1.InMilliseconds())); + + std::unique_ptr<base::HistogramSamples> samples_latency_jitter( + histograms_first.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatencyJitter")); + EXPECT_EQ(0, samples_latency_jitter->TotalCount()); + + base::HistogramTester histograms_second; clock_->SetNow( base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[1] + 3500)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); - // Simulate 1s latency. - tick_clock_->Advance(base::Seconds(1)); tracker_->WaitForFetchForTesting(123123123); + base::TimeDelta latency2 = kGoodTimeResponseLatency[1]; + mean_latency += latency2; - histograms.ExpectUniqueTimeSample( - "PrivacyBudget.ClockSkew.Magnitude.Positive", base::Seconds(3), 2); - histograms.ExpectTotalCount("PrivacyBudget.ClockSkew.Magnitude.Negative", 0); - histograms.ExpectUniqueTimeSample("PrivacyBudget.ClockSkew.FetchLatency", - base::Seconds(1), 2); - histograms.ExpectTotalCount("PrivacyBudget.ClockSkew.FetchLatencyJitter", 0); + samples_positive = histograms_second.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Positive"); + EXPECT_EQ(1, samples_positive->GetCount( + (base::Seconds(3.5) - latency2 / 2).InMilliseconds())); + EXPECT_EQ(1, samples_positive->TotalCount()); + samples_negative = histograms_second.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Negative"); + EXPECT_EQ(0, samples_negative->TotalCount()); + + samples_latency = histograms_second.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatency"); + EXPECT_EQ(1, samples_latency->TotalCount()); + EXPECT_EQ(1, samples_latency->GetCount(latency2.InMilliseconds())); + + samples_latency_jitter = histograms_second.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatencyJitter"); + EXPECT_EQ(0, samples_latency_jitter->TotalCount()); + + base::HistogramTester histograms_third; clock_->SetNow( base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[2] - 2500)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); - // Simulate 1s latency. - tick_clock_->Advance(base::Seconds(1)); tracker_->WaitForFetchForTesting(123123123); - - histograms.ExpectUniqueTimeSample( - "PrivacyBudget.ClockSkew.Magnitude.Positive", base::Seconds(3), 2); - histograms.ExpectUniqueTimeSample( - "PrivacyBudget.ClockSkew.Magnitude.Negative", base::Seconds(3), 1); - histograms.ExpectUniqueTimeSample("PrivacyBudget.ClockSkew.FetchLatency", - base::Seconds(1), 3); + base::TimeDelta latency3 = kGoodTimeResponseLatency[2]; + mean_latency += latency3; + + samples_positive = histograms_third.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Positive"); + EXPECT_EQ(0, samples_positive->TotalCount()); + + samples_negative = histograms_third.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.Magnitude.Negative"); + EXPECT_EQ(1, samples_negative->TotalCount()); + EXPECT_EQ(1, samples_negative->GetCount( + (base::Seconds(2.5) + latency3 / 2).InMilliseconds())); + samples_latency = histograms_third.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatency"); + EXPECT_EQ(1, samples_latency->TotalCount()); + EXPECT_EQ(1, samples_latency->GetCount(latency3.InMilliseconds())); // After three fetches, the FetchLatencyJitter should be reported. - histograms.ExpectUniqueTimeSample( - "PrivacyBudget.ClockSkew.FetchLatencyJitter", base::Seconds(0), 1); + samples_latency_jitter = histograms_third.GetHistogramSamplesSinceCreation( + "PrivacyBudget.ClockSkew.FetchLatencyJitter"); + EXPECT_EQ(1, samples_latency_jitter->TotalCount()); + mean_latency /= 3.0; + int64_t stddev = (mean_latency - latency1).InMicroseconds() * + (mean_latency - latency1).InMicroseconds() + + (mean_latency - latency2).InMicroseconds() * + (mean_latency - latency2).InMicroseconds() + + (mean_latency - latency3).InMicroseconds() * + (mean_latency - latency3).InMicroseconds(); + stddev = std::lround(std::sqrt(base::strict_cast<double>(stddev))); + EXPECT_EQ(1, samples_latency_jitter->GetCount( + base::Microseconds(stddev).InMilliseconds())); } TEST_F(NetworkTimeTrackerTest, ClockSkewHistogramsEmptyForOnDemandChecks) { @@ -986,11 +1056,9 @@ TEST_F(NetworkTimeTrackerTest, ClockSkewHistogramsEmptyForOnDemandChecks) { MultipleGoodTimeResponseHandler response_handler; base::HistogramTester histograms; - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/true)); tracker_->WaitForFetchForTesting(123123123); @@ -1010,11 +1078,9 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsEmptyForOnDemandChecks) { NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, NetworkTimeTracker::ClockDriftSamples::TWO_SAMPLES); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); clock_->SetNow(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[0])); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/true)); tracker_->WaitForFetchForTesting(123123123); @@ -1043,11 +1109,9 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsPositive) { NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, NetworkTimeTracker::ClockDriftSamples::TWO_SAMPLES); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); // This part will trigger a skew measurement fetch first, followed by a drift // measurement using two samples. @@ -1058,9 +1122,8 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsPositive) { // The next measurements are used for computing drift. clock_->SetNow(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[1])); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); - // Simulate 70ms latency. - tick_clock_->Advance(base::Milliseconds(70)); tracker_->WaitForFetchForTesting(123123123); + base::TimeDelta latency1 = kGoodTimeResponseLatency[1]; // We add an on demand time query in the middle to check it does not interfere // with our samples. @@ -1075,21 +1138,28 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsPositive) { clock_->SetNow( base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[4] + 150)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); - // Simulate 50ms latency. - tick_clock_->Advance(base::Milliseconds(50)); tracker_->WaitForFetchForTesting(123123123); + base::TimeDelta latency3 = kGoodTimeResponseLatency[4]; + double expected_positive_drift = + (base::Milliseconds(150) - latency3 / 2 + latency1 / 2).InMicroseconds() / + 2.0; + ASSERT_GT(expected_positive_drift, 0); histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.Magnitude.Positive", 1); - histograms.ExpectUniqueSample( - "PrivacyBudget.ClockDrift.Magnitude.Positive", - base::Milliseconds(150 - 50 / 2 + 70 / 2).InMicroseconds() / 2.0, 1); + histograms.ExpectUniqueSample("PrivacyBudget.ClockDrift.Magnitude.Positive", + expected_positive_drift, 1); histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.Magnitude.Negative", 0); histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.FetchLatencyVariance", 1); + + base::TimeDelta mean = (latency1 + latency3) / 2.0; + double variance = + (latency1 - mean).InMilliseconds() * (latency1 - mean).InMilliseconds() + + (latency3 - mean).InMilliseconds() * (latency3 - mean).InMilliseconds(); histograms.ExpectUniqueSample("PrivacyBudget.ClockDrift.FetchLatencyVariance", - 200, 1); + variance, 1); } TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsNegative) { @@ -1101,11 +1171,9 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsNegative) { NetworkTimeTracker::FETCHES_IN_BACKGROUND_AND_ON_DEMAND, NetworkTimeTracker::ClockDriftSamples::TWO_SAMPLES); - test_server_->RegisterRequestHandler( + SetResponseHandler( base::BindRepeating(&MultipleGoodTimeResponseHandler::ResponseHandler, base::Unretained(&response_handler))); - EXPECT_TRUE(test_server_->Start()); - tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/")); // This part will trigger a skew measurement fetch first, followed by a drift // measurement using two samples. @@ -1117,6 +1185,7 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsNegative) { clock_->SetNow(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[1])); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); tracker_->WaitForFetchForTesting(123123123); + base::TimeDelta latency1 = kGoodTimeResponseLatency[1]; clock_->SetNow(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[2])); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); @@ -1125,18 +1194,26 @@ TEST_F(NetworkTimeTrackerTest, ClockDriftHistogramsNegative) { clock_->SetNow(base::Time::FromJsTime(kGoodTimeResponseHandlerJsTime[3] - 1)); EXPECT_TRUE(tracker_->QueryTimeServiceForTesting(/*on_demand=*/false)); tracker_->WaitForFetchForTesting(123123123); + base::TimeDelta latency3 = kGoodTimeResponseLatency[3]; + double expected_negative_drift = + (base::Milliseconds(1) - latency1 / 2 + latency3 / 2).InMicroseconds() / + 2.0; + ASSERT_GT(expected_negative_drift, 0); histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.Magnitude.Positive", 0); - histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.Magnitude.Negative", 1); histograms.ExpectUniqueSample("PrivacyBudget.ClockDrift.Magnitude.Negative", - base::Milliseconds(1).InMicroseconds() / 2.0, - 1); + expected_negative_drift, 1); + + base::TimeDelta mean = (latency1 + latency3) / 2.0; + double variance = + (latency1 - mean).InMilliseconds() * (latency1 - mean).InMilliseconds() + + (latency3 - mean).InMilliseconds() * (latency3 - mean).InMilliseconds(); histograms.ExpectTotalCount("PrivacyBudget.ClockDrift.FetchLatencyVariance", 1); histograms.ExpectUniqueSample("PrivacyBudget.ClockDrift.FetchLatencyVariance", - 0, 1); + variance, 1); } } // namespace network_time |