[Sync] Log time spent configuring data types

Add UMA histograms, too.

BUG=
TEST=

Review URL: http://codereview.chromium.org/6948010

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@84732 0039d316-1c4b-4281-b951-d872f2087c98

3 files changed, 52 insertions, 1 deletions

diff --git a/chrome/browser/sync/glue/data_type_manager.h b/chrome/browser/sync/glue/data_type_manager.h
index 78aced43..c621b49 100644
--- a/chrome/browser/sync/glue/data_type_manager.h
+++ b/chrome/browser/sync/glue/data_type_manager.h
@@ -34,6 +34,8 @@ class DataTypeManager {
     STOPPING           // Data types are being stopped.
   };
 
+  // Update NotifyDone() in data_type_manager_impl.cc if you update
+  // this.
   enum ConfigureResult {
     OK,                  // Configuration finished without error.
     ASSOCIATION_FAILED,  // An error occurred during model association.
diff --git a/chrome/browser/sync/glue/data_type_manager_impl.cc b/chrome/browser/sync/glue/data_type_manager_impl.cc
index a918f46..3a7ca4c 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
diff --git a/chrome/browser/sync/glue/data_type_manager_impl.h b/chrome/browser/sync/glue/data_type_manager_impl.h
index 9764981..bd77074 100644
--- a/chrome/browser/sync/glue/data_type_manager_impl.h
+++ b/chrome/browser/sync/glue/data_type_manager_impl.h
@@ -13,6 +13,7 @@
 
 #include "base/basictypes.h"
 #include "base/task.h"
+#include "base/time.h"
 
 namespace browser_sync {
 
@@ -59,6 +60,10 @@ class DataTypeManagerImpl : public DataTypeManager {
       const tracked_objects::Location& location);
   void SetBlockedAndNotify();
 
+  // Add to |configure_time_delta_| the time since we last called
+  // Restart().
+  void AddToConfigureTime();
+
   SyncBackendHost* backend_;
   // Map of all data type controllers that are available for sync.
   // This list is determined at startup by various command line flags.
@@ -79,6 +84,13 @@ class DataTypeManagerImpl : public DataTypeManager {
 
   ScopedRunnableMethodFactory<DataTypeManagerImpl> method_factory_;
 
+  // The last time Restart() was called.
+  base::Time last_restart_time_;
+
+  // The accumulated time spent between calls to Restart() and going
+  // to the DONE/BLOCKED state.
+  base::TimeDelta configure_time_delta_;
+
   DISALLOW_COPY_AND_ASSIGN(DataTypeManagerImpl);
 };