Add a Settings.FilterOnLoadTime histogram to observe time spent on this critical path in the wild.

This call is on the startup path; we believe all regressions have been addressed, but would like data from the wild to see how this truly behaves in various user configurations.

BUG=330908

Review URL: https://codereview.chromium.org/149073003

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

2 files changed, 31 insertions, 2 deletions

diff --git a/base/prefs/json_pref_store.cc b/base/prefs/json_pref_store.cc
index 0703075..2903042 100644
--- a/base/prefs/json_pref_store.cc
+++ b/base/prefs/json_pref_store.cc
@@ -13,9 +13,11 @@
 #include "base/json/json_string_value_serializer.h"
 #include "base/memory/ref_counted.h"
 #include "base/message_loop/message_loop_proxy.h"
+#include "base/metrics/histogram.h"
 #include "base/prefs/pref_filter.h"
 #include "base/sequenced_task_runner.h"
 #include "base/threading/sequenced_worker_pool.h"
+#include "base/time/time.h"
 #include "base/values.h"
 
 namespace {
@@ -314,8 +316,15 @@ void JsonPrefStore::OnFileRead(base::Value* value_owned,
       NOTREACHED() << "Unknown error: " << error;
   }
 
-  if (pref_filter_)
+  if (pref_filter_) {
+    // TODO(gab): Remove this histogram by Feb 21 2014; after sufficient timing
+    // data has been gathered from the wild to be confident this doesn't
+    // significantly affect startup.
+    base::TimeTicks checkpoint = base::TimeTicks::Now();
     pref_filter_->FilterOnLoad(prefs_.get());
+    UMA_HISTOGRAM_TIMES("Settings.FilterOnLoadTime",
+                        base::TimeTicks::Now() - checkpoint);
+  }
 
   if (error_delegate_.get() && error != PREF_READ_ERROR_NONE)
     error_delegate_->OnError(error);
@@ -330,8 +339,15 @@ JsonPrefStore::~JsonPrefStore() {
 }
 
 bool JsonPrefStore::SerializeData(std::string* output) {
-  if (pref_filter_)
+  if (pref_filter_) {
+    // TODO(gab): Remove this histogram by Feb 21 2014; after sufficient timing
+    // data has been gathered from the wild to be confident this doesn't
+    // significantly affect performance on the UI thread.
+    base::TimeTicks checkpoint = base::TimeTicks::Now();
     pref_filter_->FilterSerializeData(prefs_.get());
+    UMA_HISTOGRAM_TIMES("Settings.FilterSerializeDataTime",
+                        base::TimeTicks::Now() - checkpoint);
+  }
 
   JSONStringValueSerializer serializer(output);
   serializer.set_pretty_print(true);
diff --git a/tools/metrics/histograms/histograms.xml b/tools/metrics/histograms/histograms.xml
index 98af9f6..6139f20 100644
--- a/tools/metrics/histograms/histograms.xml
+++ b/tools/metrics/histograms/histograms.xml
@@ -17343,6 +17343,19 @@ other types of suffix sets.
   </summary>
 </histogram>
 
+<histogram name="Settings.FilterOnLoadTime" units="milliseconds">
+  <summary>
+    The amount of time it took to run PrefHashFilter::FilterOnLoad on startup.
+  </summary>
+</histogram>
+
+<histogram name="Settings.FilterSerializeDataTime" units="milliseconds">
+  <summary>
+    The amount of time it took to run PrefHashFilter::FilterSerializeData on the
+    UI thread prior to writing the Preferences file to disk.
+  </summary>
+</histogram>
+
 <histogram name="Settings.GivenShowHomeButton_HomePageIsNewTabPage"
     enum="Boolean">
   <summary>