性能优化-Android中如何通过adb start命令和添加Log方式统计APP启动时间

电玩女神 2022-04-14 02:22 483阅读 0赞

### 启动时间 ###

*  前言
 *  启动时间
 *   *  adb start 命令
     *   *  AM.onRun
         *  AM.runStart
         *  时间计算
         *  总结
     *  Log日志
     *  完结

# 前言 #

鉴于最近这段时间在做APP的性能优化方面的工作，其中一个小项是需要提高APP的启动速度，最好做到秒开的地步；做这个的时候需要经常去观察和统计APP启动到底需要多长时间，所以本篇文章就记录下这方面的经历，也希望能给后来者一些帮助

**本文所含代码随时更新，可从这里下载最新代码**  
[传送门][Link 1]

# 启动时间 #

说到启动时间我们需要重新理一下应用启动时间到底怎么定义？或者说站在谁的角度定义？

APP是做给用户使用的，一切的优化都是为了给用户更好的体验，所以应该站在用户的角度来定义这个启动时间：即冷启动中（冷启动大概意思就是手机中不存在该APP的进程，然后启动这种情况），从用户点击屏幕上的Logo开始到用户看到APP第一个页面展现在他眼前的这段时间，也就是尽快让用户看到应用页面

## adb start 命令 ##

在进行开发调试和上线前的测试工作时可以通过adb命令进行统计，如下

adb shell am start -S -R 5 -W com.mango.datasave/.SplashActivity

*  S表示每次启动前先强制杀死应用进程，达到每次都是冷启动，一定要大写
 *  R表示重复次数，一定要大写
 *  W表示是否等待输出日志信息，一定要大写
 *  后面接包名加Activity名称，别忘记点号了；要启动的Activity一定要有< intent-filter>标签或者android:exported="true"属性，否则会报SecurityException: Permission Denial异常

接下来看下执行结果，这里只截取一次

Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 cmp=com.mango.datasave/.SplashActivity }
    Status: ok
    Activity: com.mango.datasave/.SplashActivity
    ThisTime: 947
    TotalTime: 947
    WaitTime: 976
    Complete

可以看到这里有显示时间的三个字段ThisTime，TotalTime，WaitTime；那这三个时间指的是什么呢？这时候我们就要找到它们是怎么计算出来的，这样才能搞明白自己到底需要哪个

这句adb命令的实现是在

> frameworks\\base\\cmds\\am\\src\\com\\android\\commands\\am\\Am.java

**本文基于API24**

### AM.onRun ###

private IActivityManager mAm;
        private IPackageManager mPm;
    		
    	@Override
        public void onRun() throws Exception {
    
            mAm = ActivityManagerNative.getDefault();
            if (mAm == null) {
                throw new AndroidException("Can't connect to activity manager; is the system running?");
            }
    
            mPm = IPackageManager.Stub.asInterface(ServiceManager.getService("package"));
            if (mPm == null) {
                throw new AndroidException("Can't connect to package manager; is the system running?");
            }
    
            String op = nextArgRequired();
    
            if (op.equals("start")) {
                runStart();
            } else {
                showError("Error: unknown command '" + op + "'");
            }
        }

这个方法里其实还有很多命令的解析，比如startservice，stopservice，broadcast，dumpheap等，大家如果有兴趣可以去研究；我们这里就只看start这个命令

### AM.runStart ###

private void runStart() throws Exception {
        		//根据命令构建Intent
            Intent intent = makeIntent(UserHandle.USER_CURRENT);
    
            if (mUserId == UserHandle.USER_ALL) {
                System.err.println("Error: Can't start service with user 'all'");
                return;
            }
    
            String mimeType = intent.getType();
            if (mimeType == null && intent.getData() != null
                    && "content".equals(intent.getData().getScheme())) {
                mimeType = mAm.getProviderMimeType(intent.getData(), mUserId);
            }
    
    
            do {
            		//强制关闭应用
                if (mStopOption) {
                    String packageName;
                    if (intent.getComponent() != null) {
                        packageName = intent.getComponent().getPackageName();
                    } else {
                        List<ResolveInfo> activities = mPm.queryIntentActivities(intent, mimeType, 0,
                                mUserId).getList();
                        if (activities == null || activities.size() <= 0) {
                            System.err.println("Error: Intent does not match any activities: "
                                    + intent);
                            return;
                        } else if (activities.size() > 1) {
                            System.err.println("Error: Intent matches multiple activities; can't stop: "
                                    + intent);
                            return;
                        }
                        packageName = activities.get(0).activityInfo.packageName;
                    }
                    System.out.println("Stopping: " + packageName);
                    mAm.forceStopPackage(packageName, mUserId);
                    Thread.sleep(250);
                }
    
                System.out.println("Starting: " + intent);
                intent.addFlags(Intent.FLAG_ACTIVITY_NEW_TASK);
    
    						......
    
                IActivityManager.WaitResult result = null;
                int res;
                final long startTime = SystemClock.uptimeMillis();
                ActivityOptions options = null;
                if (mStackId != INVALID_STACK_ID) {
                    options = ActivityOptions.makeBasic();
                    options.setLaunchStackId(mStackId);
                }
                //通过Binder机制通知AMS启动Activity
                if (mWaitOption) {
                    result = mAm.startActivityAndWait(null, null, intent, mimeType,
                            null, null, 0, mStartFlags, profilerInfo,
                            options != null ? options.toBundle() : null, mUserId);
                    res = result.result;
                } else {
                    res = mAm.startActivityAsUser(null, null, intent, mimeType,
                            null, null, 0, mStartFlags, profilerInfo,
                            options != null ? options.toBundle() : null, mUserId);
                }
                final long endTime = SystemClock.uptimeMillis();
                PrintStream out = mWaitOption ? System.out : System.err;
                boolean launched = false;
                switch (res) {
                    case ActivityManager.START_SUCCESS:
                        launched = true;
                        break;
                }
                //输出日志信息
                if (mWaitOption && launched) {
                    if (result == null) {
                        result = new IActivityManager.WaitResult();
                        result.who = intent.getComponent();
                    }
                    System.out.println("Status: " + (result.timeout ? "timeout" : "ok"));
                    if (result.who != null) {
                        System.out.println("Activity: " + result.who.flattenToShortString());
                    }
                    if (result.thisTime >= 0) {
                        System.out.println("ThisTime: " + result.thisTime);
                    }
                    if (result.totalTime >= 0) {
                        System.out.println("TotalTime: " + result.totalTime);
                    }
                    System.out.println("WaitTime: " + (endTime-startTime));
                    System.out.println("Complete");
                }
                //重复执行
                mRepeat--;
                if (mRepeat > 1) {
                    mAm.unhandledBack();
                }
            } while (mRepeat > 1);
        }
        
        private Intent makeIntent(int defUser) throws URISyntaxException {
            mStartFlags = 0;
            mWaitOption = false;
            mStopOption = false;
            mRepeat = 0;
            mProfileFile = null;
            mSamplingInterval = 0;
            mAutoStop = false;
            mUserId = defUser;
            mStackId = INVALID_STACK_ID;
    
            return Intent.parseCommandArgs(mArgs, new Intent.CommandOptionHandler() {
                @Override
                public boolean handleOption(String opt, ShellCommand cmd) {
                    if (opt.equals("-D")) {
                        mStartFlags |= ActivityManager.START_FLAG_DEBUG;
                    } else if (opt.equals("-N")) {
                        mStartFlags |= ActivityManager.START_FLAG_NATIVE_DEBUGGING;
                    } else if (opt.equals("-W")) {
                        mWaitOption = true;
                    } else if (opt.equals("-P")) {
                        mProfileFile = nextArgRequired();
                        mAutoStop = true;
                    } else if (opt.equals("--start-profiler")) {
                        mProfileFile = nextArgRequired();
                        mAutoStop = false;
                    } else if (opt.equals("--sampling")) {
                        mSamplingInterval = Integer.parseInt(nextArgRequired());
                    } else if (opt.equals("-R")) {
                        mRepeat = Integer.parseInt(nextArgRequired());
                    } else if (opt.equals("-S")) {
                        mStopOption = true;
                    } else if (opt.equals("--track-allocation")) {
                        mStartFlags |= ActivityManager.START_FLAG_TRACK_ALLOCATION;
                    } else if (opt.equals("--user")) {
                        mUserId = parseUserArg(nextArgRequired());
                    } else if (opt.equals("--receiver-permission")) {
                        mReceiverPermission = nextArgRequired();
                    } else if (opt.equals("--stack")) {
                        mStackId = Integer.parseInt(nextArgRequired());
                    } else {
                        return false;
                    }
                    return true;
                }
            });
        }

从这个方法就能清楚的看到是通过Binder机制通知ActivityManagerService（以下简称AMS）去启动Activity；调用流程可以参考[从源码解析-Android中Activity启动流程包含AIDL使用案例和APP启动闪屏的缘由][-Android_Activity_AIDL_APP]；这里就不探讨这些知识了

### 时间计算 ###

从AM.runStart方法可以看出来，WaitTime是(endTime-startTime)的结果，startTime记录startActivityAndWait刚调用的时间，endTime是startActivityAndWait调用结束的时间，所以WaitTime就是startActivityAndWait所消耗的时间；而thisTime和totalTime是WaitResult 对象带回来的，它们在如下类中计算

> frameworks\\base\\services\\core\\java\\com\\android\\server\\am\\ActivityRecord.java

//计算时间
    	private void reportLaunchTimeLocked(final long curTime) {
            final ActivityStack stack = task.stack;
            if (stack == null) {
                return;
            }
            final long thisTime = curTime - displayStartTime;
            final long totalTime = stack.mLaunchStartTime != 0
                    ? (curTime - stack.mLaunchStartTime) : thisTime;
            if (SHOW_ACTIVITY_START_TIME) {
                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(")");
                }
            }
            mStackSupervisor.reportActivityLaunchedLocked(false, this, thisTime, totalTime);
    
            displayStartTime = 0;
            stack.mLaunchStartTime = 0;
        }
        //记录时间信息
        void reportActivityLaunchedLocked(boolean timeout, ActivityRecord r,
                long thisTime, long totalTime) {
            boolean changed = false;
            for (int i = mWaitingActivityLaunched.size() - 1; i >= 0; i--) {
                WaitResult w = mWaitingActivityLaunched.remove(i);
                if (w.who == null) {
                    changed = true;
                    w.timeout = timeout;
                    if (r != null) {
                        w.who = new ComponentName(r.info.packageName, r.info.name);
                    }
                    w.thisTime = thisTime;
                    w.totalTime = totalTime;
                }
            }
            if (changed) {
                mService.notifyAll();
            }
        }

这里的thisTime和totalTime和adb命令获取的是相同的，它们是根据curTime、displayStartTime、mLaunchStartTime三个时间变量计算

*  curTime表示reportLaunchTimeLocked函数调用的时间点，也就是最终Activity完整显示的时间点
 *  displayStartTime表示一连串启动Activity中的最后一个Activity的启动时间点
 *  mLaunchStartTime表示一连串启动Activity中第一个Activity的启动时间点

**注意**：那我们需要以哪个时间为准呢，其实不同需求要参考不同的时间，比如有的公司注重于用户点击APP尽快看到第一个Activity，像我这里就是这个目的；有的公司APP注重于尽快看到主页Activity，这种情况下就会经过一个广告页或者说欢迎页Activity，然后再到主页Activity，会有两个Activity；那我们就分两种情况讨论

*  启动单个Activity

我们这里的情况是点击桌面Logo启动应用，直到看到第一个Activity为止，所以displayStartTime和mLaunchStartTime是同一个值，所以根据上面的计算公式

thisTime = curTime - displayStartTime
    totalTime = stack.mLaunchStartTime != 0 ? (curTime - stack.mLaunchStartTime) : thisTime;

可以得出thisTime = totalTime

*  启动多个Activity

如果是连续启动多个Activity，displayStartTime就表示最后一个Activity开始启动时间点，mLaunchStartTime 表示第一个Activity启动时间点；这样根据上面公式计算thisTime < totalTime

### 总结 ###

可能你会有疑问，reportLaunchTimeLocked函数的参数curTime是什么时候的时间？前面说过，在onResume方法回调之后，Activity窗口才会添加到WMS中，然后进行绘制，窗口绘制完成后通知WMS，WMS在合适的时机控制界面开始显示(夹杂了界面切换动画逻辑)；显示出来后，WMS才调用reportLaunchTimeLocked()通知AMS Activity启动完成；所以这个curTime是最终完成时间；接下来就可以得出三个时间代表什么了

*  thisTime就是最后一个Activity启动所消耗的时间
 *  totalTime就是冷启动中一个新应用启动所消耗的时间，它包括进程创建，Application创建和Activity启动
 *  WaitTime就是总的时间，它还包括前一个Activity的pause方法耗时（这里就是桌面应用Activity pause方法耗时）

所以我们如果只关注自己Activity冷启动所消耗的时间，只用关注totalTime就行了，这也是自己应用真正启动的耗时；如果只关注最后一个Activity的耗时，那关注thisTime；如果还需要考虑系统消耗，那就关注WaitTime

注意：WaitTime比totalTime多了一个桌面应用LuncherActivity的pause方法耗时，但是这个我们开发者操作不了，所以就关注totalTime就行了

## Log日志 ##

当APP上线被用户使用后，使用adb命令肯定行不通了，这时候我们就得通过Log日志来将应用启动时间上报到服务器；但是问题来了，日志该添加到哪里呢？毕竟添加的位置直接决定启动时间统计是否准确，同样也会影响启动速度优化效果的判断；这时候就需要你熟知应用的启动流程和Activity的启动流程

*  由博主前面的文章可以知道一个APP被用户启动后，第一件事就是创建它的进程，然后加载ActivityThread类，在它的main方法做经过一系列的调用，其中第一件事就是创建应用的Application实例，这个是在所有Activity加载前做的事，所以Log起点就可以在Application里加；但是加在它哪个方法呢？幸运的是这个类的构造方法是public修饰的，我们可以将起点加在构造方法中；但是我们由于一些因素一般不用这个构造方法，这时候可以看到实例创建后立即调用的第一个方法是attach方法，但是它是final修饰，我们不能重写，好在是attach方法里调用了attachBaseContext方法，这个方法是可以被重写的，这样我们就可以将Log起点加在attachBaseContext方法中
 *  Log起始点有了，那就需要结束点；我们的目的是统计到第一个Activity页面显示出来的时间，那是不是加到第一个Activity的onResume方法呢？看到网上很多博客说当一个Activity的onResume方法回调之后，你就能看到Activity的页面内容了，这其实是错的，这个时候内容并没有绘制出来，当你结合上面分析和这篇文章[  
    从源码解析-结合Activity加载流程深入理解ActivityThrad的工作逻辑][_-_Activity_ActivityThrad]，你就知道Activity的onCreate方法在回调过程中做了目标Activity类的加载，进行Activity一些初始化操作，比如完成Window的创建并建立自己和Window的关联；还有主题设置，View树的建立（这里View还没有绘制，只是inflate而已）等这些事情；onStart，onResume方法在回调之后才会将窗口添加到WMS，绘制显示完后WMS通知AMS Activity启动完成，同时Activity的onWindowFocusChanged方法会被回调；所以我们可以重写这个方法然后加Log；但是要注意该方法在 Activity 焦点发生变化时就会触发，所以要做好判断，去掉不需要的情况

这样我们可以写个工具类统计时间并提交到服务端

/**
     * @Description TODO(时间辅助类)
     * @author cxy
     * @Date 2018/11/27 16:27
     */
    public class TimeTools {
    
        private static String TAG = TimeTools.class.getSimpleName();
    
        private static Map<String,Long> mStartTime = new HashMap<>();
        private static String TIME_BEGIN = "begin";
        private static String TIME_PART = "part";
    
        /**
         * 保存应用创建的时间点
         */
        public static void saveBeginTime(){
            long time = System.currentTimeMillis();
            mStartTime.put(TIME_BEGIN,time);
        }
    
        /**
         * 保存应用冷启动到第一个Activity完整显示所消耗的时间
         */
        public static void savePartTime(){
            //判断是不是冷启动
            if (!mStartTime.containsKey(TIME_BEGIN) || mStartTime.get(TIME_BEGIN) <= 0l) {
                return;
            }
            long timePart = System.currentTimeMillis() - mStartTime.get(TIME_BEGIN);
            mStartTime.put(TIME_PART,timePart);
            mStartTime.remove(TIME_BEGIN);
        }
    
        /**
         * 将启动时间提交到服务端
         */
        public static void commitTime2Server(){
    
            if (!mStartTime.containsKey(TIME_PART) || mStartTime.get(TIME_PART) <= 0) {
                return;
            }
    
            LocalThreadPools.getInstance().execute(new Runnable() {
                @Override
                public void run() {
                    long time = mStartTime.get(TIME_PART);
                    mStartTime.remove(TIME_PART);
                }
            });
        }
    }

然后在Application里

@Override
        protected void attachBaseContext(Context base) {
            super.attachBaseContext(base);
            TimeTools.saveBeginTime();
        }

在第一个Activity里这样

@Override
    public void onWindowFocusChanged(boolean hasFocus) {
        if (hasFocus) {
            TimeTools.savePartTime();
            TimeTools.commitTime2Server();
        }
    }

## 完结 ##

通过Log统计出来Demo的启动时间是778ms左右，比上面的adb命令获取的TotalTime: 947ms时间要少，因为TotalTime还包括进程创建时间，但是进程创建这部分作为开发者来说能做的有限；所以这个778ms就可以看做是应用冷启动消耗的时间，包括Application创建所消耗时间和Activity完全显示所消耗时间

所以你要想优加快APP启动速度，可以从这两个方面入手

参考文章  
[https://www.zhihu.com/question/35487841/answer/63011462][https_www.zhihu.com_question_35487841_answer_63011462]

[Link 1]: https://github.com/Mangosir/MangoDataSave
[-Android_Activity_AIDL_APP]: https://blog.csdn.net/qq_30993595/article/details/81773286#ActivityStarterstartActivityMayWait_791
[_-_Activity_ActivityThrad]: https://blog.csdn.net/qq_30993595/article/details/82771691#ATperformResumeActivity_1802
[https_www.zhihu.com_question_35487841_answer_63011462]: https://www.zhihu.com/question/35487841/answer/63011462