Add extra histogram latency tracking in PreMainMessageLoopRunImpl.

chrome/browser/chrome_browser_main.cc

Index: chrome/browser/chrome_browser_main.cc
diff --git a/chrome/browser/chrome_browser_main.cc b/chrome/browser/chrome_browser_main.cc
index 3af4c611d1d4f5ae87ea353d7983a8d746302712..897212608127c2d86bf40db771572d2aafa16f69 100644
--- a/chrome/browser/chrome_browser_main.cc
+++ b/chrome/browser/chrome_browser_main.cc
@@ -1121,6 +1121,7 @@ void ChromeBrowserMainParts::PostBrowserStart() {
 int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
   TRACE_EVENT0("startup", "ChromeBrowserMainParts::PreMainMessageLoopRunImpl");
   SCOPED_UMA_HISTOGRAM_LONG_TIMER("Startup.PreMainMessageLoopRunImplLongTime");
+  const base::TimeTicks start_time_step1 = base::TimeTicks::Now();
   // Android updates the metrics service dynamically depending on whether the
   // application is in the foreground or not. Do not start here.
 #if !defined(OS_ANDROID)
@@ -1293,12 +1294,18 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
   metrics::MetricsService::SetExecutionPhase(
       metrics::MetricsService::CREATE_PROFILE,
       g_browser_process->local_state());
+
+  UMA_HISTOGRAM_TIMES("Startup.PreMainMessageLoopRunImplStep1Time",
+                       base::TimeTicks::Now() - start_time_step1);
+
   profile_ = CreatePrimaryProfile(parameters(),

[Alexei Svitkine (slow), 2015/02/26 20:58:39]

Add a comment that this function is covered by a histogram, else it looks like a
bug that your histograms aren't covering it.

[rkaplow, 2015/02/28 20:09:47]

Done.

                                   user_data_dir_,
                                   parsed_command_line());
   if (!profile_)
     return content::RESULT_CODE_NORMAL_EXIT;
 
+  const base::TimeTicks start_time_step2 = base::TimeTicks::Now();
+
 #if !defined(OS_ANDROID)
   // The first run sentinel must be created after the process singleton was
   // grabbed and no early return paths were otherwise hit above.
@@ -1546,8 +1553,15 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
       g_browser_process->profile_manager()->GetLastOpenedProfiles();
 #endif
 
-  if (browser_creator_->Start(parsed_command_line(), base::FilePath(),
-                              profile_, last_opened_profiles)) {
+  UMA_HISTOGRAM_TIMES("Startup.PreMainMessageLoopRunImplStep2Time",
+                       base::TimeTicks::Now() - start_time_step2);
+
+  bool started = browser_creator_->Start(parsed_command_line(),

[Alexei Svitkine (slow), 2015/02/26 20:58:40]

Ditto.

[rkaplow, 2015/02/28 20:09:47]

Done.

+                                         base::FilePath(),
+                                         profile_,
+                                         last_opened_profiles);
+  const base::TimeTicks start_time_step3 = base::TimeTicks::Now();
+  if (started) {
 #if defined(OS_WIN) || (defined(OS_LINUX) && !defined(OS_CHROMEOS))
     // Initialize autoupdate timer. Timer callback costs basically nothing
     // when browser is not in persistent mode, so it's OK to let it ride on
@@ -1626,6 +1640,10 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
     RecordBrowserStartupTime();
   }
 #endif
+
+  UMA_HISTOGRAM_TIMES("Startup.PreMainMessageLoopRunImplStep3Time",
+                       base::TimeTicks::Now() - start_time_step3);
+
   return result_code_;
 }