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

base/prefs/json_pref_store.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/prefs/json_pref_store.h"
 
 #include <algorithm>
 
 #include "base/bind.h"
 #include "base/callback.h"
 #include "base/file_util.h"
 #include "base/json/json_file_value_serializer.h"
 #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 {
 
 // Some extensions we'll tack on to copies of the Preferences files.
 const base::FilePath::CharType* kBadExtension = FILE_PATH_LITERAL("bad");
 
 // Differentiates file loading between origin thread and passed
 // (aka file) thread.
 class FileThreadDeserializer
@@ skipping 278 matching lines @@
       // If the file just doesn't exist, maybe this is first run.  In any case
       // there's no harm in writing out default prefs in this case.
       break;
     case PREF_READ_ERROR_JSON_PARSE:
     case PREF_READ_ERROR_JSON_REPEAT:
       break;
     default:
       NOTREACHED() << "Unknown error: " << error;
   }
 
-  if (pref_filter_)
+  if (pref_filter_) {
+    // TODO(gab): Remove this histogram after sufficient timing data has been
+    // gathered from the wild to be confident this doesn't significantly affect
+    // startup.

[Nico, 2014/01/29 17:58:13]

Put a date on this ("remove by Feb 14" or similar) and below.

[gab, 2014/01/29 19:15:56]

Done, used Feb 21, might be before if the data appears conclusive.

+    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);
 
   FOR_EACH_OBSERVER(PrefStore::Observer,
                     observers_,
                     OnInitializationCompleted(true));
 }
 
 JsonPrefStore::~JsonPrefStore() {
   CommitPendingWrite();
 }
 
 bool JsonPrefStore::SerializeData(std::string* output) {
-  if (pref_filter_)
+  if (pref_filter_) {
+    // TODO(gab): Remove this histogram 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);
   return serializer.Serialize(*prefs_);
 }