Header image: Ressence Type 5 Tilt by Romain Guy.
This blog series is focused on stability and performance monitoring of Android apps in production. Last week, I wrote about using process importance to determine why an app was started.
To track cold start time, we need to know when the app started. There are many ways to do that and this blog evaluates different approaches.
As a reminder, I already established in Android Vitals - What time is it? that I would use SystemClock.uptimeMillis() to measure time intervals.
Application.onCreate()
The simplest approach is to capture the time at which Application.onCreate() is called.
class MyApp : Application() {
var applicationOnCreateMs: Long = 0
override fun onCreate() {
super.onCreate()
applicationOnCreateMs = SystemClock.uptimeMillis()
}
}
ContentProvider.onCreate()
In How does Firebase initialize on Android? we learn that a safe early initialization hook for library developers is ContentProvider.onCreate():
class StartTimeProvider : ContentProvider() {
var providerOnCreateMs: Long = 0
override fun onCreate(): Boolean {
providerOnCreateMs = SystemClock.uptimeMillis()
return false
}
}
ContentProvider.onCreate() also works for app developers and it's called earlier in the app lifecycle than Application.onCreate().
Class load time
Before any class can be used, it has to be loaded. We can rely on static initializers to store the time at which specific classes are loaded.
We could track the time at which the Application class is loaded:
class MyApp : Application() {
companion object {
val applicationClassLoadMs = SystemClock.uptimeMillis()
}
}
In Android Vitals - Diving into cold start waters 🥶, we learnt that on Android P+ the first class loaded is the AppComponentFactory:
@RequiresApi(Build.VERSION_CODES.P)
class StartTimeFactory : androidx.core.app.AppComponentFactory() {
companion object {
val factoryClassLoadMs = SystemClock.uptimeMillis()
}
}
<?xml version="1.0" encoding="utf-8"?>
<manifest
xmlns:android="http://schemas.android.com/apk/res/android"
xmlns:tools="http://schemas.android.com/tools"
package="com.example">
<!-- Replace AndroidX appComponentFactory. -->
<application
android:appComponentFactory="com.example.StartTimeFactory"
tools:replace="android:appComponentFactory"
tools:targetApi="p" />
</manifest>
To track start time before Android P, Library developers can rely on the class load time of providers:
class StartTimeProvider : ContentProvider() {
companion object {
val providerClassLoadMs = SystemClock.uptimeMillis()
}
}
The class loading order will usually be AppComponentFactory > Application > ContentProvider. That may change if your AppComponentFactory loads other classes on class load.
Process fork time
We know that every app process starts by being forked from Zygote. On Linux & Android, there's a file called /proc/[pid]/stat that is readable and contains stats for each process, including the process start time.
Let's check out man proc, under the /proc/[pid]/stat section:
(2) comm %s
The filename of the executable, in parentheses.
This is visible whether or not the executable is
swapped out.
...
(22) starttime %llu
The time the process started after system boot. In
kernels before Linux 2.6, this value was expressed
in jiffies. Since Linux 2.6, the value is expressed
in clock ticks (divide by sysconf(_SC_CLK_TCK)).
/proc/[pid]/stat is a file with one line of text, where each stat is separated by a space. However, the second entry is the filename of the executable, which may contain spaces, so we'll have to jump past it by looking for the first ) character. Once we've done that, we can split the remaining string by spaces and pick the 20th entry at index 19.
object Processes {
fun readProcessForkRealtimeMillis(): Long {
val myPid = android.os.Process.myPid()
val ticksAtProcessStart = readProcessStartTicks(myPid)
// Min API 21, use reflection before API 21.
// See https://stackoverflow.com/a/42195623/703646
val ticksPerSecond = Os.sysconf(OsConstants._SC_CLK_TCK)
return ticksAtProcessStart * 1000 / ticksPerSecond
}
// Benchmarked (with Jetpack Benchmark) on Pixel 3 running
// Android 10. Median time: 0.13ms
fun readProcessStartTicks(pid: Int): Long {
val path = "/proc/$pid/stat"
val stat = BufferedReader(FileReader(path)).use { reader ->
reader.readLine()
}
val fields = stat.substringAfter(") ")
.split(' ')
return fields[19].toLong()
}
}
This gives us the realtime for when the process was forked. We can convert that to uptime:
val forkRealtime = Processes.readProcessForkRealtimeMillis()
val nowRealtime = SystemClock.elapsedRealtime()
val nowUptime = SystemClock.uptimeMillis()
val elapsedRealtime = nowRealtime - forkRealtime
val forkUptimeMs = nowUptime - elapsedRealtimeMs
This gives us the real process start time. However, in Android Vitals - Diving into cold start waters 🥶, we concluded that app cold start monitoring should start when ActivityThread.handleBindApplication() is called, because app developers have little influence on the time spent before that.
Pre forking
There's another downside to relying on fork time: the process can be forked long before the application starts specializing in ActivityThread.handleBindApplication(). I measured the time from fork to Application.onCreate() in a production app: while the median time was 350ms, the max was 4 days, and the interval was greater than 1 minute for 0.5% of app starts. This might be due to some systems keeping a pool of pre forked zygotes to accelerate app start.
Bind application time
One of the first things ActivityThread.handleBindApplication() does is call Process.setStartTimes():
public class ActivityThread {
private void handleBindApplication(AppBindData data) {
// Note when this process has started.
Process.setStartTimes(
SystemClock.elapsedRealtime(),
SystemClock.uptimeMillis()
);
...
}
}
The corresponding timestamp is available via Process.getStartUptimeMillis():
Return the SystemClock#uptimeMillis() at which this process was started.
Sounds great, right? Well, it was great, until API 28. I measured the time from bind application to Application.onCreate() in a production app. While the median time was 250ms, on API 28+ the max was 14 hours, and the interval was greater than 1 minute for 0.05% of app starts.
I also found similar issues with the time from class loading of AppComponentFactory to Application.onCreate(): greater than 1 minute for 0.1% of app start on API 28+.
This can't be due to the device sleeping, since we only measure time intervals using SystemClock.uptimeMillis(). I haven't been able to figure out exactly what's going on here, it looks like sometimes bind application starts then halts mid way and the actual app start is much later.
Conclusion
Here's how we can most accurately measure the app start time when monitoring cold start:
- Up to API 24: Use the class load time of a content provider.
- API 24 - API 28: Use Process.getStartUptimeMillis().
- API 28 and beyond: Use Process.getStartUptimeMillis() but filter out weird values (e.g. more than 1 min to get to
Application.onCreate()) and fallback to the timeContentProvider.onCreate()is called.
Top comments (5)
Did you do any analysis using a timestamp from the object initialization of
AppComponentFactoryrather than the static initialization? I'm wondering if there might be something that causes class loading to happen much before the actual application instantiation.Thanks for the series! It's been extremely helpful. Question on the conclusion again. For APIs before 24, if we don't need Context, could we use an earlier time than the class load time of a content provider, e.g. class load of Application?
Content providers are loaded before the Application class. If you leverage the application class then you're likely missing some of the init time.
Speaking of measuring time, is there a way to measure all functions that are being called (especially of various libraries the project uses), till some specific function call, and then look at what could be optimized to make the app-boot better?
You can either use tooling that modifies the bytecode to add timing measurements everywhere, or you can turn capture a profiling trace via the Debug class.