Set process phases in the StackSamplingProfiler.

components/startup_metric_utils/browser/startup_metric_utils.cc

Index: components/startup_metric_utils/browser/startup_metric_utils.cc
diff --git a/components/startup_metric_utils/browser/startup_metric_utils.cc b/components/startup_metric_utils/browser/startup_metric_utils.cc
index 6d9ffcc2da6bda3e1333fba7211fcbb624c6c3ce..e2eee42f6d21c6a52b9568e69feb9b5fbc855ad6 100644
--- a/components/startup_metric_utils/browser/startup_metric_utils.cc
+++ b/components/startup_metric_utils/browser/startup_metric_utils.cc
@@ -16,11 +16,13 @@
 #include "base/metrics/histogram.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/process/process_info.h"
+#include "base/profiler/stack_sampling_profiler.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/sys_info.h"
 #include "base/threading/platform_thread.h"
 #include "base/trace_event/trace_event.h"
 #include "build/build_config.h"
+#include "components/metrics/call_stack_profile_metrics_provider.h"
 #include "components/prefs/pref_registry_simple.h"
 #include "components/prefs/pref_service.h"
 #include "components/startup_metric_utils/browser/pref_names.h"
@@ -601,6 +603,9 @@ void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
   RecordSystemUptimeHistogram();
   RecordMainEntryTimeHistogram();
 
+  base::StackSamplingProfiler::SetProcessPhase(
+      metrics::CallStackProfileMetricsProvider::MAIN_LOOP_START);

[Mike Wittman, 2016/12/01 18:46:50]

This line should be as close as possible to where we get the time, but
unfortunately that's is in the caller and not proximate to the histogram
recording below.

To keep these three things together I'd suggest making the
base::TimeTicks::Now() call at the start of this function, then setting the
phase.

[Alexei Svitkine (slow), 2016/12/01 19:49:12]

Right, I think we need to clearly define what SetProcessPhase() means - because
its name implies you should call it at the *start* of a phase, but the way this
CL is doing it, is you're calling it at the *end* of a phase - i.e. you're
calling it when the histogram is logged - which is at the end of the time.

I agree that logging the *end* of a phase is nice because then you can keep the
code to set it can live right next to the histogram - as is being done here.
However, then the API should be renamed to make that clear.

[Alexei Svitkine (slow), 2017/01/05 20:54:12]

Ping on this comment.

[bcwhite, 2017/01/06 16:50:56]

In this case, the name indicates that the "main loop has started".  Perhaps
simply changing the name to MAIN_LOOP_STARTED would be sufficient?

[Alexei Svitkine (slow), 2017/01/09 19:12:18]

I guess I'm less concerned with the name and more that I would like to make the
API & comment more explicit by what is meant.

e.g. change SetProcessPhase to something like SetLastCompletedProcessPhase() -
to make it clear that a call to this function implies the phase ended and not
started. Otherwise, its name makes me think you're setting the current phase
that's happening right now.

[bcwhite, 2017/01/10 17:56:54]

That's not what it does, though.  Perhaps "SetProcessMilestone" would be a
better name because it's not specifically beginning or ending of a phase.  For
example, the "shutdown" phase indicates that shutdown in starting.

[Mike Wittman, 2017/01/10 20:10:36]

Just noticed that this comment still remains to be addressed. Please make this
change before submitting.

[bcwhite, 2017/01/11 16:15:48]

If I understand you correctly, this amounts to removing the |ticks| parameter
and getting it directly at the start of the method, then immediately setting the
phase.

[Mike Wittman, 2017/01/11 16:24:47]

Yes, and moving the histogram recording immediately after that.

[bcwhite, 2017/01/11 16:26:39]

Looking further, every other method also takes a time parameter so I think we
should keep the parameter for consistency sake.  But I'll move the histogram
set.

[Mike Wittman, 2017/01/11 16:30:18]

Sounds good to me.

[bcwhite, 2017/01/11 16:53:28]

Done (order) and Done (naming).

+
   const base::TimeTicks& process_creation_ticks =
       g_process_creation_ticks.Get();
   if (!is_first_run && !process_creation_ticks.is_null()) {
@@ -736,6 +741,8 @@ void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
   if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
     return;
 
+  base::StackSamplingProfiler::SetProcessPhase(
+      metrics::CallStackProfileMetricsProvider::FIRST_NONEMPTY_PAINT);
   UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
       UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.NonEmptyPaint2",
       g_process_creation_ticks.Get(), ticks);
@@ -749,6 +756,8 @@ void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks) {
   if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
     return;
 
+  base::StackSamplingProfiler::SetProcessPhase(
+      metrics::CallStackProfileMetricsProvider::MAIN_NAVIGATION_START);
   UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
       UMA_HISTOGRAM_LONG_TIMES_100,
       "Startup.FirstWebContents.MainNavigationStart",
@@ -764,6 +773,8 @@ void RecordFirstWebContentsMainNavigationFinished(
   if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
     return;
 
+  base::StackSamplingProfiler::SetProcessPhase(
+      metrics::CallStackProfileMetricsProvider::MAIN_NAVIGATION_FINISHED);
   UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
       UMA_HISTOGRAM_LONG_TIMES_100,
       "Startup.FirstWebContents.MainNavigationFinished",