Last week, Chet Haase published a great blog post:Testing App Startup Performance. It leverages the output ofActivityTaskManager to obtain the app startup duration.

Whenever an activity starts, you’ll see something like this in the logcat output:

ActivityTaskManager: Displayedcom.android.samples.mytest/.MainActivity: +1s380ms

This duration (1,380ms in this example) represents the time that it took from launching the app to the time when the system consider it “launched,” which includes drawing the first frame (hence “Displayed”).

This article is a deep dive to explore the question:

What doesActivityTaskManager measure exactly?

I know you're impatient, let's jump to the conclusion:ActivityTaskManager measures the time (uptime on API < 30, realtime on API 30+) from whensystem_process receives an Intent to start an activity to when the window of that activity is done drawing.

Key takeways:

• This measure includes afew hundred milliseconds prior to app code and resources loading, i.e. time that an app developer cannot affect.
• You can measure this without the extra time from within the app, I'll share how at the end.

And now, let's dive into AOSP code!

ActivityTaskManager log

ActivityTaskManager: Displayedcom.android.samples.mytest/.MainActivity: +1s380ms

We know what the log looks like so we can search for it oncs.android.com:

This leads us toActivityTaskManager.logAppDisplayed():

privatevoidlogAppDisplayed(TransitionInfoSnapshotinfo){StringBuildersb=mStringBuilder;sb.setLength(0);sb.append("Displayed ");sb.append(info.launchedActivityShortComponentName);sb.append(": ");TimeUtils.formatDuration(info.windowsDrawnDelayMs,sb);Log.i(TAG,sb.toString());}

The startup duration isTransitionInfoSnapshot.windowsDrawnDelayMs. It's calculated inTransitionInfoSnapshot.notifyWindowsDrawn():

TransitionInfoSnapshotnotifyWindowsDrawn(ActivityRecordr,longtimestampNs){TransitionInfoinfo=getActiveTransitionInfo(r);info.mWindowsDrawnDelayMs=info.calculateDelay(timestampNs);returnnewTransitionInfoSnapshot(info);}privatestaticfinalclassTransitionInfo{intcalculateDelay(longtimestampNs){longdelayNanos=timestampNs-mTransitionStartTimeNs;return(int)TimeUnit.NANOSECONDS.toMillis(delayNanos);}}

Let's find wheretimestampNs andmTransitionStartTimeNs are captured.

ActivityMetricsLogger.notifyActivityLaunching() captures the start of the activity transition:

privateLaunchingStatenotifyActivityLaunching(Intentintent,ActivityRecordcaller,intcallingUid){longtransitionStartNs=SystemClock.elapsedRealtimeNanos();LaunchingStatelaunchingState=newLaunchingState();launchingState.mCurrentTransitionStartTimeNs=transitionStartNs;returnlaunchingState;}

TransitionInfoSnapshot.notifyWindowsDrawn() is called byActivityRecord.onWindowsDrawn() which is called byActivityRecord.updateReportedVisibilityLocked():

voidupdateReportedVisibilityLocked(){// ...if(nowDrawn!=reportedDrawn){onWindowsDrawn(nowDrawn,SystemClock.elapsedRealtimeNanos());reportedDrawn=nowDrawn;}// ...}

We now know where the start and end timestamps are captured, but unfortunatelyActivityMetricsLogger.notifyActivityLaunching() andActivityRecord.updateReportedVisibilityLocked() have many call sites, so it's hard to dig further within the AOSP source.

Debuggingsystem_process

I was telling a friend I hit a dead end looking at the Android sources, and he asked me:

Why don't you put a breakpoint?

Duh. I have never tried to debugsystem_process, but there's no reason we can't. ThanksVincent for the idea! Lucky for us, Android Studio is set up to find sources for the Android version the app is compiled against:

I can put a breakpoint like I would in my app:

Side note: this screenshot showsSystemClock.uptimeMillis() while the code I shared aboved showedSystemClock.elapsedRealtimeNanos(). I'm using an API 29 device, and it turns out that API 29 measured startup time withSystemClock.uptimeMillis(), and API 30 measures it withSystemClock.elapsedRealtimeNanos().

Using a rooted device, I can connect a debugger tosystem_process:

When I start my app, I hit a breakpoint forActivityMetricsLogger.notifyActivityLaunching():

and another breakpoint forTransitionInfoSnapshot.notifyWindowsDrawn():

Reading the stacktraces

• The first stacktrace shows that the start timestamp is captured whensystem_process receives an Intent to start an activity.
• The second stacktrace shows that the end timestamp is captured when the window of that activity is done drawing. The corresponding frame should be visible on the display within 16 ms.

App startup time

InAndroid Vitals - Diving into cold start waters 🥶, I explored what happens on app startup and concluded:

The user experience of launching an activity starts when the user touches the screen, however app developers have little influence on the time spent beforeActivityThread.handleBindApplication(), so that's where app cold start monitoring should start.

ActivityThread.handleBindApplication() loads the APK and the app components (AppComponentFactory,ContentProvider,Application). Unfortunately,ActivityTaskManager usesActivityTaskManagerService.startActivity() as start time, which happens some time beforeActivityThread.handleBindApplication().

How much time isActivityTaskManager adding?

InAndroid Vitals - When did my app start? ⏱, I showed that we can useProcess.getStartUptimeMillis() to get the timestamp at whichActivityThread.handleBindApplication() was called. I also shared a code snippet to read the process fork time (seeProcesses.readProcessForkRealtimeMillis()). We can logs these 2 values to logcat:

valforkRealtime=Processes.readProcessForkRealtimeMillis()valnowRealtimeMs=SystemClock.elapsedRealtime()valnowUptimeMs=SystemClock.uptimeMillis()valelapsedRealtimeMs=nowRealtimeMs-forkRealtimevalforkUptimeMs=nowUptimeMs-elapsedRealtimeMsLog.d("AppStart","$forkUptimeMs fork timestamp")valprocessStart=Process.getStartUptimeMillis()Log.d("AppStart","$processStart bindApplication() timestamp")

We also need to logActivityMetricsLogger.mCurrentTransitionStartTime. We can make our previoussystem_process breakpointnon-suspending and have it log the value. The output ofEvaluate and log goes to the debugger console. We want all logs in logcat so we're invokingLog.d() from there:

Results

D/AppStart: 27464211 Intent receivedD/AppStart: 27464340 fork timestampD/AppStart: 27464533 bindApplication() timestamp...I/ActivityTaskManager: Displayedcom.example.logstartup/.MainActivity: +1s185ms

That's 129 ms from receiving the intent to forking the zygote process, and 193 ms from forking toActivityThread.handleBindApplication(), i.e. 322 ms before the app starts loading its code and resources. In this example, that's ~30% of the app startup time reported byActivityTaskManager.

The real number is lower than that, sincesystem_process was running with a debugger connected. Still, it's significant enough that you should have this extra penalty in mind when measuring app startup withActivityTaskManager.

Measuring app startup time from within the app

InAndroid Vitals - First draw time 👩‍🎨 I showed how to determine the first draw time. I compared that timestamp with the timestamp passed toTransitionInfoSnapshot.notifyWindowsDrawn(), and the two values are only a few milliseconds apart.

We can put together what we've learnt to measure the app startup duration from within the app:

classMyApp:Application(){overridefunonCreate(){super.onCreate()varfirstDraw=falsevalhandler=Handler()registerActivityLifecycleCallbacks(object:ActivityLifecycleCallbacks{overridefunonActivityCreated(activity:Activity,savedInstanceState:Bundle?){if(firstDraw)returnvalname=activity::class.java.simpleNamevalwindow=activity.windowwindow.onDecorViewReady{window.decorView.onNextDraw{if(firstDraw)return@onNextDrawfirstDraw=truehandler.postAtFrontOfQueue{valstart=Process.getStartUptimeMillis()valnow=SystemClock.uptimeMillis()valstartDurationMs=now-startLog.d("AppStart","Displayed $name in $startDurationMs ms")}}}}})}}

D/AppStart: Displayed MainActivity in 863 ms

Conclusion

• The output fromActivityTaskManager is convenient, and totally worth using if you're trying to compare startup time for different versions of your app. Just be aware that there's a non-trivial portion of that time that app developers cannot affect.
• You can measure app startup time from within the app. I intend to eventually publish that code as an open source library, in the meantime the details are inAndroid Vitals - First draw time 👩‍🎨.

Header image:Deep Diveby Romain Guy.