[034]Activity启动时间

前言

我相信大家肯定遇到过Activity启动慢的BUG,在优化问题之前,我们都会自我测试一下Activity启动耗时是不是和测试给的数值一样,在我们没有高速相机的情况下,我们如何获得Activity启动时间。
我一般都用这个指令:

adb logcat -b all | grep am_activity_launch_time

注意结果最后的数字297,代表Activity启动的时长297ms。

am_activity_launch_time: [0,44198042,com.kobe.jankblock/.MainActivity,297]

一、am_activity_launch_time计算的截止时间

一般对于一个Activity显示到屏幕上,有三个重要时间点,请问am_activity_launch_time计算的截止时间是以下哪个事件完成之后的。
onCreate
onResume
doTraversal-View.onDraw

二、Demo时间

写个demo试试看。

public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);
        try {
            Thread.sleep(100);//休眠100ms
        }catch (Exception e) {

        }
    }

    @Override
    protected void onResume() {
        super.onResume();
        try {
            Thread.sleep(200);//休眠200ms
        }catch (Exception e) {

        }
    }
}
public class MyTextView extends TextView {
    public MyTextView(Context context) {
        super(context);
    }

    public MyTextView(Context context, @Nullable AttributeSet attrs) {
        super(context, attrs);
    }

    public MyTextView(Context context, @Nullable AttributeSet attrs, int defStyleAttr) {
        super(context, attrs, defStyleAttr);
    }

    public MyTextView(Context context, @Nullable AttributeSet attrs, int defStyleAttr, int defStyleRes) {
        super(context, attrs, defStyleAttr, defStyleRes);
    }

    @Override
    protected void onDraw(Canvas canvas) {
        super.onDraw(canvas);
        try {
            Thread.sleep(400);//休眠100ms
        }catch (Exception e) {

        }
    }
}

上述代码非常简单,我分别在三个阶段block了100ms,200ms,400ms
这几个数值选取还是很有讲究的,我们可以通过一次测试就可以得到结论。
测试结果:1008 - 297 = 711 约等于 700ms。

am_activity_launch_time: [0,44198042,com.kobe.jankblock/.MainActivity,1008]
答案:am_activity_launch_time是以第一次doTraversal-View.onDraw完成为截止时间的,也就是Activity的第一帧绘制完成的时间(当然这句话不准确,因为真正的绘制还需要通过RenderThread去绘制)。

三、源码分析

我们就看看这个am_activity_launch_time是怎么计算的。

3.1 logAppDisplayed

/frameworks/base/services/core/java/com/android/server/wm/ActivityMetricsLogger.java

    private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
        if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
            return;
        }

        EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
                info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
                info.windowsDrawnDelayMs);//注意这个windowsDrawnDelayMs的值

        StringBuilder sb = mStringBuilder;
        sb.setLength(0);
        sb.append("Displayed ");
        sb.append(info.launchedActivityShortComponentName);
        sb.append(": ");
        TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
        Log.i(TAG, sb.toString());
    }

我们需要找到windowsDrawnDelayMs赋值的地方

3.2 notifyWindowsDrawn

/frameworks/base/services/core/java/com/android/server/wm/ActivityMetricsLogger.java

     /**
     * Notifies the tracker that all windows of the app have been drawn.
     */
    WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
                                                           long timestamp) {
        if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);

        final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
        if (info == null || info.loggedWindowsDrawn) {
            return null;
        }
        info.windowsDrawnDelayMs = calculateDelay(timestamp);//调用3.2.1
        info.loggedWindowsDrawn = true;
        final WindowingModeTransitionInfoSnapshot infoSnapshot =
                new WindowingModeTransitionInfoSnapshot(info);
        if (allWindowsDrawn() && mLoggedTransitionStarting) {
            reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
        }
        return infoSnapshot;
    }

    //3.2.1
    private int calculateDelay(long timestamp) {
        // Shouldn't take more than 25 days to launch an app, so int is fine here.
        return (int) (timestamp - mCurrentTransitionStartTime);
    }

info.windowsDrawnDelayMs = timestamp - mCurrentTransitionStartTime,所以我们需要找到调用notifyWindowsDrawn的地方。

3.3 onWindowsDrawn

/frameworks/base/services/core/java/com/android/server/wm/ActivityRecord.java

    /** Called when the windows associated app window container are drawn. */
    public void onWindowsDrawn(boolean drawn, long timestamp) {
        synchronized (mAtmService.mGlobalLock) {
            mDrawn = drawn;
            if (!drawn) {
                return;
            }
            final WindowingModeTransitionInfoSnapshot info = mStackSupervisor
                    .getActivityMetricsLogger().notifyWindowsDrawn(getWindowingMode(), timestamp);
            final int windowsDrawnDelayMs = info != null ? info.windowsDrawnDelayMs : INVALID_DELAY;
            final @LaunchState int launchState = info != null ? info.getLaunchState() : -1;
            mStackSupervisor.reportActivityLaunchedLocked(false /* timeout */, this,
                    windowsDrawnDelayMs, launchState);
            mStackSupervisor.stopWaitingForActivityVisible(this);
            finishLaunchTickingLocked();
            if (task != null) {
                task.hasBeenVisible = true;
            }
        }
    }

我们只要找对到onWindowsDrawn被调用的地方就可以了,我就不继续逆向分析,直接给出调用关系。

3.4 调用关系

3.4.1 App绘制完成如何通知WindowManagerService

有兴趣的朋友可以去看reportDrawFinished是什么时候被回调的,我就不深入讲了,不想研究的,只要记住第一帧绘制结束就会调用reportDrawFinished。
最后WindowSurfacePlacer中post(mPerformSurfacePlacement)
异步执行mPerformSurfacePlacement.run()

3.4.2 mPerformSurfacePlacement.run()如何调用到3.3 onWindowsDrawn

因为整个代码调用关系比较长,我就不画时序图了,直接给出调用堆栈。

V kobe    : java.lang.Exception: kobe
V kobe    :     at com.android.server.wm.ActivityRecord.onWindowsDrawn(ActivityRecord.java:2458)
V kobe    :     at com.android.server.wm.AppWindowToken.updateReportedVisibilityLocked(AppWindowToken.java:432)
V kobe    :     at com.android.server.wm.AppWindowToken.onFirstWindowDrawn(AppWindowToken.java:394)
V kobe    :     at com.android.server.wm.WindowState.performShowLocked(WindowState.java:3955)
V kobe    :     at com.android.server.wm.WindowStateAnimator.commitFinishDrawingLocked(WindowStateAnimator.java:349)
V kobe    :     at com.android.server.wm.DisplayContent.lambda$new$8$DisplayContent(DisplayContent.java:859)
V kobe    :     at com.android.server.wm.-$$Lambda$DisplayContent$qxt4izS31fb0LF2uo_OF9DMa7gc.accept(Unknown Source:4)
V kobe    :     at com.android.server.wm.WindowContainer$ForAllWindowsConsumerWrapper.apply(WindowContainer.java:1178)
V kobe    :     at com.android.server.wm.WindowContainer$ForAllWindowsConsumerWrapper.apply(WindowContainer.java:1168)
V kobe    :     at com.android.server.wm.WindowState.applyInOrderWithImeWindows(WindowState.java:4168)
V kobe    :     at com.android.server.wm.WindowState.forAllWindows(WindowState.java:4067)
V kobe    :     at com.android.server.wm.WindowContainer.forAllWindows(WindowContainer.java:877)
V kobe    :     at com.android.server.wm.AppWindowToken.forAllWindowsUnchecked(AppWindowToken.java:2061)
V kobe    :     at com.android.server.wm.AppWindowToken.forAllWindows(AppWindowToken.java:2051)
V kobe    :     at com.android.server.wm.WindowContainer.forAllWindows(WindowContainer.java:877)
V kobe    :     at com.android.server.wm.WindowContainer.forAllWindows(WindowContainer.java:877)
V kobe    :     at com.android.server.wm.WindowContainer.forAllWindows(WindowContainer.java:877)
V kobe    :     at com.android.server.wm.DisplayContent$TaskStackContainers.forAllWindows(DisplayContent.java:4447)
V kobe    :     at com.android.server.wm.DisplayContent.forAllWindows(DisplayContent.java:2224)
V kobe    :     at com.android.server.wm.WindowContainer.forAllWindows(WindowContainer.java:894)
V kobe    :     at com.android.server.wm.DisplayContent.applySurfaceChangesTransaction(DisplayContent.java:3838)
V kobe    :     at com.android.server.wm.RootWindowContainer.applySurfaceChangesTransaction(RootWindowContainer.java:864)
V kobe    :     at com.android.server.wm.RootWindowContainer.performSurfacePlacementNoTrace(RootWindowContainer.java:641)
V kobe    :     at com.android.server.wm.RootWindowContainer.performSurfacePlacement(RootWindowContainer.java:598)
V kobe    :     at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacementLoop(WindowSurfacePlacer.java:159)
V kobe    :     at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:105)
V kobe    :     at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:95)
V kobe    :     at com.android.server.wm.WindowSurfacePlacer.lambda$new$0$WindowSurfacePlacer(WindowSurfacePlacer.java:62)
V kobe    :     at com.android.server.wm.-$$Lambda$WindowSurfacePlacer$4Hbamt-LFcbu8AoZBoOZN_LveKQ.run(Unknown Source:2)
V kobe    :     at android.os.Handler.handleCallback(Handler.java:883)
V kobe    :     at android.os.Handler.dispatchMessage(Handler.java:100)
V kobe    :     at android.os.Looper.loop(Looper.java:214)
V kobe    :     at android.os.HandlerThread.run(HandlerThread.java:67)
V kobe    :     at com.android.server.ServiceThread.run(ServiceThread.java:44)

四、总结

am_activity_launch_time是截止到activity的第一帧绘制完成的时间,整个时间包含onCreate,onResume,doTraversal,一般情况下am_activity_launch_time还是很客观地展现出一个activity启动时间。

但是有时候测试标准不一样,测试标准可能要求是整个界面完全显示出来,尤其是需要异步网络请求数据,后面几帧展现更多UI,对于这个情况,Activity启动时间就要远远大于am_activity_launch_time。

但是通过am_activity_launch_time来衡量一个Activity启动时间还是很科学的。

五、尾巴

我主要是跟踪了这个timestamp是怎么来的,你们自己可以跟一下mCurrentTransitionStartTime

    private int calculateDelay(long timestamp) {
        // Shouldn't take more than 25 days to launch an app, so int is fine here.
        return (int) (timestamp - mCurrentTransitionStartTime);
    }

如何跟踪Android的源码,最要的是记住关键的跨进程Binder调用点,跨线程的Handler异步调用点。我上面跟踪代码中就有一处跨进程Binder调用点和跨线程的Handler异步调用点,欢迎留言回答。

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

推荐阅读更多精彩内容