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

news2024/10/2 12:28:05

文章基于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;
        }
    }