Great find!

I wonder what actually happens when Chrome starts from an "empty" process. That is, I don't know whether the Application object is removed or not (I would guess not, as unloading code is not that easy).

nice! assuming that this reliably characterizes the time of a fork, this will allow to remove the android hack that we use to measure the starting point in startup metrics (recorded from Java and then converted).

@pasko: I suspect that we still want to keep this metric, of only for the sake of historical comparison. But also because it tells us the amount of time that we can control directly (by doing less work), rather than indirectly (through reducing the dex size, for instance).

I agree that more metrics provide a better picture, but they are also costly to support. Would it be sufficient to convert the current one to the early java tracepoint? Tiny loss of precision here, and available only when early java traces are enabled, but overall I think it's a nice tradeoff (carrying the timestamps in android-specific ways is one of my most hated pieces of code).

of course, during transition we can watch how the two metrics work together

I'd hoping to create a metric that is a good representation of dex loading time (issue 512357) and I was playing around with this a bit.

Adding logging to ChromeApplication.attachBaseContext():
System.currentTimeMillis() - new File("/proc/self/stat").lastModified()

and then running:
while :; sleep 5; do out/Release/bin/chrome_public_apk stop && out/Release/bin/chrome_public_apk launch; done

On a Nexus 6p I'm seeing values anywhere from 50 - 1000 ms, averaging ~500 ms with standard deviation of ~300ms.. Doesn't seem very reliable to me, any thoughts here? Is there a good way to ensure consistency of startup conditions?

Not totally unexpected, but yeah, 300ms stdev is a bit large.

> Is there a good way to ensure consistency of startup conditions?

I don't think there is. Though you can try doing a 1000 startups with trace/systrace (in reasonable time) and then figuring out unique properties of the outliers. Time consuming at the analysis time, not recommended.

If you have a change that you want to one-time benchmark to prove usefulness of the optimization, there is a way we used in the past:
* put your optimization under a flag and randomize the flag value to avoid time skew (this is ideal, not sure it is possible with the multidex optimization you have)
* start 1000 or more times
* get all the raw data and plot a side by side histograms [1] for each value of the flag
* later may throw some fancy stats at it, but stopping at the plot is often sufficiently practical-&-non-scientific :)

If you want to go this route, let's discuss more, it is nuanced.

[1] 'Histogram' is an overloaded term, I am referring to https://en.wikipedia.org/wiki/Histogram. And the plot can look like:

https://pandas.pydata.org/pandas-docs/version/0.18.1/_images/hist_new_stacked.png

or

https://pandas.pydata.org/pandas-docs/version/0.18.1/_images/hist_new.png

There are some device bits you can set to try and make runs more reproducible:
https://cs.chromium.org/chromium/src/third_party/catapult/devil/devil/android/perf/

Looks like many scripts just use the drop_caches module, but might be nice to have something under tools/android that would enable them all, then be able to restore their settings after.

Re #9: Interesting approach! Sounds like it would work well as a one-time benchmark as you mentioned but I was hoping for something that we could use to monitor loading over time.

I'll retry with drop_caches and see if that makes a difference.

I am getting increasingly skeptical about using process creation time on Android, leaning towards WontFix.

This clock seems to be wallclock-based in the kernel. It drifts differently from the monotonic ticks-based clocks that we prefer for performance measurement (uptimeMillis() == clock_gettime(CLOCK_MONOTONIC) and elapsedRealtime()). On Android the drift seems to be a bigger problem than on other platforms because the NTP sync on the device correlates with when the device gets online, which correlates heavily with Chrome startup.

We often observe ~15 _minutes_ of drift on BrowserMessageLoopStartTimeFromMainEntry2 (reported in Issue 795836) and I suspect it may be partly because of this drift that happens when wallclock is adjusted by NTP.

Searching around I found this report about wallclock being imprecise: [1], which beyond various good observations points at 15s error on some devices when the time is coming from GPS. It is not hard to imagine that the wallclock would jump back and forth in amount of 15s when switching between NTP and GPS as source. I am not 100% sure this actually happens. On the other hand, monotonic ticks do not have all these problems.

[1] OpenSignal: Android clock errors: June, 2013
    https://opensignal.com/reports/timestamps/

One correction: For process creation time on Linux we are using /proc/self/stat which is ticks-based: 

https://codesearch.chromium.org/chromium/src/base/process/internal_linux.cc?type=cs&sq=package:chromium&l=215

This idea was about looking at ctime of a file in /proc/self, which would involve calling stat(2), which reads it as wallclock from the kernel timer that is based on CLOCK_REALTIME (at least for ext4 (xtime), see 'struct timekeeper' in the kernel). Complicated :)

Complicated indeed!

Locally I've been launching ChromeTabbedActivity and greping logcat for:

12-28 15:12:44.656   932   951 I ActivityManager: Displayed org.chromium.chrome/.browser.ChromeTabbedActivity: +1s18ms

It's been fairly stable (std dev < 80 ms) and seems to be a good way to measure dex loading time.