Track execution phase of browser process and track it as

a UMA histogram.

As a first attempt, tracked the following 

- Before starting metrics service,
- Before creating profile
- Before starting startup time bomb
- Before starting thread watcher
- Before starting main message loop
- Before starting shutdown time bomb
- clean shutdown.

R=jar@chromium.org

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

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

chrome/browser/chrome_browser_main.cc

@@ -1098,6 +1098,7 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
   // application is in the foreground or not. Do not start here.
 #if !defined(OS_ANDROID)
   // Now that the file thread has been started, start recording.
+  MetricsService::SetExecutionPhase(MetricsService::START_METRICS_RECORDING);
   StartMetricsRecording();
 #endif
 
@@ -1244,6 +1245,7 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
   // calls to GetDefaultProfile().
   ProfileManager::AllowGetDefaultProfile();
 
+  MetricsService::SetExecutionPhase(MetricsService::CREATE_PROFILE);
   profile_ = CreateProfile(parameters(), user_data_dir_, parsed_command_line());
   if (!profile_)
     return content::RESULT_CODE_NORMAL_EXIT;
@@ -1428,6 +1430,7 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
   // Start watching for hangs during startup. We disarm this hang detector when
   // ThreadWatcher takes over or when browser is shutdown or when
   // startup_watcher_ is deleted.
+  MetricsService::SetExecutionPhase(MetricsService::STARTUP_TIMEBOMB_ARM);
   startup_watcher_->Arm(base::TimeDelta::FromSeconds(300));
 
   // On mobile, need for clean shutdown arises only when the application comes
@@ -1449,6 +1452,7 @@ int ChromeBrowserMainParts::PreMainMessageLoopRunImpl() {
 #endif
 
   // Start watching all browser threads for responsiveness.
+  MetricsService::SetExecutionPhase(MetricsService::THREAD_WATCHER_START);
   ThreadWatcherList::StartWatchingAll(parsed_command_line());
 
 #if !defined(DISABLE_NACL)
@@ -1620,6 +1624,7 @@ bool ChromeBrowserMainParts::MainMessageLoopRun(int* result_code) {
 
   performance_monitor::PerformanceMonitor::GetInstance()->StartGatherCycle();
 
+  MetricsService::SetExecutionPhase(MetricsService::MAIN_MESSAGE_LOOP_RUN);
   run_loop.Run();
 
   return true;
@@ -1636,6 +1641,7 @@ void ChromeBrowserMainParts::PostMainMessageLoopRun() {
 
   // Start watching for jank during shutdown. It gets disarmed when
   // |shutdown_watcher_| object is destructed.
+  MetricsService::SetExecutionPhase(MetricsService::SHUTDOWN_TIMEBOMB_ARM);
   shutdown_watcher_->Arm(base::TimeDelta::FromSeconds(300));
 
   // Disarm the startup hang detector time bomb if it is still Arm'ed.

chrome/browser/metrics/metrics_service.cc

@@ -329,6 +329,8 @@ int MapCrashExitCodeForHistogram(int exit_code) {
 void MarkAppCleanShutdownAndCommit() {
   PrefService* pref = g_browser_process->local_state();
   pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
+  pref->SetInteger(prefs::kStabilityExecutionPhase,
+                   MetricsService::CLEAN_SHUTDOWN);
   // Start writing right away (write happens on a different thread).
   pref->CommitPendingWrite();
 }
@@ -339,6 +341,9 @@ void MarkAppCleanShutdownAndCommit() {
 MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
     MetricsService::CLEANLY_SHUTDOWN;
 
+MetricsService::ExecutionPhase MetricsService::execution_phase_ =
+    MetricsService::CLEAN_SHUTDOWN;
+
 // This is used to quickly log stats from child process related notifications in
 // MetricsService::child_stats_buffer_.  The buffer's contents are transferred
 // out when Local State is periodically saved.  The information is then
@@ -409,6 +414,8 @@ void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) {
   registry->RegisterStringPref(prefs::kStabilityStatsVersion, std::string());
   registry->RegisterInt64Pref(prefs::kStabilityStatsBuildTime, 0);
   registry->RegisterBooleanPref(prefs::kStabilityExitedCleanly, true);
+  registry->RegisterIntegerPref(prefs::kStabilityExecutionPhase,
+                                CLEAN_SHUTDOWN);
   registry->RegisterBooleanPref(prefs::kStabilitySessionEndCompleted, true);
   registry->RegisterIntegerPref(prefs::kMetricsSessionID, -1);
   registry->RegisterIntegerPref(prefs::kStabilityLaunchCount, 0);
@@ -445,6 +452,7 @@ void MetricsService::RegisterPrefs(PrefRegistrySimple* registry) {
 // static
 void MetricsService::DiscardOldStabilityStats(PrefService* local_state) {
   local_state->SetBoolean(prefs::kStabilityExitedCleanly, true);
+  local_state->SetInteger(prefs::kStabilityExecutionPhase, CLEAN_SHUTDOWN);
   local_state->SetBoolean(prefs::kStabilitySessionEndCompleted, true);
 
   local_state->SetInteger(prefs::kStabilityIncompleteSessionEndCount, 0);
@@ -773,6 +781,7 @@ void MetricsService::OnAppEnterBackground() {
 void MetricsService::OnAppEnterForeground() {
   PrefService* pref = g_browser_process->local_state();
   pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
+  pref->SetInteger(prefs::kStabilityExecutionPhase, execution_phase_);
 
   StartSchedulerIfNecessary();
 }
@@ -780,6 +789,7 @@ void MetricsService::OnAppEnterForeground() {
 void MetricsService::LogNeedForCleanShutdown() {
   PrefService* pref = g_browser_process->local_state();
   pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
+  pref->SetInteger(prefs::kStabilityExecutionPhase, execution_phase_);
   // Redundant setting to be sure we call for a clean shutdown.
   clean_shutdown_status_ = NEED_TO_SHUTDOWN;
 }
@@ -898,6 +908,13 @@ void MetricsService::InitializeMetricsState() {
     // Reset flag, and wait until we call LogNeedForCleanShutdown() before
     // monitoring.
     pref->SetBoolean(prefs::kStabilityExitedCleanly, true);
+
+    // TODO(rtenneti): On windows, consider saving/getting execution_phase from
+    // the registry.
+    int execution_phase = pref->GetInteger(prefs::kStabilityExecutionPhase);
+    UMA_HISTOGRAM_SPARSE_SLOWLY("Chrome.Browser.ExecutionPhase",
+                                execution_phase);
+    pref->SetInteger(prefs::kStabilityExecutionPhase, CLEAN_SHUTDOWN);
   }
 
 #if defined(OS_WIN)
@@ -1670,6 +1687,9 @@ void MetricsService::LogCleanShutdown() {
   clean_shutdown_status_ = CLEANLY_SHUTDOWN;
 
   RecordBooleanPrefValue(prefs::kStabilityExitedCleanly, true);
+  PrefService* pref = g_browser_process->local_state();
+  pref->SetInteger(prefs::kStabilityExecutionPhase,
+                   MetricsService::CLEAN_SHUTDOWN);
 }
 
 #if defined(OS_CHROMEOS)

chrome/browser/metrics/metrics_service.h

@@ -74,6 +74,17 @@ class MetricsService
       public net::URLFetcherDelegate,
       public MetricsServiceBase {
  public:
+  // The execution phase of the browser.
+  enum ExecutionPhase {
+    CLEAN_SHUTDOWN = 0,
+    START_METRICS_RECORDING = 100,
+    CREATE_PROFILE = 200,
+    STARTUP_TIMEBOMB_ARM = 300,
+    THREAD_WATCHER_START = 400,
+    MAIN_MESSAGE_LOOP_RUN = 500,
+    SHUTDOWN_TIMEBOMB_ARM = 600,
+  };
+
   MetricsService();
   virtual ~MetricsService();
 
@@ -164,6 +175,9 @@ class MetricsService
   static void LogNeedForCleanShutdown();
 #endif  // defined(OS_ANDROID) || defined(OS_IOS)
 
+  static void SetExecutionPhase(ExecutionPhase execution_phase) {
+    execution_phase_ = execution_phase;
+  }
   // Saves in the preferences if the crash report registration was successful.
   // This count is eventually send via UMA logs.
   void RecordBreakpadRegistration(bool success);
@@ -495,6 +509,9 @@ class MetricsService
   // Stores the time of the last call to |GetIncrementalUptime()|.
   base::TimeTicks last_updated_time_;
 
+  // Execution phase the browser is in.
+  static ExecutionPhase execution_phase_;
+
   // Reduntant marker to check that we completed our shutdown, and set the
   // exited-cleanly bit in the prefs.
   static ShutdownCleanliness clean_shutdown_status_;

chrome/common/pref_names.cc

@@ -1377,6 +1377,10 @@ const char kVariationsSeedDate[] = "variations_seed_date";
 // SHA-1 hash of the serialized variations seed data.
 const char kVariationsSeedHash[] = "variations_seed_hash";
 
+// An enum value to indicate the execution phase the browser was in.
+const char kStabilityExecutionPhase[] =
+    "user_experience_metrics.stability.execution_phase";
+
 // True if the previous run of the program exited cleanly.
 const char kStabilityExitedCleanly[] =
     "user_experience_metrics.stability.exited_cleanly";

chrome/common/pref_names.h

@@ -456,6 +456,7 @@ extern const char kProfilesNumCreated[];
 extern const char kProfileInfoCache[];
 extern const char kProfileCreatedByVersion[];
 
+extern const char kStabilityExecutionPhase[];
 extern const char kStabilityExitedCleanly[];
 extern const char kStabilityStatsVersion[];
 extern const char kStabilityStatsBuildTime[];

chrome_frame/test/reliability/page_load_test.cc

@@ -136,6 +136,7 @@ class PageLoadTest : public testing::Test {
     int crash_dump_count;
     // These are stability metrics recorded by Chrome itself
     bool browser_clean_exit;
+    int browser_execution_phase;
     int browser_launch_count;
     int page_load_count;
     int browser_crash_count;
@@ -446,6 +447,7 @@ class PageLoadTest : public testing::Test {
       return;
     scoped_refptr<PrefRegistrySimple> registry = new PrefRegistrySimple();
     registry->RegisterBooleanPref(prefs::kStabilityExitedCleanly, false);
+    registry->RegisterIntegerPref(prefs::kStabilityExecutionPhase, 0);
     registry->RegisterIntegerPref(prefs::kStabilityLaunchCount, -1);
     registry->RegisterIntegerPref(prefs::kStabilityPageLoadCount, -1);
     registry->RegisterIntegerPref(prefs::kStabilityCrashCount, 0);
@@ -457,6 +459,8 @@ class PageLoadTest : public testing::Test {
 
     metrics->browser_clean_exit =
         local_state->GetBoolean(prefs::kStabilityExitedCleanly);
+    metrics->browser_execution_phase =
+        local_state->GetInteger(prefs::kStabilityExecutionPhase);
     metrics->browser_launch_count =
         local_state->GetInteger(prefs::kStabilityLaunchCount);
     metrics->page_load_count =