[Sync] Log time spent configuring data types

chrome/browser/sync/glue/data_type_manager_impl.cc

Index: chrome/browser/sync/glue/data_type_manager_impl.cc
diff --git a/chrome/browser/sync/glue/data_type_manager_impl.cc b/chrome/browser/sync/glue/data_type_manager_impl.cc
index a918f464c2a6db68239d586895507ee60d2e164f..3a7ca4c5bd59559e23550b5ee2cfd71e67d39d7c 100644
--- a/chrome/browser/sync/glue/data_type_manager_impl.cc
+++ b/chrome/browser/sync/glue/data_type_manager_impl.cc
@@ -10,6 +10,7 @@
 #include "base/compiler_specific.h"
 #include "base/logging.h"
 #include "base/message_loop.h"
+#include "base/metrics/histogram.h"
 #include "chrome/browser/sync/glue/data_type_controller.h"
 #include "chrome/browser/sync/glue/sync_backend_host.h"
 #include "content/browser/browser_thread.h"
@@ -154,6 +155,7 @@ void DataTypeManagerImpl::Configure(const TypeSet& desired_types,
 
 void DataTypeManagerImpl::Restart(sync_api::ConfigureReason reason) {
   VLOG(1) << "Restarting...";
+  last_restart_time_ = base::Time::Now();
 
   DCHECK(state_ == STOPPED || state_ == CONFIGURED || state_ == BLOCKED);
 
@@ -363,7 +365,34 @@ void DataTypeManagerImpl::NotifyDone(ConfigureResult result,
     const tracked_objects::Location& location) {
   ConfigureResultWithErrorLocation result_with_location(result, location,
                                                         last_requested_types_);
-  VLOG(1) << "NotifyDone called with result: " << result;
+  AddToConfigureTime();
+  VLOG(1) << "Total time spent configuring: "
+          << configure_time_delta_.InSecondsF() << "s";
+  switch (result) {
+    case DataTypeManager::OK:
+      VLOG(1) << "NotifyDone called with result: OK";
+      UMA_HISTOGRAM_TIMES("Sync.ConfigureTime.OK",
+                          configure_time_delta_);
+      break;
+    case DataTypeManager::ASSOCIATION_FAILED:
+      VLOG(1) << "NotifyDone called with result: ASSOCIATION_FAILED";
+      UMA_HISTOGRAM_TIMES("Sync.ConfigureTime.ASSOCIATION_FAILED",
+                          configure_time_delta_);
+      break;
+    case DataTypeManager::ABORTED:
+      VLOG(1) << "NotifyDone called with result: ABORTED";
+      UMA_HISTOGRAM_TIMES("Sync.ConfigureTime.ABORTED",
+                          configure_time_delta_);
+      break;
+    case DataTypeManager::UNRECOVERABLE_ERROR:
+      VLOG(1) << "NotifyDone called with result: UNRECOVERABLE_ERROR";
+      UMA_HISTOGRAM_TIMES("Sync.ConfigureTime.UNRECOVERABLE_ERROR",
+                          configure_time_delta_);
+      break;
+    default:
+      NOTREACHED();
+      break;
+  }
   NotificationService::current()->Notify(
       NotificationType::SYNC_CONFIGURE_DONE,
       Source<DataTypeManager>(this),
@@ -380,10 +409,18 @@ DataTypeManager::State DataTypeManagerImpl::state() {
 
 void DataTypeManagerImpl::SetBlockedAndNotify() {
   state_ = BLOCKED;
+  AddToConfigureTime();
+  VLOG(1) << "Accumulated spent configuring: "
+          << configure_time_delta_.InSecondsF() << "s";
   NotificationService::current()->Notify(
       NotificationType::SYNC_CONFIGURE_BLOCKED,
       Source<DataTypeManager>(this),
       NotificationService::NoDetails());
 }
 
+void DataTypeManagerImpl::AddToConfigureTime() {
+  DCHECK(!last_restart_time_.is_null());
+  configure_time_delta_ += (base::Time::Now() - last_restart_time_);
+}
+
 }  // namespace browser_sync