Android：如何跟踪第一个Activity界面绘制完成前的时间开销状况及优化方案

在Android中，以最典型的应用启动为例，从Launcher点击应用图标到第一个Activity加载完成，系统开放给开发者的接口及类包括：Application生命周期相关的方法：onCreate、启动Activity的onCreate、onStart、onResume。对于启动Activity的三个方法的执行时间，没什么疑问，如果定义的复杂，有复杂运行，则运行时间长，定义的简单，则运行的时间短，优化非常简洁明了，在此不再说明。重点是Application的onCreate到Activity的onCreate这段时间系统在干什么，如果对其时间片不能做到精确把握，则应用的首次启动时间处于不可控状态，作为一个有要求的程序员，这个是不可接受的。

说完原因，进入正题，怎么才能获知上面所说的时间开销呢？也许有些同学已经想到了：系统log，没错，我们来分析下怎么看系统log（注意不是应用所属进程的log，而是全部的log），对系统log及AMS相当了解的同学可以关闭本文了。

第一步：杀掉进程

一定要注意确保进程被杀死，而不是返回键退出应用

第二步：抓取log

这个也需要说吗？我认为是需要的，如果只是普通的“adb logcat > 文件名”获取到的log里面掺杂着过往的信息，分析起来干扰性太强，而又缺少了一些必要的信息，比如：时间、线程Id。

运行如下命令：

adb logcat -c -b main 

adb logcat -c -b events

adb logcat -c -b system

adb logcat -c -b radio

Android应用的log存放于四个缓存区中，执行上述命令将四个缓存区的log全部清除，排除以往log的干扰

然后开启抓log命令：adb logcat -v threadtime > 路径/文件名

threadtime非常重要，分析过程中我们需要用到线程Id判断是否是主线程、需要时间来判断每一步的时间开销是什么。下面看到的是我抓取的一个log文件：

注：进程id == 线程id 表示该线程为该进程的主线程

第三步：开启应用，然后获取到应用的进程id：adb shell ps | grep 应用包名

我测试的进程id为30311

第四步：搜索log中的进程id有关的文本，推荐使用UE进行log查看及搜索，可以看到所有的搜索获得项，下图为我的搜索结果：

第五步：也是最关键的一步，分析该log及搜索项，有几个原则：

a.所有标注为进程id的log全部都是待优化的app的逻辑行为，也是可以优化的项

b.通过查看log，分析时间差，可以看到与log有关的逻辑的时间开锁，某个逻辑如果低于5ms的时间开销则不用关注，没有优化的必要

c.app进程id之间可以间隔着其他进程（假设为B进程）的log，如果超过5ms，需要查看下B进程是什么进程，在做什么事情，通过进程Id追溯进程的命令为：adb shell ps | grep 进程id

d.有几个里程碑时间点：1.Application的onCreate进入时间t1，2.首个Activity的onCreate进入时间t2，t1<t<t2，t时间段内的log是可以优化的log，小于t1的没必要关注，是系统的调度，app是没法介入的，大于t2的时间归属于Activity自身的优化。

e.在我们的项目中，为防止Application的主线程加载时间长导致ANR，部分逻辑放入工作线程中，要关注工作线程的工作时间，是否占用我们的待优化时间段。

根据上面的原则，我们来分析一下log，时间较长，看几个关键之处吧，先找第一个时间点，Application的onCreate时间点：

上图所指的位置第509行与513行即为该分界点，为啥不是onCreate呢，没办法，那个地方没有日志点。在此处还发现另一个现象，在第513行，开了一个新线程，线程id为30328。我优化的应用中，线程的开启在Application的onCreate刚刚启用的位置，因此，线程的创建是最早执行的，但居然线程内逻辑的执行也要先于主线程逻辑，工作线程优先于主线程抢到了cpu的控制权，这个是我没想到的。因此，第一个结论是，开启工作线程，只是不导致ANR，提升首个Activity的启动时间难以做到。

第861行是主线程第一次出现，时间过去了不到100ms，这个时间一直是工作线程占着。

上面滑动log文件，发现大片的30311进程的log，而基本没有别的进程啥事（是基本没有，还是有一点的，下面细说），可见此处的时间开销的确是我们的app占着，首个Acitivity启动，和别的应用没任何关系，不要猜想是不是因为别的应用抢去了CPU，导致加载慢的。

看一个有别的进程日志的例子，说一下怎么分析：

上面看，有一些3717的进程log，当然时间并不长，只有2ms，从优化的角度看，不需要分析的，但我们希望了解下它是谁在干吗呢？

通过上述命令看到3717是system_server进程，熟悉Android系统原理的同学应该会知道这个进程，是在系统启动时就启动了，装载着部分的基本服务，比如ActivityManagerService服务，从上面的日志可以看出，是在做我们进程的权限鉴定工作，触发时机也在我们的app里。

再来看一下下面这个log:

此处有57-566=6ms的开销，是在取android_id，也就是说我们要获得android_id信息，就要付出这6ms的系统处理时间。

以上基本说到了log分析的多种情况，具体场景下的具体分析关心的同学仔细琢磨就能明白。

第六步：制定优化方案

a.Application最理想的状态是啥都不做，最快，当然这是不可能的，所以，只有必须要放在此处的加载，才放在此处，一定是必须，放别的地方都不成。

b.既然开启工作线程并不能降低时间开销，那就要考虑耗时操作是否可以延时加载，放到首个Activity的onResume之后

c.万能的懒加载：用了懒加载，要多写代码，系统性能好，分散了系统负载，不用懒加载，说明开发者懒

d.从log中获得的时间开销是否必要，比如说硬件信息，网络监听等，没必要的要去掉