Android Activity启动耗时统计方案

Android Activity启动耗时统计方案

---

作者：普惠产品技术

Activity的启动速度是很多开发者关心的问题，当页面跳转耗时过长时，App就会给人一种非常笨重的感觉。在遇到某个页面启动过慢的时候，开发的第一直觉一般是onCreate执行速度太慢了，然后在onCreate方法前后记录下时间戳计算出耗时。不过有时候即使把onCreate方法的耗时优化了，效果仍旧不明显。实际上影响到Activity启动速度的原因是多方面的，需要从Activity的启动流程入手，才能找到真正问题所在。

Activity启动流程

如果要给Activity的“启动”做一个定义的话，个人觉得应该是：从调用startActivity到
Activity可被操作为止，代表启动成功。所谓的可被操作，是指可接受各种输入事件，比如手势、键盘输入之类的。换个角度来说，也可以看成是主线程处于空闲状态，能执行后续进入的各种Message。

Activity的启动可以分为三个步骤，以ActivityA启动ActivityB为例，三步骤分别为：

1. 以ActivityA调用startActivity，到ActivityA成功pause为止
2. ActivityB成功初始化，到执行完resume为止
3. ActivityB向WSM注册窗口，到第一帧绘制完成为止

Activity启动涉及到App进程与ActivityManagerService（AMS）、WindowManagerService（WMS）的通信，网上关于这个流程的文章很多，这边就不再具体描述了，只列一下关键方法的调用链路。

ActiivtyA Pause流程

当ActivityA使用startActivity方法启动ActivityB时，执行函数链路如下

ActivityA.startActivity->
Instrumentation.execStartActivity->
ActivityManagerNative.getDefault.startActivity->
ActivityManagerService.startActivityAsUser->
ActivityStarter.startActivityMayWait->
ActivityStarter.startActivityLocked->
ActivityStarter.startActivityUnchecked->
ActivityStackSupervisor.resumeFocusedStackTopActivityLocked->
ActivityStack.resumeTopActivityUncheckedLocked->
ActivityStack.resumeTopActivityInnerLocked->
ActivityStack.startPausingLocked->
ActivityThread$$ApplicationThread.schedulePauseActivity->
ActivityThread.handlePauseActivity->
 └ActivityA.onPause
ActivityManagerNative.getDefault().activityPaused

当App请求AMS要启动一个新页面的时候，AMS首先会pause掉当前正在显示的Activity，当然，这个Activity可能与请求要开启的Activity不在一个进程，比如点击桌面图标启动App,当前要暂停的Activity就是桌面程序Launcher。在onPause内执行耗时操作是一种很不推荐的做法，从上述调用链路可以看出，如果在onPause内执行了耗时操作，会直接影响到ActivityManagerNative.getDefault().activityPaused()方法的执行，而这个方法的作用就是通知AMS，“当前Activity已经已经成功暂停，可以启动新Activity了”。

ActivityB Launch流程

在AMS接收到App进程对于activityPaused方法的调用后，执行函数链路如下

ActivityManagerService.activityPaused->
ActivityStack.activityPausedLocked->
ActivityStack.completePauseLocked->
ActivityStackSupervisor.resumeFocusedStackTopActivityLocked->
ActivityStackSupervisor.resumeFocusedStackTopActivityLocked->
ActivityStack.resumeTopActivityUncheckedLocked->
ActivityStack.resumeTopActivityInnerLocked->
ActivityStackSupervisor.startSpecificActivityLocked->
 └1.启动新进程：ActivityManagerService.startProcessLocked 暂不展开
 └2.当前进程：ActivityStackSupervisor.realStartActivityLocked->
ActivityThread$$ApplicationThread.scheduleLaunchActivity->
Activity.handleLaunchActivity->
 └Activity.onCreate
 └Activity.onRestoreInstanceState
 └handleResumeActivity
   └Activity.onStart->
   └Activity.onResume->
   └WindowManager.addView->

AMS在经过一系列方法调用后，通知App进程正式启动一个Actviity，注意如果要启动Activity所在进程不存在，比如点击桌面图标第一次打开应用，或者App本身就是多进程的，要启动的新页面处于另外一个进程，那就需要走到ActivityManagerService.startProcessLocked流程，等新进程启动完毕后再通知AMS，这里不展开。按照正常流程，会依次走过Activity生命周期内的onCreate、onRestoreInstanceState、onStart、onResume方法，这一步的耗时基本也可以看成就是这四个方法的耗时，由于这四个方法是同步调用的，所以可以通过以onCreate方法为起点，onResume方法为终点，统计出这一步骤的总耗时。

ActivityB Render流程

在ActivityB执行完onResume方法后，就可以显示该Activity了，调用流程如下

WindowManager.addView->
WindowManagerImpl.addView->
ViewRootImpl.setView->
ViewRootImpl.requestLayout->
 └ViewRootImpl.scheduleTraversals->
 └Choreographer.postCallback->
WindowManagerSerivce.add

这一步的核心实际上是Choreographer.postCallback，向Choreographer注册了一个回调，当Vsync事件到来时，就会执行下面的回调进行ui的渲染

ViewRootImpl.doTraversal->
ViewRootImpl.performTraversals->
 └ViewRootImpl.relayoutWindow
 └ViewRootImpl.performMeasure
 └ViewRootImpl.performLayout
 └ViewRootImpl.performDraw
ViewRootImpl.reportDrawFinished

这里分别执行了performMeasure、performLayout、performDraw，实际上就是对应到DecorView的测量、布局、绘制三个流程。由于Android的UI是个树状结构，作为根View的DecorView的测量、布局、绘制，会调用到所有子View相应的方法，因此，这一步的总耗时就是所有子View在测量、布局、绘制中的耗时之和，如果某个子View在这三个方法中如果进行了耗时操作，就会拖慢整个UI的渲染，进而影响Activity第一帧的渲染速度。

耗时统计方案

知道了Actviity启动流程的三个步骤和对应的方法耗时统计方法，那该如何设计一个统计方案呢？在这之前，可以先看看系统提供的耗时统计方法。

系统耗时统计

打开Android Studio的Logcat,输入过滤关键字ActivityManager,在启动一个Actviity后就能看到如下日志

末尾的+59ms便是启动该Activity的耗时。这个日志是Android系统在AMS端直接输出的，《WMS常见问题一（Activity displayed延迟）》这篇文章分析了系统耗时统计的方法，简单来说，上述日志是通过ActivityRecord.reportLaunchTimeLocked方法打印出来的

    ActivityRecord.java
   
    private void reportLaunchTimeLocked(final long curTime) {
   
        ......
        final long thisTime = curTime - displayStartTime;
        final long totalTime = stack.mLaunchStartTime != 0
                ? (curTime - stack.mLaunchStartTime) : thisTime;
        if (SHOW_ACTIVITY_START_TIME) {
   
            Trace.asyncTraceEnd(TRACE_TAG_ACTIVITY_MANAGER, "launching: " + packageName, 0);
            EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
                    userId, System.identityHashCode(this), shortComponentName,
                    thisTime, totalTime);
            StringBuilder sb = service.mStringBuilder;
            sb.setLength(0);
            sb.append("Displayed ");
            sb.append(shortComponentName);
            sb.append(": ");
            TimeUtils.formatDuration(thisTime, sb);
            if (thisTime != totalTime) {
   
                sb.append(" (total ");
                TimeUtils.formatDuration(totalTime, sb);
                sb.append(")");
            }
            Log.i(TAG, sb