Android(安卓)App 启动过程分析
16lz
2021-01-26
原文链接：http://harttle.com/2014/05/27/android-appstartup.html
通过分析和修改Android 源码,分析 Android App 启动过程的时间消耗及性能瓶颈。
本文包括源码编译与运行、源码修改与调试、数据收集与分析。分析了 App 启动过程中， Activity Manager Service 、Binder、Launcher和MainActivity扮演的角色以及消耗的时间。
源码编译与运行
环境配置
环境要求可以在从 文档 查询得到。以下在Arch Linux中进行Android Source Building的环境配置。
安装依赖
# x86yaourt -S --needed gcc git gnupg flex bison gperf sdl wxgtk squashfs-tools curl ncurses zlib schedtool perl-switch zip unzip libxslt# x64yaourt -S --needed gcc-multilib lib32-zlib lib32-ncurses lib32-readline# Android 工具yaourt -S android-sdk android-sdk-platform-tools android-sdk-build-tools android-studio增加交换空间，加 RAM 应达到 16G (另外，还需要 30G 的大小写敏感文件系统可用空间)
suswapoff /swapfile && rm /swapfiledd if=/dev/zero of=/swapfile bs=512M count=8mkswap /swapfile && swapon /swapfile环境降级
# make 3.81-3.82yaourt -S make-3.81 # python2cd /usr/bin && sudo ln -sf python python2# java SE 1.6yaourt -S jdk6-compat环境配置
#!/bin/bash# file: env.sh# cacheexport USE_CCACHE=1export CCACHE_DIR=~/.ccache# outputexport OUT_DIR_COMMON_BASE=~/code/androidcore/output# aliasalias make='make-3.81'# java6export JAVA_HOME=/opt/java6export PATH=/opt/java6/bin:$PATH配置USB访问权限：
# file: /etc/udev/rules.d/51-android.rules# adb protocol on passion (Nexus One)SUBSYSTEM=="usb", ATTR{idVendor}=="18d1", ATTR{idProduct}=="4e12", MODE="0600", OWNER="<username>"# fastboot protocol on passion (Nexus One)SUBSYSTEM=="usb", ATTR{idVendor}=="0bb4", ATTR{idProduct}=="0fff", MODE="0600", OWNER="<username>"# ...最终环境
Linux acer 3.13.7-1-ARCH #1 SMP PREEMPT Mon Mar 24 20:06:08 CET 2014 x86_64 GNU/LinuxPython 2.7.6 (default, Feb 26 2014, 12:07:17)gcc 版本 4.9.0 20140507 (prerelease) (GCC)GNU Make 3.81java SE 1.6编译Android Source
参照 文档 ，下载Android4.2源码。
# 导入环境. ../env.sh. build/envsetup.sh# 设置缓存大小prebuilts/misc/linux-x86/ccache/ccache -M 50G# 选择目标lunch# 并行编译make -j4启动Emulator
# 加载环境lunch # 启动emulator启动成功，Android版本为4.2.1：
源码修改与调试
考虑从Launcher启动应用程序时，ActivityManagerService，Launcher，MainActivity之间的执行与通信序列如下图。在源码中相应的过程调用或进程通信处加入日志信息，用于分析启动时各部分的耗时。
Android源码修改
以下列出所有需要更改的源码。注释中给出了文件路径、类名、函数名，与添加的语句。添加日志输出（Level为Info，Tag为”PKU”）。
说明：文件ApplicationThreadNative没有引入Log类。添加import andriod.util.Log会发生运行时错误，可能是因为该文件的在类层次中的特殊性。所以我们将在try catch语句中指明命名空间并进行调用。我们关心的是整个系统启动后的 App启动过程，所以直接吞掉这个在早期才会产生的异常。
/////////////////////////////////////////////////////////////////////////// file: packages/apps/Launcher2/src/com/android/launcher2/Launcher.java// 0 Launcher.onClickLog.i("PKU", "0 shortcut clicked");/////////////////////////////////////////////////////////////////////////// file: frameworks/base/core/java/android/app/ActivityManagerNative.java// 1 ActivityManagerProxy.startActivity Log.i("PKU","1 START_ACTIVITY_TRANSACTION begin");Log.i("PKU","1 START_ACTIVITY_TRANSACTION end");// 5 ActivityManagerProxy.activityPausedLog.i("PKU","5 ACTIVITY_PAUSED_TRANSACTION begin");Log.i("PKU","5 ACTIVITY_PAUSED_TRANSACTION end");// 9 ActivityManagerProxy.attachApplicationLog.i("PKU","9 ATTACH_APPLICATION_TRANSACTION begin");Log.i("PKU","9 ATTACH_APPLICATION_TRANSACTION end");/////////////////////////////////////////////////////////////////////////// file: frameworks/base/services/java/com/android/server/am/ActivityManagerService.java// 2 ActivityManagerService.startActivityLog.i("PKU","2 on START_ACTIVITY_TRANSACTION");// 6 ActivityManagerService.activityPausedLog.i("PKU","6 on ACTIVITY_PAUSED_TRANSACTION");// 7 ActivityManagerService.startProcessLockedLog.i("PKU","7 process starting");Log.i("PKU","7 process started");// 10 ActivityManagerService.attachApplicationLog.i("PKU","10 on ATTACH_APPLICATION_TRANSACTION");/////////////////////////////////////////////////////////////////////////// file: frameworks/base/core/java/android/app/ApplicationThreadNative.java// 3 ApplicationThreadProxy.schedulePauseActivitytry{ android.util.Log.i("PKU","3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin");}catch(Exception e){}try{ android.util.Log.i("PKU","3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end");}catch(Exception e){}// 11 ApplicationThreadProxy.scheduleLaunchActivitytry{ android.util.Log.i("PKU","11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin");}catch(Exception e){}try{ android.util.Log.i("PKU","11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end");}catch(Exception e){}/////////////////////////////////////////////////////////////////////////// file: frameworks/base/core/java/android/app/ActivityThread.java// 4 ApplicationThread.schedulePauseActivity Log.i("PKU","4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION");// 8 ActivityThread.mainLog.i("PKU","8 main entered");// 12 ApplicationThread.scheduleLaunchActivityLog.i("PKU","12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION");App源码修改
/////////////////////////////////////////////////////////////////////////// file: src/com/example/android/searchabledict/SearchableDictionary.javaimport android.util.Log;// SearchableDictionary.onCreateLog.i("PKU", "searchabledictionary oncreate");// SearchableDictionary.handleIntentLog.i("PKU", "item clicked");/////////////////////////////////////////////////////////////////////////// file: src/com/example/android/searchabledict/SearchableDictionary.javaimport android.util.Log;// WordActivity.onCreateLog.i("PKU", "wordactivity oncreate");重新编译
重新编译Android Source
. ../env.sh. build/envsetup.shprebuilts/misc/linux-x86/ccache/ccache -M 50Glunchmake -j4运行模拟器
emulator&安装测试应用：SearchableDictionary
# 拷贝Samplecp -r /opt/android-sdk/samples/android-19/legacy/SearchableDictionary/ .# 创建Projectandroid update project -t 1 -n searchabledict -p ./SearchableDictionary# 编译cd SearchableDictionary && ant debug# 查看正在运行的设备adb devices# 安装到指定设备adb -s emulator-5554 install bin/searchabledict-debug.apk安装后在应用程序列表中出现SearchableDictionary：
数据采集与分析
数据采集
首先运行模拟器，在设置中更改 “background process limit” 为0，勾选”don’t keep activities”。这样每次点击Home即可结束应用进程。
然后监视日志并重定向到文件：
# 清空日志adb -s emulator-5554 logcat -c# 开始过滤adb -s emulator-5554 logcat -v time PKU:I *:S | tee pku.log现在，我们来获得10组启动过程的日志数据：
- 启动SearchableDictionary；
- 点击搜索，随机搜索一个单词并打开；
- 点击Home按键（因为我们只关心启动过程）；
- 重复1-3；
- 结束
logcat，得到pku.log，文件46行为一个周期，10次测试共460行，前46行如下：
1 06-01 05:08:57.111 I/PKU ( 399): 0 shortcut clicked 2 06-01 05:08:57.111 I/PKU ( 399): 1 START_ACTIVITY_TRANSACTION begin 3 06-01 05:08:57.121 I/PKU ( 276): 2 on START_ACTIVITY_TRANSACTION 4 06-01 05:08:57.151 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin 5 06-01 05:08:57.151 I/PKU ( 399): 4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION 6 06-01 05:08:57.151 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end 7 06-01 05:08:57.171 I/PKU ( 399): 1 START_ACTIVITY_TRANSACTION end 8 06-01 05:08:57.171 I/PKU ( 399): 5 ACTIVITY_PAUSED_TRANSACTION begin 9 06-01 05:08:57.171 I/PKU ( 276): 6 on ACTIVITY_PAUSED_TRANSACTION 10 06-01 05:08:57.171 I/PKU ( 276): 7 process starting 11 06-01 05:08:57.191 I/PKU ( 276): 7 process started 12 06-01 05:08:57.211 I/PKU ( 399): 5 ACTIVITY_PAUSED_TRANSACTION end 13 06-01 05:08:57.361 I/PKU ( 1005): 8 main entered 14 06-01 05:08:57.371 I/PKU ( 1005): 9 ATTACH_APPLICATION_TRANSACTION begin 15 06-01 05:08:57.371 I/PKU ( 276): 10 on ATTACH_APPLICATION_TRANSACTION 16 06-01 05:08:57.391 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin 17 06-01 05:08:57.391 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end 18 06-01 05:08:57.391 I/PKU ( 1005): 12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION 19 06-01 05:08:57.461 I/PKU ( 1005): 9 ATTACH_APPLICATION_TRANSACTION end 20 06-01 05:08:57.711 I/PKU ( 1005): searchabledictionary oncreate 21 06-01 05:09:03.791 I/PKU ( 1005): 1 START_ACTIVITY_TRANSACTION begin 22 06-01 05:09:03.801 I/PKU ( 276): 2 on START_ACTIVITY_TRANSACTION 23 06-01 05:09:03.812 I/PKU ( 1005): 1 START_ACTIVITY_TRANSACTION end 24 06-01 05:09:03.981 I/PKU ( 1005): item clicked 25 06-01 05:09:03.981 I/PKU ( 1005): 1 START_ACTIVITY_TRANSACTION begin 26 06-01 05:09:04.001 I/PKU ( 276): 2 on START_ACTIVITY_TRANSACTION 27 06-01 05:09:04.001 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin 28 06-01 05:09:04.001 I/PKU ( 1005): 4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION 29 06-01 05:09:04.001 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end 30 06-01 05:09:04.011 I/PKU ( 1005): 1 START_ACTIVITY_TRANSACTION end 31 06-01 05:09:04.041 I/PKU ( 1005): 5 ACTIVITY_PAUSED_TRANSACTION begin 32 06-01 05:09:04.041 I/PKU ( 276): 6 on ACTIVITY_PAUSED_TRANSACTION 33 06-01 05:09:04.051 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin 34 06-01 05:09:04.051 I/PKU ( 1005): 12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION 35 06-01 05:09:04.051 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end 36 06-01 05:09:04.091 I/PKU ( 1005): 5 ACTIVITY_PAUSED_TRANSACTION end 37 06-01 05:09:04.171 I/PKU ( 1005): wordactivity oncreate 38 06-01 05:09:09.201 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin 39 06-01 05:09:09.201 I/PKU ( 1005): 4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION 40 06-01 05:09:09.211 I/PKU ( 1005): 5 ACTIVITY_PAUSED_TRANSACTION begin 41 06-01 05:09:09.211 I/PKU ( 276): 6 on ACTIVITY_PAUSED_TRANSACTION 42 06-01 05:09:09.211 I/PKU ( 276): 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end 43 06-01 05:09:09.241 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin 44 06-01 05:09:09.251 I/PKU ( 399): 12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION 45 06-01 05:09:09.251 I/PKU ( 276): 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end 46 06-01 05:09:09.311 I/PKU ( 1005): 5 ACTIVITY_PAUSED_TRANSACTION end- 1-20行：点击Launcher图标（Launcher.onClick）到Activity启动完毕（SearchableDictionary.onCreate）；
- 21-23行：点击搜索提示列表中的某一项到生成隐式Intent；
- 24-37行：调用StartActivity（SearchableDictionary.handleIntent）到WordActivity启动完毕（WordActivity.onCreate）；
- 38-46行：点击Home键直到应用程序进程结束（这一段不在我们关心的范围内）。
可以看到到
begin与end之间总会有on，即transaction类似远程过程调用，该过程是同步的。
数据分析
利用脚本pku_analyzer.sh，计算日志文件pku.log相邻事件之间的时间差，最终结果(即 10 次测试的平均值)记录在r.txt文件:
# Actor Time Event 1 0 0 shortcut clicked 2 L 0 1 START_ACTIVITY_TRANSACTION begin 3 B 5 2 on START_ACTIVITY_TRANSACTION 4 A 23 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin 5 B 1 4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION 6 L 2.9 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end 7 A 30.1 1 START_ACTIVITY_TRANSACTION end 8 L 6.9 5 ACTIVITY_PAUSED_TRANSACTION begin 9 B 1 6 on ACTIVITY_PAUSED_TRANSACTION 10 A 2 7 process starting 11 B 25.9 7 process started 12 AM 11.1 5 ACTIVITY_PAUSED_TRANSACTION end 13 M 214.9 8 main entered 14 M 22 9 ATTACH_APPLICATION_TRANSACTION begin 15 B 0 10 on ATTACH_APPLICATION_TRANSACTION 16 A 19 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin 17 B 1 12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION 18 M 2 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end 19 A 75.9 9 ATTACH_APPLICATION_TRANSACTION end 20 M 232.6 searchabledictionary oncreate 24 161 item clicked 25 L 5 1 START_ACTIVITY_TRANSACTION begin 26 B 15.9 2 on START_ACTIVITY_TRANSACTION 27 A 6 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin 28 B 0 4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION 29 L 2 3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end 30 A 15 1 START_ACTIVITY_TRANSACTION end 31 L 34 5 ACTIVITY_PAUSED_TRANSACTION begin 32 B 1 6 on ACTIVITY_PAUSED_TRANSACTION 33 A 6 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin 34 B 2 12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION 35 M 3 11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end 36 A 36.9 5 ACTIVITY_PAUSED_TRANSACTION end 37 M 58.8 wordactivity oncreate说明:
- Time 为当前事件与上一事件的间隔,Actor 为消耗这段时间的主体。A:
AMS;B:Binder;L:Launcher;M:MainActivity。 - 方便起见，请求启动子Activity的对象同样被标记为
Launcher。 Process.start的执行时间归于Binder，而该函数返回直到ActivityThread.main的时间归于MainActivity。- 在
Process.start后AMS与MainActivity并发执行,时间为 11.1ms，为便于统计这段重合时间归于AMS。 - 脚本完成了绝大部分计算，仍有部分是手工计算的(这些结果包括行 1-2、行 19-20、行 36-37 之间的间隔)。
- 相同时间的 Log 可能会出现乱序(Log 并非原子操作,但时间的正确的)，最终结果对这种情况进行了手工纠正。
对这四个主体消耗的时间进行加和,可得到如下时间分布图:
图1：主Activity 启动时间分布(合计:674.3ms)
图2：子Activity 启动时间分布(合计:185.6ms)
由图1可以看出，主Activity 启动过程中，主要的性能瓶颈由 MainActivity 的创建和切换产生，Binder 消费的时间非常少。
在图2中，各部分消费时间相差较小,以AMS和MainActivity耗时为主,Binder所占时间仍是最少的。
在图2中，子Activity启动时间相对主Activity来讲已经大大减少。此外,这个过程的时间波动可能与子Activity 的具体类型高度相关。
在图2中，Launcher的时间有所增加。注意这里的Launcher是发出启动子Activity请求的对象,即主Activity。这说明系统的Launcher程序是有所优化的(响应时间减少了76.1%)。
综上，
Binder机制是一种高效的进程间通信机制。它在提供高可靠性和扩展性的同时，并未引入过多的时间开销。AMS提供将Activity与进程分离的机制,其时间也小于MainActivity本身,这样的开销是值得的。- 系统的
Launcher启动Activity的速度要高于普通的主Activity。
更多相关文章
- android实现双击事件监听
- android 源代码 debug
- Android(安卓)EventBus3.1.1从使用到源码解析
- Android(安卓)源码
- Android打开其它APP的两种方式
- Android(安卓)Studio 关联源码配置方法
- [Android]Activity生命周期+启动模式
- android 获得一个应用程序的启动次数，运行时间等信息
- Android中ComponentName的简单运用