【Android】页面启动耗时统计流程梳理

文章基于Android 11

写在前面：
最近的文章都会放流程图，时序图之类的图片，解释下为什么这么做：
图片的好处：

流程清晰，一目了然
很多代码，如同老太太的裹脚布，又臭又长。影响理解，特别当想和别人解释清除一件事时，大量的代码，会搞得大家没耐心。

所以，如果只是浅尝辄止，只要看图即可得到你想要的结论。如果想深入了解，则跟着图片，对照源码梳理一遍流程。因此这篇文章，如果你有自己阅读源码的方式，理解完第一张图，后续的也就不用看了。后面的文章是给想学源码，却不知道怎么学的人，也是我看源码的个人习惯。

正文开始

本文重点

弄清楚Android是如何统计页面启动耗时的
这个时间是如何算出来的

查看Android的日志可以发现这样一条日志

2024-09-25 10:50:20.944 1292-1350 ActivityTaskManager system_process I Displayed xxx包名/.MainActivity: +966ms

那么我们要统计计时，其实只要弄清楚这个日志的时间怎么计算出来的。跟踪源码，全局搜索Displayed发现

ActivityMetricsLogger#logAppDisplayed

    private void logAppDisplayed(TransitionInfoSnapshot info) {if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {return;}EventLog.writeEvent(WM_ACTIVITY_LAUNCH_TIME,info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,info.windowsDrawnDelayMs);StringBuilder sb = mStringBuilder;sb.setLength(0);sb.append("Displayed ");sb.append(info.launchedActivityShortComponentName);sb.append(": ");TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);Log.i(TAG, sb.toString());}

可以看到重点就是这个时间info.windowsDrawnDelayMs，那么这个数据是怎么来的呢？直接上图（如果看不清楚，下载下来看）：

在这里插入图片描述

下面是代码分析：整个过程属实无聊。是我自己看源码的一个方法，如果你有自己看源码的方式，后续不看也罢。
as右键find Usages（后续所有的只有一个来源都是这么得到的结论）
TransitionInfoSnapshot#windowsDrawnDelayMs数据的来源只有一个

		private TransitionInfoSnapshot(TransitionInfo info, ActivityRecord launchedActivity,int windowsFullyDrawnDelayMs) {//......windowsDrawnDelayMs = info.mWindowsDrawnDelayMs;//......}

ActivityMetricsLogger#mWindowsDrawnDelayMs

		/** Elapsed time from when we launch an activity to when its windows are drawn. *///直译：从启动 Activity 到绘制其窗口所经过的时间。int mWindowsDrawnDelayMs;

查看这个值的写入只有一个地方

ActivityMetricsLogger#notifyWindowsDrawn

    /*** Notifies the tracker that all windows of the app have been drawn.** @return Non-null info if the activity was pending to draw, otherwise it might have been set*         to invisible (removed from active transition) or it was already drawn.*/TransitionInfoSnapshot notifyWindowsDrawn(@NonNull ActivityRecord r, long timestampNs) {if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn " + r);final TransitionInfo info = getActiveTransitionInfo(r);if (info == null || info.allDrawn()) {if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn no activity to be drawn");return null;}//这里进行赋值// Always calculate the delay because the caller may need to know the individual drawn time.info.mWindowsDrawnDelayMs = info.calculateDelay(timestampNs);info.removePendingDrawActivity(r);final TransitionInfoSnapshot infoSnapshot = new TransitionInfoSnapshot(info);if (info.mLoggedTransitionStarting && info.allDrawn()) {done(false /* abort */, info, "notifyWindowsDrawn - all windows drawn", timestampNs);}return infoSnapshot;}

TransitionInfo#calculateDelay

int calculateDelay(long timestampNs) {// Shouldn't take more than 25 days to launch an app, so int is fine here.//传入的时间 - 开始过渡的时间return (int) TimeUnit.NANOSECONDS.toMillis(timestampNs - mTransitionStartTimeNs);
}

接下来分两部分

开始过渡的时间什么时候赋值
传入的时间是什么时间

开始过渡的时间写入只有一个来源

        private TransitionInfo(ActivityRecord r, LaunchingState launchingState, int transitionType,boolean processRunning, boolean processSwitch) {mLaunchingState = launchingState;//此处就是赋值的地方mTransitionStartTimeNs = launchingState.mCurrentTransitionStartTimeNs;//......}

查看launchingState.mCurrentTransitionStartTimeNs的赋值

TransitionInfoSnapshot#notifyActivityLaunching

    private LaunchingState notifyActivityLaunching(Intent intent, @Nullable ActivityRecord caller,int callingUid) {final long transitionStartTimeNs = SystemClock.elapsedRealtimeNanos();//......if (existingInfo == null) {// Only notify the observer for a new launching event.launchObserverNotifyIntentStarted(intent, transitionStartTimeNs);final LaunchingState launchingState = new LaunchingState();launchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;return launchingState;}existingInfo.mLaunchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;return existingInfo.mLaunchingState;}

可以看到是在notifyActivityLaunching方法被调用时的SystemClock.elapsedRealtimeNanos()。继续跟踪这个方法被调用的时机

ActivityStarter#startResolvedActivity

ActivityStartController#doPendingActivityLaunches

ActivityStart#executeRequest

到这里熟悉Activity启动流程的基本也就知道开始过渡时间的来源了。不熟悉的我放一张图，大家看下Activity的启动流程，应该也能明白这个时间大概是什么时候。（为了方便看清楚，只截图了一部分，完整图很大，截图放不下。可私聊我获取）

在这里插入图片描述

接下来查看结束时间，即TransitionInfo#calculateDelay传入的时间

再贴一次代码

    TransitionInfoSnapshot notifyWindowsDrawn(@NonNull ActivityRecord r, long timestampNs) {//......// Always calculate the delay because the caller may need to know the individual drawn time.info.mWindowsDrawnDelayMs = info.calculateDelay(timestampNs);//......}

ActivityRecord#onWindowsDrawn

    /** Called when the windows associated app window container are drawn. */void onWindowsDrawn(boolean drawn, long timestampNs) {//......final TransitionInfoSnapshot info = mStackSupervisor.getActivityMetricsLogger().notifyWindowsDrawn(this, timestampNs);//......}

ActivityRecord#updateReportedVisibilityLocked

    void updateReportedVisibilityLocked() {if (nowDrawn != reportedDrawn) {onWindowsDrawn(nowDrawn, SystemClock.elapsedRealtimeNanos());reportedDrawn = nowDrawn;}}