am start -W 统计启动时间点简介

通过am start -W package/componentName可以开启一个Activity
例如
am start -W com.tcl.testdemo1/.MainActivity
Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=com.tcl.testdemo1/.MainActivity }
Status: ok
Activity: com.tcl.testdemo1/.MainActivity
ThisTime: 2144
TotalTime: 2144
WaitTime: 2262
Complete
我们可以得到三个时间
WaitTime、TotalTime、ThisTime分别是怎么统计的,统计的是Activity启动哪一段时间段

“adb shell am start -W ”的实现在 /frameworks/base/services/core/java/com/android/server/am/ActivityManagerShellCommand.java 文件中。通过Binder调用ActivityManagerService.startActivityAndWait() 接口
代码位置

/frameworks/base/services/core/java/com/android/server/am/ActivityManagerShellCommand.java   
   @Override
      public int onCommand(String cmd) {
           ......
              switch (cmd) {
                  case "start":
                  case "start-activity":
                      return runStartActivity(pw);
          ......
/frameworks/base/services/core/java/com/android/server/am/ActivityManagerShellCommand.java   
int runStartActivity(PrintWriter pw) throws RemoteException {
......
              intent = makeIntent(UserHandle.USER_CURRENT);//会把mWaitOption设置为了true
......
             final long startTime = SystemClock.uptimeMillis();  //计算WaitTime的开始的时间
 . . . . . .
              if (mWaitOption) {
                  result = mInterface.startActivityAndWait(null, null, intent, mimeType,
                          null, null, 0, mStartFlags, profilerInfo,
                          options != null ? options.toBundle() : null, mUserId);
                  res = result.result;
              } else {
                  res = mInterface.startActivityAsUser(null, null, intent, mimeType,
                          null, null, 0, mStartFlags, profilerInfo,
                          options != null ? options.toBundle() : null, mUserId);
              }
             final long endTime = SystemClock.uptimeMillis();  //计算WaitTime结束的时间
......

      调用result = mInterface.startActivityAndWait 启动成功,返回result。 启动成功后launched为true
       下面就是我们看到的输入am start -W 后打印的结果,
              if (mWaitOption && launched) {
                  if (result == null) {
                      result = new WaitResult();
                      result.who = intent.getComponent();
                  }
                  pw.println("Status: " + (result.timeout ? "timeout" : "ok"));
                  if (result.who != null) {
                      pw.println("Activity: " + result.who.flattenToShortString());
                  }
                  if (result.thisTime >= 0) {
                      pw.println("ThisTime: " + result.thisTime);
                  }
                  if (result.totalTime >= 0) {
                      pw.println("TotalTime: " + result.totalTime);
                  }
                  pw.println("WaitTime: " + (endTime-startTime));
                  pw.println("Complete");
                  pw.flush();
              }

结果有 status:,Activity:,ThisTime:,TotalTime:,WaitTime:,Complete字段等。

可以看到WaitTime 是 endTime-startTime 就是结束时间减开始时间

一、WaitTime

那 mInterface.startActivityAndWait是走到哪一步返回了。

接下来源码跟踪下这些字段的赋值。

/frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java
    @Override
    public final WaitResult startActivityAndWait(IApplicationThread caller, String callingPackage,
            Intent intent, String resolvedType, IBinder resultTo, String resultWho, int requestCode,
            int startFlags, ProfilerInfo profilerInfo, Bundle bOptions, int userId) {
        enforceNotIsolatedCaller("startActivityAndWait");
        userId = mUserController.handleIncomingUser(Binder.getCallingPid(), Binder.getCallingUid(),
                userId, false, ALLOW_FULL_ONLY, "startActivityAndWait", null);
        WaitResult res = new WaitResult();      //WaitResult在这里new出来,Activity启动时间对象
        // TODO: Switch to user app stacks here.
        mActivityStartController.obtainStarter(intent, "startActivityAndWait")
                .setCaller(caller)
                .setCallingPackage(callingPackage)
                .setResolvedType(resolvedType)
                .setResultTo(resultTo)
                .setResultWho(resultWho)
                .setRequestCode(requestCode)
                .setStartFlags(startFlags)
                .setActivityOptions(bOptions)
                .setMayWait(userId)
                .setProfilerInfo(profilerInfo)
                .setWaitResult(res)
                .execute();
        return res;  //这里return的是WaitResult对象
    }
/frameworks/base/services/core/java/com/android/server/am/ActivityStarter.java
    int execute() {
......
                return startActivityMayWait(mRequest.caller, mRequest.callingUid,
                        mRequest.callingPackage, mRequest.intent, mRequest.resolvedType,
                        mRequest.voiceSession, mRequest.voiceInteractor, mRequest.resultTo,
                        mRequest.resultWho, mRequest.requestCode, mRequest.startFlags,
                        mRequest.profilerInfo, mRequest.waitResult, mRequest.globalConfig,
                        mRequest.activityOptions, mRequest.ignoreTargetSecurity, mRequest.userId,
                        mRequest.inTask, mRequest.reason,
                        mRequest.allowPendingRemoteAnimationRegistryLookup);
        ...... //这里return的是int类型,当然没人接它,感觉没啥用处。
    }


  private int startActivityMayWait(......){
      ......
          final ActivityRecord[] outRecord = new ActivityRecord[1];
           int res = startActivity(caller, intent, ephemeralIntent, resolvedType, aInfo, rInfo,
            voiceSession, voiceInteractor, resultTo, resultWho, requestCode, callingPid,
            callingUid, callingPackage, realCallingPid, realCallingUid, startFlags, options,
            ignoreTargetSecurity, componentSpecified, outRecord, inTask, reason,
            allowPendingRemoteAnimationRegistryLookup);
      ......
            if (outResult != null) { //这个就是WaitResult对象,当然不为空
//res可能返回三个不同结果START_SUCCESS、START_TASK_TO_FRONT、START_DELIVERED_TO_TOP,我们的重点在START_SUCCESS
                outResult.result = res;   
                final ActivityRecord r = outRecord[0];
                switch(res) {
                    case START_SUCCESS: {
                        mSupervisor.mWaitingActivityLaunched.add(outResult);//把outResult加入到队列中是想干啥,当然是赋值了,totalTime,ThisTime用。
                        do {
                            try {
                                mService.wait(); //启动成功后直接wait住了,等待唤醒。
                            } catch (InterruptedException e) {
                            }
                        } while (outResult.result != START_TASK_TO_FRONT
                                && !outResult.timeout && outResult.who == null);
                        if (outResult.result == START_TASK_TO_FRONT) {
                            res = START_TASK_TO_FRONT;
                        }
                        break;
                    }
                    case START_DELIVERED_TO_TOP: {
                        ......
                        break;
                    }
                    case START_TASK_TO_FRONT: {
                        ......
                        break;
                    }
                }
            }

            mSupervisor.getActivityMetricsLogger().notifyActivityLaunched(res, outRecord[0]);
            return res;
  }
  

一共三点:
1,startActivity什么时候返回;
2,mSupervisor.mWaitingActivityLaunched.add(outResult) 是怎么个赋值;
3,mService.wait() 什么时候唤醒。
唤醒后就直接返回了START_SUCCESS,然后一路返回,到最开始,这个时候waitTime就计算出来了。

二、TotalTime、ThisTime

我们知道Activity显示出来会走到ActivityRecord的reportLaunchTimeLocked

/frameworks/base/services/core/java/com/android/server/am/ActivityRecord.java
    private void reportLaunchTimeLocked(final long curTime) {
               //这个LaunchTimeTracker是个关键,下来跟踪一下。
        final LaunchTimeTracker.Entry entry = mStackSupervisor.getLaunchTimeTracker().getEntry(
                getWindowingMode());
        if (entry == null) {
            return;
        }
        final long thisTime = curTime - displayStartTime;
        final long totalTime = entry.mLaunchStartTime != 0
                ? (curTime - entry.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.toString()); //ActivityManager: Displayed packagename/.xxx: +3s534ms
        }
        //这个就是更新mWaitingActivityLaunched的集合,更新WaitResult
        mStackSupervisor.reportActivityLaunchedLocked(false, this, thisTime, totalTime); 
        if (totalTime > 0) {
            //service.mUsageStatsService.noteLaunchTime(realActivity, (int)totalTime);
        }
        displayStartTime = 0;
        entry.mLaunchStartTime = 0;
    }

这里有几个关键字

curTime表示该函数调用的时间点.
displayStartTime表示一连串启动Activity中的最后一个Activity的启动时间点.
mLaunchStartTime表示一连串启动Activity中第一个Activity的启动时间点.

thisTime:最后一个activity从启动到绘制完成的时间
totalTime:是第一个activity的启动时间到最后一个activity的绘制完成时间。如果只启动一个activity,则thisTime和totalTime一致。

看下displayStartTime、mLaunchStartTime的赋值

/frameworks/base/services/core/java/com/android/server/am/LaunchTimeTracker.java
    static class Entry {
        long mLaunchStartTime;
        long mFullyDrawnStartTime;


        void setLaunchTime(ActivityRecord r) {
            if (r.displayStartTime == 0) {
                r.fullyDrawnStartTime = r.displayStartTime = SystemClock.uptimeMillis();
                if (mLaunchStartTime == 0) {
                    startLaunchTraces(r.packageName);
                    mLaunchStartTime = mFullyDrawnStartTime = r.displayStartTime;
                }
            } else if (mLaunchStartTime == 0) {
                startLaunchTraces(r.packageName);
                mLaunchStartTime = mFullyDrawnStartTime = SystemClock.uptimeMillis();
            }
        }

setLaunchTime 的调用的地方有两处
1、ActivityStackSupervisor.java

int startSpecificActivityLocked(){
......
getLaunchTimeTracker().setLaunchTime(r);
......
}

2、ActivityStack.java

int minimalResumeActivityLocked(){
......
mStackSupervisor.getLaunchTimeTracker().setLaunchTime(r);
......
}

启动Activity执行顺序先1后2,
1、只启动一个Activity
这个时候displayStartTime == mLaunchStartTime 就是进程启动之前的时间点。
thisTime = TotalTime
2、连续启动2个Activity
这个时候displayStartTime就是第一个Activity的启动时间,mLaunchStartTime就是第二个Activity的启动时间。
thisTime 是最后一个activity启动的时间点。


image.png

在上面的图中,我用①②③分别标注了三个时间段,在这三个时间段内分别干了什么事呢?

在第①个时间段内,AMS 创建 ActivityRecord 记录块和选择合理的 Task、将当前Resume 的 Activity 进行 pause
在第②个时间段内,启动进程、调用无界面 Activity 的 onCreate() 等、 pause/finish 无界面的 Activity
在第③个时间段内,调用有界面 Activity 的 onCreate、onResume
看到这里应该清楚 ThisTime、TotalTime、WaitTime 三个时间的关系了吧:

WaitTime 就是总的耗时,包括前一个应用 Activity pause 的时间和新应用启动的时间;
ThisTime 表示一连串启动 Activity 的最后一个 Activity 的启动耗时;
TotalTime 表示新应用启动的耗时,包括新进程的启动和 Activity 的启动,但不包括前
一个应用 Activity pause 的耗时。也就是说,开发者一般只要关心 TotalTime 即可,这个时间才是自己应用真正启动的耗时。

Event log中 TAG=am_activity_launch_time 中的两个值分表表示 ThisTime、TotalTime,跟通过 “adb shell am start -W ” 得到的值是一致的。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,271评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,275评论 2 380
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,151评论 0 336
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,550评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,553评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,559评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,924评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,580评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,826评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,363评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,940评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2 342

推荐阅读更多精彩内容