Add UMA stats for initial user policy fetch on Chrome OS.

Add UMA stats for initial user policy fetch on Chrome OS.

This collects timing data as well as error codes for initial policy
fetches on Chrome OS. These block Profile creation, so we'd like to
get some insight on how much delay this encurs in the field.

BUG=271321
TEST=Log in to an enrolled device, check chrome://histograms

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=221422

[Mattias Nissler (ping if slow), 2013-08-30 09:50:43]

bartfab: Main reviewer
jar: histograms.xml
derat: FYI

[bartfab (slow), 2013-08-30 10:04:40]

https://codereview.chromium.org/23271009/diff/1/chrome/browser/chromeos/polic...
File chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
(right):

https://codereview.chromium.org/23271009/diff/1/chrome/browser/chromeos/polic...
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc:291:
base::Time now = base::Time::Now();
Nit: const

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
tools/metrics/histograms/histograms.xml:2591: +<histogram
name="Enterprise.UserPolicyChromeOS.ClientError"
In the code, this is "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".

Also, the order in which the histograms are listed in
/user_cloud_policy_manager_chromeos.cc and here does not quite match. This
histogram should be second, not first in the list.

[Mattias Nissler (ping if slow), 2013-09-03 11:09:22]

PTAL.

Adding rogerta@ for google_apis/gaia/OWNERS.

https://codereview.chromium.org/23271009/diff/1/chrome/browser/chromeos/polic...
File chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
(right):

https://codereview.chromium.org/23271009/diff/1/chrome/browser/chromeos/polic...
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc:291:
base::Time now = base::Time::Now();
On 2013/08/30 10:04:40, bartfab wrote:
> Nit: const

Done.

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
tools/metrics/histograms/histograms.xml:2591: +<histogram
name="Enterprise.UserPolicyChromeOS.ClientError"
On 2013/08/30 10:04:40, bartfab wrote:
> In the code, this is "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".
> 
> Also, the order in which the histograms are listed in
> /user_cloud_policy_manager_chromeos.cc and here does not quite match. This
> histogram should be second, not first in the list.

Done.

[bartfab (slow), 2013-09-03 14:52:16]

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
tools/metrics/histograms/histograms.xml:2591: +<histogram
name="Enterprise.UserPolicyChromeOS.ClientError"
On 2013/09/03 11:09:22, Mattias Nissler wrote:
> On 2013/08/30 10:04:40, bartfab wrote:
> > In the code, this is
"Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".
> > 
> > Also, the order in which the histograms are listed in
> > /user_cloud_policy_manager_chromeos.cc and here does not quite match. This
> > histogram should be second, not first in the list.
> 
> Done.

I think you uploaded an outdated CL. This comment was not addressed.

[Mattias Nissler (ping if slow), 2013-09-03 15:24:38]

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
tools/metrics/histograms/histograms.xml:2591: +<histogram
name="Enterprise.UserPolicyChromeOS.ClientError"
On 2013/09/03 14:52:16, bartfab wrote:
> On 2013/09/03 11:09:22, Mattias Nissler wrote:
> > On 2013/08/30 10:04:40, bartfab wrote:
> > > In the code, this is
> "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".
> > > 
> > > Also, the order in which the histograms are listed in
> > > /user_cloud_policy_manager_chromeos.cc and here does not quite match. This
> > > histogram should be second, not first in the list.
> > 
> > Done.
> 
> I think you uploaded an outdated CL. This comment was not addressed.

According to the patch rietveld displays to me, ClientError is now moved down in
patchset 2:
https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...

Am I missing something?

[Roger Tawa OOO till Jul 10th, 2013-09-03 15:57:00]

lgtm for google_apis/gaia/google_service_auth_error.h, but could TBR :-)

[jar (doing other things), 2013-09-03 16:50:18]

Histograms.xml LGTM (see comment below)

https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
tools/metrics/histograms/histograms.xml:3080: +   
enum="EnterpriseDeviceManagementStatus">
I assume this is already defined.

[Mattias Nissler (ping if slow), 2013-09-03 17:08:27]

https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
tools/metrics/histograms/histograms.xml:3080: +   
enum="EnterpriseDeviceManagementStatus">
On 2013/09/03 16:50:18, jar wrote:
> I assume this is already defined.

It is, and the presubmit checks pass.

[bartfab (slow), 2013-09-03 23:14:04]

On 2013/09/03 15:24:38, Mattias Nissler wrote:
>
https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
> File tools/metrics/histograms/histograms.xml (right):
> 
>
https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
> tools/metrics/histograms/histograms.xml:2591: +<histogram
> name="Enterprise.UserPolicyChromeOS.ClientError"
> On 2013/09/03 14:52:16, bartfab wrote:
> > On 2013/09/03 11:09:22, Mattias Nissler wrote:
> > > On 2013/08/30 10:04:40, bartfab wrote:
> > > > In the code, this is
> > "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".
> > > > 
> > > > Also, the order in which the histograms are listed in
> > > > /user_cloud_policy_manager_chromeos.cc and here does not quite match.
This
> > > > histogram should be second, not first in the list.
> > > 
> > > Done.
> > 
> > I think you uploaded an outdated CL. This comment was not addressed.
> 
> According to the patch rietveld displays to me, ClientError is now moved down
in
> patchset 2:
>
https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
> 
> Am I missing something?

I was looking at the "Delta from patch set" column, expecting to see a delta
between patch sets 1 and 2 for histograms.xml. But I see now that Rietveld
decided not show a link, even though the patch changed. Thank you, Rietveld.
Very helpful :(.

LGTM

[Mattias Nissler (ping if slow), 2013-09-04 13:35:33]

On 2013/09/03 23:14:04, bartfab wrote:
> On 2013/09/03 15:24:38, Mattias Nissler wrote:
> >
>
https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
> > File tools/metrics/histograms/histograms.xml (right):
> > 
> >
>
https://codereview.chromium.org/23271009/diff/1/tools/metrics/histograms/hist...
> > tools/metrics/histograms/histograms.xml:2591: +<histogram
> > name="Enterprise.UserPolicyChromeOS.ClientError"
> > On 2013/09/03 14:52:16, bartfab wrote:
> > > On 2013/09/03 11:09:22, Mattias Nissler wrote:
> > > > On 2013/08/30 10:04:40, bartfab wrote:
> > > > > In the code, this is
> > > "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError".
> > > > > 
> > > > > Also, the order in which the histograms are listed in
> > > > > /user_cloud_policy_manager_chromeos.cc and here does not quite match.
> This
> > > > > histogram should be second, not first in the list.
> > > > 
> > > > Done.
> > > 
> > > I think you uploaded an outdated CL. This comment was not addressed.
> > 
> > According to the patch rietveld displays to me, ClientError is now moved
down
> in
> > patchset 2:
> >
>
https://codereview.chromium.org/23271009/diff/10001/tools/metrics/histograms/...
> > 
> > Am I missing something?
> 
> I was looking at the "Delta from patch set" column, expecting to see a delta
> between patch sets 1 and 2 for histograms.xml. But I see now that Rietveld
> decided not show a link, even though the patch changed. Thank you, Rietveld.
> Very helpful :(.

FWIW: It can't because it's missing the base file, and showing a diff between
two diffs isn't really readable.

> 
> LGTM

[commit-bot: I haz the power, 2013-09-04 16:32:07]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mnissler@chromium.org/23271009/10001

[commit-bot: I haz the power, 2013-09-04 16:32:10]

Failed to apply patch for
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc:
While running patch -p1 --forward --force --no-backup-if-mismatch;
  patching file
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
  Hunk #1 FAILED at 7.
  Hunk #2 succeeded at 24 (offset 2 lines).
  Hunk #3 succeeded at 55 with fuzz 2 (offset 2 lines).
  Hunk #4 succeeded at 153 (offset 10 lines).
  Hunk #5 succeeded at 199 (offset 10 lines).
  Hunk #6 succeeded at 225 (offset 10 lines).
  Hunk #7 succeeded at 265 (offset 10 lines).
  Hunk #8 succeeded at 280 (offset 10 lines).
  Hunk #9 succeeded at 295 (offset 10 lines).
  1 out of 9 hunks FAILED -- saving rejects to file
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc.rej

Patch:      
chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
Index: chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
diff --git
a/chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
b/chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
index
e3452f9547f8936ef0e6a9c93578f681475bebd0..10d64a0d0bca85df10c4cbcc506417cb7f37276f
100644
--- a/chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
+++ b/chrome/browser/chromeos/policy/user_cloud_policy_manager_chromeos.cc
@@ -7,6 +7,8 @@
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/logging.h"
+#include "base/metrics/histogram.h"
+#include "base/metrics/sparse_histogram.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chromeos/policy/policy_oauth2_token_fetcher.h"
 #include
"chrome/browser/chromeos/policy/user_cloud_policy_manager_factory_chromeos.h"
@@ -22,6 +24,28 @@ namespace em = enterprise_management;
 
 namespace policy {
 
+namespace {
+
+// UMA histogram names.
+const char kUMADelayInitialization[] =
+    "Enterprise.UserPolicyChromeOS.DelayInitialization";
+const char kUMAInitialFetchClientError[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.ClientError";
+const char kUMAInitialFetchDelayClientRegister[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.DelayClientRegister";
+const char kUMAInitialFetchDelayOAuth2Token[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.DelayOAuth2Token";
+const char kUMAInitialFetchDelayPolicyFetch[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.DelayPolicyFetch";
+const char kUMAInitialFetchDelayTotal[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.DelayTotal";
+const char kUMAInitialFetchOAuth2Error[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.OAuth2Error";
+const char kUMAInitialFetchOAuth2NetworkError[] =
+    "Enterprise.UserPolicyChromeOS.InitialFetch.OAuth2NetworkError";
+
+}  // namespace
+
 UserCloudPolicyManagerChromeOS::UserCloudPolicyManagerChromeOS(
     scoped_ptr<CloudPolicyStore> store,
     scoped_ptr<ResourceCache> resource_cache,
@@ -31,6 +55,7 @@
UserCloudPolicyManagerChromeOS::UserCloudPolicyManagerChromeOS(
           store.get()),
       store_(store.Pass()),
       wait_for_policy_fetch_(wait_for_policy_fetch) {
+  time_init_started_ = base::Time::Now();
   if (resource_cache) {
     component_policy_service_.reset(new ComponentCloudPolicyService(
         this, store_.get(), resource_cache.Pass()));
@@ -120,6 +145,11 @@ void
UserCloudPolicyManagerChromeOS::OnInitializationCompleted(
     CloudPolicyService* cloud_policy_service) {
   DCHECK_EQ(service(), cloud_policy_service);
   cloud_policy_service->RemoveObserver(this);
+
+  time_init_completed_ = base::Time::Now();
+  UMA_HISTOGRAM_TIMES(kUMADelayInitialization,
+                      time_init_completed_ - time_init_started_);
+
   // If the CloudPolicyClient isn't registered at this stage then it needs an
   // OAuth token for the initial registration.
   //
@@ -161,7 +191,14 @@ void UserCloudPolicyManagerChromeOS::OnPolicyFetched(
 void UserCloudPolicyManagerChromeOS::OnRegistrationStateChanged(
     CloudPolicyClient* cloud_policy_client) {
   DCHECK_EQ(client(), cloud_policy_client);
+
   if (wait_for_policy_fetch_) {
+    time_client_registered_ = base::Time::Now();
+    if (!time_token_available_.is_null()) {
+      UMA_HISTOGRAM_TIMES(kUMAInitialFetchDelayClientRegister,
+                          time_client_registered_ - time_token_available_);
+    }
+
     // If we're blocked on the policy fetch, now is a good time to issue it.
     if (client()->is_registered()) {
       service()->RefreshPolicy(
@@ -180,6 +217,11 @@ void UserCloudPolicyManagerChromeOS::OnClientError(
     CloudPolicyClient* cloud_policy_client) {
   DCHECK_EQ(client(), cloud_policy_client);
   CancelWaitForPolicyFetch();
+
+  if (wait_for_policy_fetch_) {
+    UMA_HISTOGRAM_SPARSE_SLOWLY(kUMAInitialFetchClientError,
+                                cloud_policy_client->status());
+  }
 }
 
 void UserCloudPolicyManagerChromeOS::OnComponentCloudPolicyRefreshNeeded() {
@@ -215,6 +257,13 @@ void
UserCloudPolicyManagerChromeOS::OnOAuth2PolicyTokenFetched(
     const std::string& policy_token,
     const GoogleServiceAuthError& error) {
   DCHECK(!client()->is_registered());
+
+  time_token_available_ = base::Time::Now();
+  if (wait_for_policy_fetch_) {
+    UMA_HISTOGRAM_TIMES(kUMAInitialFetchDelayOAuth2Token,
+                        time_token_available_ - time_init_completed_);
+  }
+
   if (error.state() == GoogleServiceAuthError::NONE) {
     // Start client registration. Either OnRegistrationStateChanged() or
     // OnClientError() will be called back.
@@ -223,6 +272,14 @@ void
UserCloudPolicyManagerChromeOS::OnOAuth2PolicyTokenFetched(
   } else {
     // Failed to get a token, stop waiting and use an empty policy.
     CancelWaitForPolicyFetch();
+
+    UMA_HISTOGRAM_ENUMERATION(kUMAInitialFetchOAuth2Error,
+                              error.state(),
+                              GoogleServiceAuthError::NUM_STATES);
+    if (error.state() == GoogleServiceAuthError::CONNECTION_FAILED) {
+      UMA_HISTOGRAM_SPARSE_SLOWLY(kUMAInitialFetchOAuth2NetworkError,
+                                  error.network_error());
+    }
   }
 
   token_fetcher_.reset();
@@ -230,6 +287,11 @@ void
UserCloudPolicyManagerChromeOS::OnOAuth2PolicyTokenFetched(
 
 void UserCloudPolicyManagerChromeOS::OnInitialPolicyFetchComplete(
     bool success) {
+
+  const base::Time now = base::Time::Now();
+  UMA_HISTOGRAM_TIMES(kUMAInitialFetchDelayPolicyFetch,
+                      now - time_client_registered_);
+  UMA_HISTOGRAM_TIMES(kUMAInitialFetchDelayTotal, now - time_init_started_);
   CancelWaitForPolicyFetch();
 }

[commit-bot: I haz the power, 2013-09-05 11:13:47]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mnissler@chromium.org/23271009/28001

[commit-bot: I haz the power, 2013-09-05 14:33:57]

Change committed as 221422