Add NetworkTimeTracker UMA histograms

components/network_time/network_time_tracker_unittest.cc

 // Copyright 2014 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "components/network_time/network_time_tracker.h"
 
 #include <map>
 #include <memory>
 #include <string>
 #include <utility>
 
 #include "base/compiler_specific.h"
 #include "base/feature_list.h"
 #include "base/metrics/field_trial.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/stringprintf.h"
+#include "base/test/histogram_tester.h"
 #include "base/test/mock_entropy_provider.h"
 #include "base/test/simple_test_clock.h"
 #include "base/test/simple_test_tick_clock.h"
 #include "components/client_update_protocol/ecdsa.h"
 #include "components/network_time/network_time_pref_names.h"
 #include "components/prefs/testing_pref_service.h"
 #include "components/variations/variations_associated_data.h"
 #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 "net/url_request/url_fetcher.h"
 #include "net/url_request/url_request_test_util.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 namespace network_time {
 
+namespace {
+const char kFetchAttemptHistogram[] =
+    "NetworkTimeTracker.UpdateTimeFetchAttempted";
+const char kFetchFailedHistogram[] = "NetworkTimeTracker.UpdateTimeFetchFailed";
+const char kFetchSucceededHistogram[] =
+    "NetworkTimeTracker.UpdateTimeFetchSucceeded";
+const char kFetchValidHistogram[] = "NetworkTimeTracker.UpdateTimeFetchValid";
+}  // namespace
+
 class NetworkTimeTrackerTest : public testing::Test {
  public:
   ~NetworkTimeTrackerTest() override {}
 
   NetworkTimeTrackerTest()
       : io_thread_("IO thread"),
         clock_(new base::SimpleTestClock),
         tick_clock_(new base::SimpleTestTickClock),
         test_server_(new net::EmbeddedTestServer) {
     base::Thread::Options thread_options;
@@ skipping 384 matching lines @@
                     tick_clock_->NowTicks());
 
   base::Time out_network_time;
   EXPECT_TRUE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   clock_->Advance(base::TimeDelta::FromDays(1));
   Reset();
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
 }
 
 TEST_F(NetworkTimeTrackerTest, UpdateFromNetwork) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   base::Time out_network_time;
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   // First query should happen soon.
   EXPECT_EQ(base::TimeDelta::FromMinutes(0),
             tracker_->GetTimerDelayForTesting());
 
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::GoodTimeResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
 
   EXPECT_TRUE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   EXPECT_EQ(base::Time::UnixEpoch() +
                 base::TimeDelta::FromMilliseconds(1461621971825),
             out_network_time);
   // Should see no backoff in the success case.
   EXPECT_EQ(base::TimeDelta::FromMinutes(60),
             tracker_->GetTimerDelayForTesting());
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 1);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 1);
 }
 
 TEST_F(NetworkTimeTrackerTest, NoNetworkQueryWhileSynced) {
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::GoodTimeResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
 
   SetNetworkQueriesWithVariationsService(true, 0.0);
   base::Time in_network_time = clock_->Now();
@@ skipping 20 matching lines @@
   EXPECT_EQ(base::TimeDelta::FromMinutes(6),
             tracker_->GetTimerDelayForTesting());
 
   // Enable time queries and check that a query is sent.
   SetNetworkQueriesWithVariationsService(true, 0.0);
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
 }
 
 TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkBadSignature) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::BadSignatureResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
 
   base::Time out_network_time;
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   EXPECT_EQ(base::TimeDelta::FromMinutes(120),
             tracker_->GetTimerDelayForTesting());
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 1);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
 }
 
 static const uint8_t kDevKeyPubBytes[] = {
     0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02,
     0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03,
     0x42, 0x00, 0x04, 0xe0, 0x6b, 0x0d, 0x76, 0x75, 0xa3, 0x99, 0x7d, 0x7c,
     0x1b, 0xd6, 0x3c, 0x73, 0xbb, 0x4b, 0xfe, 0x0a, 0xe7, 0x2f, 0x61, 0x3d,
     0x77, 0x0a, 0xaa, 0x14, 0xd8, 0x5a, 0xbf, 0x14, 0x60, 0xec, 0xf6, 0x32,
     0x77, 0xb5, 0xa7, 0xe6, 0x35, 0xa5, 0x61, 0xaf, 0xdc, 0xdf, 0x91, 0xce,
     0x45, 0x34, 0x5f, 0x36, 0x85, 0x2f, 0xb9, 0x53, 0x00, 0x5d, 0x86, 0xe7,
     0x04, 0x16, 0xe2, 0x3d, 0x21, 0x76, 0x2b};
 
 TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkBadData) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   test_server_->RegisterRequestHandler(
       base::Bind(&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;
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   EXPECT_EQ(base::TimeDelta::FromMinutes(120),
             tracker_->GetTimerDelayForTesting());
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 1);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
 }
 
 TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkServerError) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::ServerErrorResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
 
   base::Time out_network_time;
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   // Should see backoff in the error case.
   EXPECT_EQ(base::TimeDelta::FromMinutes(120),
             tracker_->GetTimerDelayForTesting());
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 1);
+  histograms.ExpectBucketCount(kFetchFailedHistogram, net::OK, 1);

[mab, 2016/07/28 06:58:55]

Why is this net::OK for an error response?

[estark, 2016/07/28 18:27:58]

net::OK because there was no network error, just a non-200 status code. I could
have sworn I had a comment here to explain that. O.o I guess I was thinking of
the histogram description, so I'll add a comment here.

I don't think we need to histogram the HTTP status codes that we receive because
I assume we can get that data from the server.

+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
 }
 
-TEST_F(NetworkTimeTrackerTest, UpdateFromNetworNetworkError) {
+TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkNetworkError) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::NetworkErrorResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
 
   base::Time out_network_time;
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
   // Should see backoff in the error case.
   EXPECT_EQ(base::TimeDelta::FromMinutes(120),
             tracker_->GetTimerDelayForTesting());
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 1);
+  histograms.ExpectBucketCount(kFetchFailedHistogram, -net::ERR_EMPTY_RESPONSE,
+                               1);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
 }
 
 TEST_F(NetworkTimeTrackerTest, UpdateFromNetworkLargeResponse) {
+  base::HistogramTester histograms;
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 0);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 0);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   test_server_->RegisterRequestHandler(
       base::Bind(&NetworkTimeTrackerTest::GoodTimeResponseHandler));
   EXPECT_TRUE(test_server_->Start());
   tracker_->SetTimeServerURLForTesting(test_server_->GetURL("/"));
 
   base::Time out_network_time;
 
   tracker_->SetMaxResponseSizeForTesting(3);
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
   EXPECT_FALSE(tracker_->GetNetworkTime(&out_network_time, nullptr));
 
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 1);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 1);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 0);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 0);
+
   tracker_->SetMaxResponseSizeForTesting(1024);
   EXPECT_TRUE(tracker_->QueryTimeServiceForTesting());
   tracker_->WaitForFetchForTesting(123123123);
   EXPECT_TRUE(tracker_->GetNetworkTime(&out_network_time, nullptr));
+
+  histograms.ExpectTotalCount(kFetchAttemptHistogram, 2);
+  histograms.ExpectTotalCount(kFetchFailedHistogram, 1);
+  histograms.ExpectTotalCount(kFetchSucceededHistogram, 1);
+  histograms.ExpectTotalCount(kFetchValidHistogram, 1);
 }
 
 }  // namespace network_time