Commit f86681ce authored by Egor Pasko's avatar Egor Pasko Committed by Commit Bot

startup_metric_utils: remove main entry computed ticks

For a little while we have been recording startup metrics based on main
entry point time using two techniques:
* (old way) by converting process creation wall time using
  StartupTimeToTimeTicks()
* (new way) by calling base::TimeTicks::Now()

The new way is theoretically cleaner and removes a few possible skews
(see details in the bug). During a few months of overlap we have been
computing these two histograms for the identical time interval:
* (old way) Startup.BrowserMessageLoopStartTimeFromMainEntry2
* (new way) Startup.BrowserMessageLoopStartTimeFromMainEntry3

On Windows the skew between the two is super tiny (2-3 UMA samples with
difference during the day).

On Android the difference is between 0.5% and 0.7% for the same day for
various quantiles. The overflow bucket (1 hour and more) for the new
histogram is 3.5x smaller - nice. Also the new histogram looks a tiny
bit smoother on Android. Overall the shape of the distribution does not
change our subjective perception of the startup metrics on Android.

Based on these observations this change proposes to:
* Switch the remaining calculations based on the main entry point to the
  new way - calling base::TimeTicks::Now() (no conversion to ticks, not
  using the wallclock)
* Avoid renaming the histograms because the expected difference is
  likely not worth worrying
* Celebrate cleanup :)

Bug: 797762
Change-Id: I5c32541280c359d6571cbcc5c6e7500b79002011
Reviewed-on: https://chromium-review.googlesource.com/1104696Reviewed-by: default avatarFrançois Doray <fdoray@chromium.org>
Commit-Queue: Egor Pasko <pasko@chromium.org>
Cr-Commit-Position: refs/heads/master@{#568189}
parent 17651d3d
......@@ -47,8 +47,6 @@ base::TimeTicks g_process_creation_ticks;
base::TimeTicks g_browser_main_entry_point_ticks;
base::TimeTicks g_browser_main_entry_point_ticks_computed_from_time;
base::TimeTicks g_renderer_main_entry_point_ticks;
base::TimeTicks g_browser_exe_main_entry_point_ticks;
......@@ -433,22 +431,21 @@ base::TimeTicks StartupTimeToTimeTicks(base::Time time) {
}
void RecordRendererMainEntryHistogram() {
if (!g_browser_main_entry_point_ticks_computed_from_time.is_null() &&
if (!g_browser_main_entry_point_ticks.is_null() &&
!g_renderer_main_entry_point_ticks.is_null()) {
UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMainToRendererMain",
g_browser_main_entry_point_ticks_computed_from_time,
g_renderer_main_entry_point_ticks);
g_browser_main_entry_point_ticks, g_renderer_main_entry_point_ticks);
}
}
void AddStartupEventsForTelemetry()
{
DCHECK(!g_browser_main_entry_point_ticks_computed_from_time.is_null());
DCHECK(!g_browser_main_entry_point_ticks.is_null());
TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
"startup", "Startup.BrowserMainEntryPoint", 0,
g_browser_main_entry_point_ticks_computed_from_time);
TRACE_EVENT_INSTANT_WITH_TIMESTAMP0("startup",
"Startup.BrowserMainEntryPoint", 0,
g_browser_main_entry_point_ticks);
}
// Logs the Startup.TimeSinceLastStartup histogram. Obtains the timestamp of the
......@@ -551,11 +548,6 @@ void RecordMainEntryPointTime(base::Time wall_time, base::TimeTicks ticks) {
DCHECK(g_browser_main_entry_point_ticks.is_null());
g_browser_main_entry_point_ticks = ticks;
DCHECK(!g_browser_main_entry_point_ticks.is_null());
DCHECK(g_browser_main_entry_point_ticks_computed_from_time.is_null());
g_browser_main_entry_point_ticks_computed_from_time =
StartupTimeToTimeTicks(wall_time);
DCHECK(!g_browser_main_entry_point_ticks_computed_from_time.is_null());
}
void RecordExeMainEntryPointTicks(base::TimeTicks ticks) {
......@@ -598,14 +590,8 @@ void RecordBrowserMainMessageLoopStart(base::TimeTicks ticks,
UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE(
UMA_HISTOGRAM_LONG_TIMES,
"Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun2",
g_browser_main_entry_point_ticks_computed_from_time, ticks);
g_browser_main_entry_point_ticks, ticks);
} else {
// TODO(pasko): Stop recording the "...MainEntry2" histogram after M65 hits
// Stable.
UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
UMA_HISTOGRAM_LONG_TIMES,
"Startup.BrowserMessageLoopStartTimeFromMainEntry2",
g_browser_main_entry_point_ticks_computed_from_time, ticks);
UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
UMA_HISTOGRAM_LONG_TIMES,
"Startup.BrowserMessageLoopStartTimeFromMainEntry3",
......@@ -629,15 +615,13 @@ void RecordBrowserMainMessageLoopStart(base::TimeTicks ticks,
// chrome.exe:main() to chrome.dll:main().
UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ExeMainToDllMain2",
g_browser_exe_main_entry_point_ticks,
g_browser_main_entry_point_ticks_computed_from_time);
g_browser_exe_main_entry_point_ticks, g_browser_main_entry_point_ticks);
// Process create to chrome.dll:main(). Reported as a histogram only as
// the other two events above are sufficient for tracing purposes.
UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain2",
g_browser_main_entry_point_ticks_computed_from_time -
g_process_creation_ticks);
g_browser_main_entry_point_ticks - g_process_creation_ticks);
}
}
......@@ -792,7 +776,7 @@ void RecordBrowserWindowFirstPaintCompositingEnded(
}
base::TimeTicks MainEntryPointTicks() {
return g_browser_main_entry_point_ticks_computed_from_time;
return g_browser_main_entry_point_ticks;
}
} // namespace startup_metric_utils
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment