Add metrics to track the status of force signin verfication.

Metrics to count whether the verification request will be sent when profile is loaded.
Metrics to count the amount of time from profile loaded to verification finished.

Bug: 791171
Change-Id: I693eb5bd2289fc7ba7c295dbd45309d1b04ffe26
Reviewed-on: https://chromium-review.googlesource.com/804754Reviewed-by: Jesse Doherty <jwd@chromium.org>
Reviewed-by: Roger Tawa <rogerta@chromium.org>
Commit-Queue: Owen Min <zmin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#521830}

chrome/browser/signin/force_signin_verifier.cc

@@ -7,6 +7,7 @@
 #include "chrome/browser/signin/force_signin_verifier.h"
 
 #include "base/bind.h"
+#include "base/metrics/histogram_macros.h"
 #include "chrome/browser/profiles/profile.h"
 #include "chrome/browser/signin/profile_oauth2_token_service_factory.h"
 #include "chrome/browser/signin/signin_manager_factory.h"
@@ -27,14 +28,24 @@ const net::BackoffEntry::Policy kBackoffPolicy = {
 
 }  // namespace
 
+const char kForceSigninVerificationMetricsName[] =
+    "Signin.ForceSigninVerificationRequest";
+const char kForceSigninVerificationSuccessTimeMetricsName[] =
+    "Signin.ForceSigninVerificationTime.Success";
+const char kForceSigninVerificationFailureTimeMetricsName[] =
+    "Signin.ForceSigninVerificationTime.Failure";
+
 ForceSigninVerifier::ForceSigninVerifier(Profile* profile)
     : OAuth2TokenService::Consumer("force_signin_verifier"),
       has_token_verified_(false),
       backoff_entry_(&kBackoffPolicy),
+      creation_time_(base::TimeTicks::Now()),
       oauth2_token_service_(
           ProfileOAuth2TokenServiceFactory::GetForProfile(profile)),
       signin_manager_(SigninManagerFactory::GetForProfile(profile)) {
   net::NetworkChangeNotifier::AddNetworkChangeObserver(this);
+  UMA_HISTOGRAM_BOOLEAN(kForceSigninVerificationMetricsName,
+                        ShouldSendRequest());
   SendRequest();
 }
 
@@ -46,6 +57,8 @@ void ForceSigninVerifier::OnGetTokenSuccess(
     const OAuth2TokenService::Request* request,
     const std::string& access_token,
     const base::Time& expiration_time) {
+  UMA_HISTOGRAM_MEDIUM_TIMES(kForceSigninVerificationSuccessTimeMetricsName,
+                             base::TimeTicks::Now() - creation_time_);
   has_token_verified_ = true;
   net::NetworkChangeNotifier::RemoveNetworkChangeObserver(this);
   Cancel();
@@ -55,6 +68,8 @@ void ForceSigninVerifier::OnGetTokenFailure(
     const OAuth2TokenService::Request* request,
     const GoogleServiceAuthError& error) {
   if (error.IsPersistentError()) {
+    UMA_HISTOGRAM_MEDIUM_TIMES(kForceSigninVerificationFailureTimeMetricsName,
+                               base::TimeTicks::Now() - creation_time_);
     has_token_verified_ = true;
     CloseAllBrowserWindows();
     net::NetworkChangeNotifier::RemoveNetworkChangeObserver(this);

chrome/browser/signin/force_signin_verifier.h

@@ -18,6 +18,10 @@
 class Profile;
 class SigninManager;
 
+extern const char kForceSigninVerificationMetricsName[];
+extern const char kForceSigninVerificationSuccessTimeMetricsName[];
+extern const char kForceSigninVerificationFailureTimeMetricsName[];
+
 // ForceSigninVerifier will verify profile's auth token when profile is loaded
 // into memory by the first time via gaia server. It will retry on any transient
 // error.
@@ -70,6 +74,7 @@ class ForceSigninVerifier
   bool has_token_verified_;
   net::BackoffEntry backoff_entry_;
   base::OneShotTimer backoff_request_timer_;
+  base::TimeTicks creation_time_;
 
   OAuth2TokenService* oauth2_token_service_;
   SigninManager* signin_manager_;

chrome/browser/signin/force_signin_verifier_unittest.cc

@@ -4,6 +4,7 @@
 
 #include "chrome/browser/signin/force_signin_verifier.h"
 
+#include "base/test/histogram_tester.h"
 #include "chrome/test/base/testing_profile.h"
 #include "content/public/test/test_browser_thread_bundle.h"
 #include "testing/gmock/include/gmock/gmock.h"
@@ -43,6 +44,8 @@ class ForceSigninVerifierTest : public ::testing::Test {
       GoogleServiceAuthError::State::INVALID_GAIA_CREDENTIALS);
   GoogleServiceAuthError transient_error_ =
       GoogleServiceAuthError(GoogleServiceAuthError::State::CONNECTION_FAILED);
+
+  base::HistogramTester histogram_tester_;
 };
 
 TEST_F(ForceSigninVerifierTest, OnGetTokenSuccess) {
@@ -60,6 +63,12 @@ TEST_F(ForceSigninVerifierTest, OnGetTokenSuccess) {
   ASSERT_TRUE(verifier_->HasTokenBeenVerified());
   ASSERT_FALSE(verifier_->IsDelayTaskPosted());
   ASSERT_EQ(0, verifier_->FailureCount());
+  histogram_tester_.ExpectBucketCount(kForceSigninVerificationMetricsName, 0,
+                                      1);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationSuccessTimeMetricsName, 1);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationFailureTimeMetricsName, 0);
 }
 
 TEST_F(ForceSigninVerifierTest, OnGetTokenPersistentFailure) {
@@ -77,6 +86,12 @@ TEST_F(ForceSigninVerifierTest, OnGetTokenPersistentFailure) {
   ASSERT_TRUE(verifier_->HasTokenBeenVerified());
   ASSERT_FALSE(verifier_->IsDelayTaskPosted());
   ASSERT_EQ(0, verifier_->FailureCount());
+  histogram_tester_.ExpectBucketCount(kForceSigninVerificationMetricsName, 0,
+                                      1);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationSuccessTimeMetricsName, 0);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationFailureTimeMetricsName, 1);
 }
 
 TEST_F(ForceSigninVerifierTest, OnGetTokenTransientFailure) {
@@ -93,6 +108,12 @@ TEST_F(ForceSigninVerifierTest, OnGetTokenTransientFailure) {
   ASSERT_FALSE(verifier_->HasTokenBeenVerified());
   ASSERT_TRUE(verifier_->IsDelayTaskPosted());
   ASSERT_EQ(1, verifier_->FailureCount());
+  histogram_tester_.ExpectBucketCount(kForceSigninVerificationMetricsName, 0,
+                                      1);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationSuccessTimeMetricsName, 0);
+  histogram_tester_.ExpectTotalCount(
+      kForceSigninVerificationFailureTimeMetricsName, 0);
 }
 
 TEST_F(ForceSigninVerifierTest, OnLostConnection) {

tools/metrics/histograms/histograms.xml

@@ -79957,6 +79957,25 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="Signin.ForceSigninVerificationRequest" enum="BooleanRequested">
+  <owner>zmin@chromium.org</owner>
+  <summary>
+    The number profile load events that needs a force-sign-in verification
+    request. It's recorded when profile is loaded with an authentication token
+    and force-sign-in policy is enabled.
+  </summary>
+</histogram>
+
+<histogram name="Signin.ForceSigninVerificationTime" units="ms">
+  <owner>zmin@chromium.org</owner>
+  <summary>
+    Elapsed time of the force-sign-in verfication if it's finished. It includes
+    total network delay, retry delay and wait time due to no connection. The
+    verfication will not be recorded if it's not finished before profile is
+    signed out or removed from memory.
+  </summary>
+</histogram>
+
 <histogram name="Signin.InvestigatedScenario" enum="SigninInvestigatedScenario">
   <owner>skym@chromium.org</owner>
   <summary>
@@ -108616,6 +108635,14 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   <affected-histogram name="Signin"/>
 </histogram_suffixes>
 
+<histogram_suffixes name="Signin.ForceSigninVerificationResult" separator=".">
+  <suffix name="Success" label="The authenticaion token is valid"/>
+  <suffix name="Failure"
+      label="The authenticaion token can not be verified due to persisten
+             error"/>
+  <affected-histogram name="Signin.ForceSigninVerificationTime"/>
+</histogram_suffixes>
+
 <histogram_suffixes name="Signin.ObsoleteActions" separator=".">
   <obsolete>
     Deprecated as of 12/2014.