性能优化之matrix学习-Trace Canary

1,177 阅读22分钟

TraceCanary 模块只能在 API 16 以上的设备运行,内部分为 ANR、帧率、慢方法、启动四个监测模块,核心接口是 LooperObserver。 LooperObserver 是一个抽象类,顾名思义,它是 Looper 的观察者,在 Looper 分发消息、刷新 UI 时回调,这几个回调方法也是 ANR、慢方法等模块的判断依据:

public abstract class LooperObserver  {

    // 分发消息前
    @CallSuper
    public void dispatchBegin(long beginMs, long cpuBeginMs, long token) {
    }

    // UI 刷新
    public void doFrame(String focusedActivityName, long start, long end, long frameCostMs,
                        long inputCostNs, long animationCostNs, long traversalCostNs) {
    }

    // 分发消息后
    @CallSuper
    public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
    }
}

Looper 的监控是由类 LooperMonitor 实现的,原理很简单,为主线程 Looper 设置一个 Printer 即可,但值得一提的是,LooperMonitor 不会直接设置 Printer,而是先获取旧对象,并创建代理对象,避免影响到其它用户设置的 Printer:

private synchronized void resetPrinter() {
    Printer originPrinter = ReflectUtils.get(looper.getClass(), "mLogging", looper);;
    looper.setMessageLogging(printer = new LooperPrinter(originPrinter));
}

class LooperPrinter implements Printer {
    @Override
    public void println(String x) {
        if (null != origin) {
            origin.println(x); // 保证原对象正常执行
        }
        dispatch(x.charAt(0) == '>', x); // 分发,通过第一个字符判断是开始分发,还是结束分发
    }
}

UI 刷新监控是基于 Choreographer 实现的,TracePlugin 初始化时,UIThreadMoniter 就会通过反射的方式往 Choreographer 添加回调:

public class UIThreadMonitor implements BeatLifecycle, Runnable {

    // Choreographer 中一个内部类的方法,用于添加回调
    private static final String ADD_CALLBACK = "addCallbackLocked";

    // 回调类型,分别为输入事件、动画、View 绘制三种
    public static final int CALLBACK_INPUT = 0;
    public static final int CALLBACK_ANIMATION = 1;
    public static final int CALLBACK_TRAVERSAL = 2;

    public void init(TraceConfig config) {
        choreographer = Choreographer.getInstance();
        // 回调队列
        callbackQueues = reflectObject(choreographer, "mCallbackQueues");
        // 反射,找到在 Choreographer 上添加回调的方法
        addInputQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_INPUT], ADD_CALLBACK, long.class, Object.class, Object.class);
        addAnimationQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_ANIMATION], ADD_CALLBACK, long.class, Object.class, Object.class);
        addTraversalQueue = reflectChoreographerMethod(callbackQueues[CALLBACK_TRAVERSAL], ADD_CALLBACK, long.class, Object.class, Object.class);
    }
}

之所以通过反射的方式实现,而不是通过 postCallback,是为了把我们的 callback 放到头部,这样才能计算系统提交的输入事件、动画、View 绘制等事件的耗时。

这样,等 Choreographer 监听到 vsync 信号时,UIThreadMonitor 和系统添加的回调都会被执行(比如在绘制 View 的时候,系统会往 Choreographer 添加一个 traversal callback):

public final class Choreographer {

    private final class FrameDisplayEventReceiver extends DisplayEventReceiver implements Runnable {
        @Override
        public void run() {
            doFrame(mTimestampNanos, mFrame);
        }
    }

    void doFrame(long frameTimeNanos, int frame) {
        doCallbacks(Choreographer.CALLBACK_INPUT, frameTimeNanos);
        doCallbacks(Choreographer.CALLBACK_ANIMATION, frameTimeNanos);
        doCallbacks(Choreographer.CALLBACK_TRAVERSAL, frameTimeNanos);
        ...
    }
}

因为 UIThreadMonitor 添加的回调在队列头部,可用于记录开始时间,而其它系统方法,比如 View 的 postOnAnimation 添加的回调在后面,因此所有同类型回调执行完毕后,就可以计算对应的事件(输入事件、动画、View 绘制等)的耗时。

image.png

ANR 监控原理:在 Looper 分发消息时,往后台线程插入一个延时(5s 后执行)任务,Looper 消息分发完毕后就删除,如果过了 5s,该任务未被删除,就认为出现了 ANR。

public class AnrTracer extends Tracer {

    // onAlive 时初始化,onDead 时退出
    private Handler anrHandler;
    private volatile AnrHandleTask anrTask;

    public void dispatchBegin(long beginMs, long cpuBeginMs, long token) {
        // 插入方法结点,如果出现了 ANR,就从该结点开始收集方法执行记录
        anrTask = new AnrHandleTask(AppMethodBeat.getInstance().maskIndex("AnrTracer#dispatchBegin"), token);
        // 5 秒后执行
        // token 和 beginMs 相等,因此后一个减式用于减去回调该方法过程中所消耗的时间
        anrHandler.postDelayed(anrTask, Constants.DEFAULT_ANR - (SystemClock.uptimeMillis() - token));
    }

    @Override
    public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
        if (null != anrTask) {
            anrTask.getBeginRecord().release();
            anrHandler.removeCallbacks(anrTask);
        }
    }
}

如果 5s 后该任务未被删除,那么 AnrTracer 就会开始收集进程、线程、内存、堆栈等信息,并上报。

应用的启动监控以第一个执行的方法为起点:

public class AppMethodBeat implements BeatLifecycle {

    private static volatile int status = STATUS_DEFAULT;

    // 该方法会被插入到每一个方法的开头执行
    public static void i(int methodId) {

        if (status == STATUS_DEFAULT) { // 如果是默认状态,则说明是第一个方法
            realExecute();
            status = STATUS_READY;
        }
    }

    private static void realExecute() {
        // 记录时间戳
        ActivityThreadHacker.hackSysHandlerCallback();
        // 开始监控主线程 Looper
        LooperMonitor.register(looperMonitorListener);
    }
}

记录了第一个方法开始执行时的时间戳后,Matrix 还会通过反射的方式,接管 ActivityThread 的 Handler 的 Callback:

public class ActivityThreadHacker {

    public static void hackSysHandlerCallback() {
        // 记录时间戳,作为应用启用的开始时间
        sApplicationCreateBeginTime = SystemClock.uptimeMillis();
        // 反射 ActivityThread,接管 Handler
        Class<?> forName = Class.forName("android.app.ActivityThread");
        ...
    }
}

这样就能知道第一个 Activity 或 Service 或 Receiver 启动的具体时间了,这个时间戳可以作为 Application 启动的结束时间:

private final static class HackCallback implements Handler.Callback {
    private static final int LAUNCH_ACTIVITY = 100;
    private static final int CREATE_SERVICE = 114;
    private static final int RECEIVER = 113;
    private static boolean isCreated = false;

    @Override
    public boolean handleMessage(Message msg) {
        boolean isLaunchActivity = isLaunchActivity(msg);
        // 如果是第一个启动的 Activity 或 Service 或 Receiver,则以该时间戳作为 Application 启动的结束时间
        if (!isCreated) {
            if (isLaunchActivity || msg.what == CREATE_SERVICE || msg.what == RECEIVER) { // todo for provider
                ActivityThreadHacker.sApplicationCreateEndTime = SystemClock.uptimeMillis();
                ActivityThreadHacker.sApplicationCreateScene = msg.what;
                isCreated = true;
            }
        }
    }
}

最后以主 Activity(闪屏页之后的第一个 Activity)的 onWindowFocusChange 方法作为终点,记录时间戳——Activity 的启动耗时可以通过 onWindowFocusChange 方法回调时的时间戳减去其启动时的时间戳。收集到上述信息之后即可统计启动耗时:

firstMethod.i       LAUNCH_ACTIVITY   onWindowFocusChange   LAUNCH_ACTIVITY    onWindowFocusChange
^                         ^                   ^                     ^                  ^
|                         |                   |                     |                  |
|---------app---------|---|---firstActivity---|---------...---------|---careActivity---|
|<--applicationCost-->|
|<--------------firstScreenCost-------------->|
|<---------------------------------------coldCost------------------------------------->|
.                         |<-----warmCost---->|

如果冷启动/暖启动耗时超过某个阈值(可通过 IDynamicConfig 设置,默认分别为 10s、4s),那么就会从 AppMethodBeat 收集启动过程中的方法执行记录并上报,否则只会简单地上报耗时信息。

慢方法监测的原理是在 Looper 分发消息时,计算分发耗时(endMs - beginMs),如果大于阈值(可通过 IDynamicConfig 设置,默认为 700ms),就收集信息并上报。

ublic class EvilMethodTracer extends Tracer {

    @Override
    public void dispatchBegin(long beginMs, long cpuBeginMs, long token) {
        super.dispatchBegin(beginMs, cpuBeginMs, token);
        // 插入方法结点,如果出现了方法执行过慢的问题,就从该结点开始收集方法执行记录
        indexRecord = AppMethodBeat.getInstance().maskIndex("EvilMethodTracer#dispatchBegin");
    }

    @Override
    public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
        long dispatchCost = endMs - beginMs;
        // 耗时大于慢方法阈值
        if (dispatchCost >= evilThresholdMs) {
            long[] data = AppMethodBeat.getInstance().copyData(indexRecord);
            MatrixHandlerThread.getDefaultHandler().post(new AnalyseTask(...);
        }
    }

    private class AnalyseTask implements Runnable {
        void analyse() {
            // 收集进程与 CPU 信息
            int[] processStat = Utils.getProcessPriority(Process.myPid());
            String usage = Utils.calculateCpuUsage(cpuCost, cost);
            // 从插入结点开始收集并整理方法执行记录
            TraceDataUtils.structuredDataToStack(data, stack, true, endMs);
            TraceDataUtils.trimStack(stack, Constants.TARGET_EVIL_METHOD_STACK,
                    new TraceDataUtils.IStructuredDataFilter() { ... }
            // 上报问题
            TracePlugin plugin = Matrix.with().getPluginByClass(TracePlugin.class);
            plugin.onDetectIssue(issue);
        }
    }
}

帧率监测的原理是监听 Choreographer,在所有回调都执行完毕后计算当前总共花费的时间,从而计算掉帧数及掉帧程度,当同一个 Activity/Fragment 掉帧程度超过阈值时,就上报问题。关键源码如下:

private class FPSCollector extends IDoFrameListener {
    @Override
    public void doFrameAsync(String visibleScene, long taskCost, long frameCostMs,
                             int droppedFrames, boolean isContainsFrame) {
        // 使用 Map 保存同一 Activity/Fragment 的掉帧信息
        FrameCollectItem item = map.get(visibleScene);
        if (null == item) {
            item = new FrameCollectItem(visibleScene);
            map.put(visibleScene, item);
        }

        // 累计
        item.collect(droppedFrames, isContainsFrame);

        // 如果掉帧程度超过一定阈值,就上报问题,并重新计算
        // 总掉帧时间 sumFrameCost = 掉帧数 * 16.66ms
        // 掉帧上报阈值 timeSliceMs 可通过 IDynamicConfig 设置,默认为 10s
        if (item.sumFrameCost >= timeSliceMs) { // report
            map.remove(visibleScene);
            item.report();
        }
    }
}

但这里存在一个问题,那就是 Matrix 计算 UI 刷新耗时时,每次都会在掉帧数的基础上加 1:

private class FrameCollectItem {

    void collect(int droppedFrames, boolean isContainsFrame) {
        // 即使掉帧数为 0,这个值也会不断增加
        sumFrameCost += (droppedFrames + 1) * frameIntervalCost / Constants.TIME_MILLIS_TO_NANO;
    }
}

而且,doFrame 方法不是只在 UI 刷新时回调,而是每次 Looper 分发消息完毕后都会回调,而 Lopper 分发消息的频率可能远远大于帧率,这就导致即使实际上没有出现掉帧的情况,但由于 Looper 不断分发消息的缘故,sumFrameCost 的值也会不断累加,很快就突破了上报的阈值,进而频繁地上报:

private void dispatchEnd() {
    ...
    synchronized (observers) {
        for (LooperObserver observer : observers) {
            if (observer.isDispatchBegin()) {
                observer.doFrame(...);
            }
        }
    }
}

解决方法是在 PluginListener 中手动过滤,或者修改源码。

TraceCanary 分为慢方法、启动、ANR、帧率四个模块,每个模块的功能都是通过监听接口 LooperObserver 实现的,LooperObserver 用于对主线程的 Looper 和 Choreographer 进行监控。

Looper 的监控是通过 Printer 实现的,每次事件分发都会回调 LooperObserver 的 dispatchBegin、dispatchEnd 方法,计算这两个方法的耗时可以检测慢方法和 ANR 等问题。

Choreographer 的监控则是通过添加 input、animation、traversal 等各个类型的回调到 Choreographer 头部实现的,vsync 信号触发后,Choreographer 中各个类型的回调会被执行,两种类型的回调的开始时间的间隔就相当于第一种类型的事件的耗时(即 input.cost = animation.begin - input.begiin),最后一种事件(traversal)执行完毕后,Looper 的 diaptchEnd 方法也会被执行,因此 traversal.cost = Looper.dispatchEnd -traversal.begin。

各个模块的实现原理如下:

ANR:在 Looper 开始分发消息时,往后台线程插入一个延时(5s 后执行)任务,Looper 消息分发完毕后就删除,如果过了 5s,该任务未被删除,就认为出现了 ANR,收集信息,报告问题

慢方法:在 Looper 分发消息时,计算分发耗时(endMs - beginMs),如果大于阈值(可通过 IDynamicConfig 设置,默认为 700ms),就收集信息并上报

启动:以第一个执行的方法为起点记录时间戳,接着记录第一个 Activity 或 Service 或 Receiver 启动时的时间戳,作为 Application 启动的结束时间。最后以主 Activity(闪屏页之后的第一个 Activity)的 onWindowFocusChange 方法作为终点,记录时间戳。Activity 的启动耗时可以通过 onWindowFocusChange 方法回调时的时间戳减去其启动时的时间戳。收集到上述信息之后即可统计启动耗时。

掉帧:监听 Choreographer,doFrame 回调时统计 UI 刷新耗时,计算掉帧数及掉帧程度,当同一个 Activity/Fragment 掉帧程度超过阈值时,就上报。但 Matrix 的计算方法存在问题,可能出现频繁上报的情况,需要自行手动过滤。

慢函数检测

目的:检测影响主线程执行的慢函数。

与FrameTracer类似,EvilMethodTracer的实现也依赖于UIThreadMonitor中抛出来的LooperObserver接口里面的dispatchBegin、doFrame、dispatchEnd三个方法。

在dispatchBegin方法中,记录下AppMethodBeat中目前的index,记为start; 在dispatchEnd中,读取目前AppMethodBeat中目前的index,记为end。这两者中间的数据则为这段时间内执行的方法的入栈、出栈信息。当这个Message执行时间超过指定的阈值(默认700ms)时,认为可能发生了慢方法,此时会进行进一步的分析。 至于doFrame中记录的数据,没有啥具体的用处,这是在最后打印了log而已。

@Override
public void dispatchBegin(long beginMs, long cpuBeginMs, long token) {
    super.dispatchBegin(beginMs, cpuBeginMs, token);
    // 记录起始index
    indexRecord = AppMethodBeat.getInstance().maskIndex("EvilMethodTracer#dispatchBegin");
}

@Override
public void doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCostNs, long animationCostNs, long traversalCostNs) {
    queueTypeCosts[0] = inputCostNs;
    queueTypeCosts[1] = animationCostNs;
    queueTypeCosts[2] = traversalCostNs;
}

@Override
public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
    super.dispatchEnd(beginMs, cpuBeginMs, endMs, cpuEndMs, token, isBelongFrame);
    long start = config.isDevEnv() ? System.currentTimeMillis() : 0;
    try {
        // 若Message执行总耗时超过了阈值
        long dispatchCost = endMs - beginMs;
        if (dispatchCost >= evilThresholdMs) {
            // 则解析出这段时间内函数的调用堆栈
            long[] data = AppMethodBeat.getInstance().copyData(indexRecord);
            long[] queueCosts = new long[3];
            System.arraycopy(queueTypeCosts, 0, queueCosts, 0, 3);
            String scene = AppMethodBeat.getVisibleScene();
            // 在子线程进行分析上报
            MatrixHandlerThread.getDefaultHandler().post(new AnalyseTask(isForeground(), scene, data, queueCosts, cpuEndMs - cpuBeginMs, endMs - beginMs, endMs));
        }
    } finally {
        // 释放IndexRecord
        indexRecord.release();
        if (config.isDevEnv()) {
            String usage = Utils.calculateCpuUsage(cpuEndMs - cpuBeginMs, endMs - beginMs);
            MatrixLog.v(TAG, "[dispatchEnd] token:%s cost:%sms cpu:%sms usage:%s innerCost:%s",
                    token, endMs - beginMs, cpuEndMs - cpuBeginMs, usage, System.currentTimeMillis() - start);
        }
    }
}

下面我们看看AnalyseTask是如何分析并上报的:

private class AnalyseTask implements Runnable {
    ...

    void analyse() {

        // process
        // 获取进程的priority以及nice,原理是读取/proc/<pid>/stat中的数据
        int[] processStat = Utils.getProcessPriority(Process.myPid());
        // 计算出cpu使用率
        String usage = Utils.calculateCpuUsage(cpuCost, cost);
        LinkedList<MethodItem> stack = new LinkedList();
        if (data.length > 0) {
            // 将原始long[]数组合并成为MethodItem类型的List
            // 第3个参数(isStrict)与第4个参数(endTime)成对,若isStrict为true,则处理原始数据时会从第一个METHOD_ID_DISPATCH开始
            // 同时,若处理完毕后还有部分i数据没有匹配的o,则将endTime作为o的时间合并到List中
            TraceDataUtils.structuredDataToStack(data, stack, true, endMs);
            TraceDataUtils.trimStack(stack, Constants.TARGET_EVIL_METHOD_STACK, new TraceDataUtils.IStructuredDataFilter() {
                // 处理过程中需要被丢弃的条件
                @Override
                public boolean isFilter(long during, int filterCount) {
                    return during < filterCount * Constants.TIME_UPDATE_CYCLE_MS;
                }

                // 最多保留的item条数
                @Override
                public int getFilterMaxCount() {
                    return Constants.FILTER_STACK_MAX_COUNT;
                }

                // 最后处理完毕后,还是超过了maxCount,则调用此方法进行兜底
                @Override
                public void fallback(List<MethodItem> stack, int size) {
                    MatrixLog.w(TAG, "[fallback] size:%s targetSize:%s stack:%s", size, Constants.TARGET_EVIL_METHOD_STACK, stack);
                    Iterator iterator = stack.listIterator(Math.min(size, Constants.TARGET_EVIL_METHOD_STACK));
                    while (iterator.hasNext()) {
                        iterator.next();
                        iterator.remove();
                    }
                }
            });
        }


        StringBuilder reportBuilder = new StringBuilder();
        StringBuilder logcatBuilder = new StringBuilder();
        long stackCost = Math.max(cost, TraceDataUtils.stackToString(stack, reportBuilder, logcatBuilder));
        String stackKey = TraceDataUtils.getTreeKey(stack, stackCost);

        MatrixLog.w(TAG, "%s", printEvil(scene, processStat, isForeground, logcatBuilder, stack.size(), stackKey, usage, queueCost[0], queueCost[1], queueCost[2], cost)); // for logcat

        // report
        try {
            ...
        } catch (JSONException e) {
            MatrixLog.e(TAG, "[JSONException error: %s", e);
        }

    }

    @Override
    public void run() {
        analyse();
    }

    ...
}

AnalyseTask中比较耗脑的就是原始数据sBuffer如何进行整合以及裁剪,如何生成能够代表卡顿的key,方便进行聚合。这部分在Matrix-Wiki中也有一点介绍。摘抄如下:

堆栈聚类问题: 如果将收集的原始数据进行上报,数据量很大而且后台很难聚类有问题的堆栈,所以在上报之前需要对采集的数据进行简单的整合及裁剪,并分析出一个能代表卡顿堆栈的 key,方便后台聚合。

通过遍历采集的 buffer ,相邻 i 与 o 为一次完整函数执行,计算出一个调用树及每个函数执行耗时,并对每一级中的一些相同执行函数做聚合,最后通过一个简单策略,分析出主要耗时的那一级函数,作为代表卡顿堆栈的key

image.png

image.png 上文讲述了在编译期,会对每个方法的执行体前后添加上MethodBeat.i(int methodId)和MethodBeat.o(int methodId)的方法调用,且methodId是在编译期生成的,在运行时是一个写死的常量。通过编译期的这个操作,就能感知到具体每个方法的进入、退出动作。下面来看下这两个方法的内部实现。

/**
     * hook method when it's called in.
     *
     * @param methodId
     */
    public static void i(int methodId) {
        if (isBackground) {
            return;
        }
        ...
        isRealTrace = true;
        if (isCreated && Thread.currentThread() == sMainThread) {
           ...
        } else if (!isCreated && Thread.currentThread() == sMainThread && sBuffer != null) {
           ..
        }
    }

    /**
     * hook method when it's called out.
     *
     * @param methodId
     */
    public static void o(int methodId) {
        if (isBackground || null == sBuffer) {
            return;
        }
        if (isCreated && Thread.currentThread() == sMainThread) {
            ...
        } else if (!isCreated && Thread.currentThread() == sMainThread) {
            ...
        }
    }

统计了当应用处于前台时,在主线程执行的方法的进入、退出。这些信息最后存储在MethodBeat的Buffer中。当主线程有疑似慢函数存在时,读取Buffer的数据,分析可能的慢函数,并上报json数据到后端(后端将methodId转换为具体的方法声明)。

疑似发生慢函数的实际有两个:一个是掉帧的场景,一个是类似ANR这样长时间主线程阻塞UI绘制的场景。

掉帧的场景

FrameTracer的实现依赖于UIThreadMonitor中抛出来的LooperObserver#doFrame回调。该回调的方法声明如下:

public void doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCostNs, long animationCostNs, long traversalCostNs)

各个参数解释如下:

  • focusedActivityName

正在显示的Activity名称

  • start

Message执行前的时间

  • end

Message执行完毕,调用LooperObserver#doFrame时的时间

  • frameCostMs

如果调用执行dispatchEnd时,UIThreadMonitor#run执行过了,那么该值为上面的end-start的值;否则为0

  • inputCostNs、animationCostNs、traversalCostNs

执行三种CallbackQueue的耗时

下面我们看看FrameTracer是如何通过这些值计算出帧率信息的,直接看override的doFrame方法:

@Override
public void doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCostNs, long animationCostNs, long traversalCostNs) {
    if (isForeground()) {
        notifyListener(focusedActivityName, end - start, frameCostMs, frameCostMs >= 0);
    }
}

private void notifyListener(final String visibleScene, final long taskCostMs, final long frameCostMs, final boolean isContainsFrame) {
    long start = System.currentTimeMillis();
    try {
        synchronized (listeners) {
            for (final IDoFrameListener listener : listeners) {
                if (config.isDevEnv()) {
                    listener.time = SystemClock.uptimeMillis();
                }
                final int dropFrame = (int) (taskCostMs / frameIntervalMs);

                listener.doFrameSync(visibleScene, taskCostMs, frameCostMs, dropFrame, isContainsFrame);
                if (null != listener.getExecutor()) {
                    listener.getExecutor().execute(new Runnable() {
                        @Override
                        public void run() {
                            listener.doFrameAsync(visibleScene, taskCostMs, frameCostMs, dropFrame, isContainsFrame);
                        }
                    });
                }
                if (config.isDevEnv()) {
                    listener.time = SystemClock.uptimeMillis() - listener.time;
                    MatrixLog.d(TAG, "[notifyListener] cost:%sms listener:%s", listener.time, listener);
                }
            }
        }
    } finally {
        long cost = System.currentTimeMillis() - start;
        if (config.isDebug() && cost > frameIntervalMs) {
            MatrixLog.w(TAG, "[notifyListener] warm! maybe do heavy work in doFrameSync! size:%s cost:%sms", listeners.size(), cost);
        }
    }
}

在FrameTracer#doFrame中会在App处于 前台 的状态下调用notifyListener方法,注意这里的taskCostMs参数值为end-start,实际上这个参数的值应该与frameCostMs的值一致。 在notifyListener方法中,首先通过taskCostMs / frameIntervalMs来计算此次执行丢的帧数,记为dropFrame。也就是说单次Message的执行耗时不超过16ms,则不会产生丢帧。最后调用IDoFrameListener#doFrameSync以及IDoFrameListener#doFrameAsync执行lisetner的同步方法以及异步方法。

在有了上面计算出来的dropFrame之后,我们在后面就不太需要taskCostMs以及frameCostMs这两个值了。我们把注意力放到其他几个参数中去,有了这几个参数(visibleScene、dropFrame、isContainsFrame),后面就可以进行帧率的上报以及实时帧率的显示。

先看看帧率上报的部分代码。在FrameTracer构造的时候,Matrix向其中添加了一个FPSCollector这个实现了IDoFrameListener接口的类,用来进行帧率的收集以及上报。

private class FPSCollector extends IDoFrameListener {

    private Handler frameHandler = new Handler(MatrixHandlerThread.getDefaultHandlerThread().getLooper());

    Executor executor = new Executor() {
        @Override
        public void execute(Runnable command) {
            frameHandler.post(command);
        }
    };

    private HashMap<String, FrameCollectItem> map = new HashMap<>();

    @Override
    public Executor getExecutor() {
        return executor;
    }

    @Override
    public void doFrameAsync(String visibleScene, long taskCost, long frameCostMs, int droppedFrames, boolean isContainsFrame) {
        super.doFrameAsync(visibleScene, taskCost, frameCostMs, droppedFrames, isContainsFrame);
        if (Utils.isEmpty(visibleScene)) {
            return;
        }

        FrameCollectItem item = map.get(visibleScene);
        if (null == item) {
            item = new FrameCollectItem(visibleScene);
            map.put(visibleScene, item);
        }

        item.collect(droppedFrames, isContainsFrame);

        if (item.sumFrameCost >= timeSliceMs) { // report
            map.remove(visibleScene);
            item.report();
        }
    }
}

FPSCollector以页面为key,记录每个页面的帧情况。首先调用FrameCollectItem.collect收集帧率信息。然后当页面累计事件sumFrameCost超过一定阈值(默认10s)时,进行上报。

然后我们看看重点的FrameCollectItem#collect方法:

void collect(int droppedFrames, boolean isContainsFrame) {
    long frameIntervalCost = UIThreadMonitor.getMonitor().getFrameIntervalNanos();
    sumFrameCost += (droppedFrames + 1) * frameIntervalCost / Constants.TIME_MILLIS_TO_NANO;
    sumDroppedFrames += droppedFrames;
    sumFrame++;
    if (!isContainsFrame) {
        sumTaskFrame++;
    }

    if (droppedFrames >= frozenThreshold) {
        dropLevel[DropStatus.DROPPED_FROZEN.index]++;
        dropSum[DropStatus.DROPPED_FROZEN.index] += droppedFrames;
    } else if (droppedFrames >= highThreshold) {
        dropLevel[DropStatus.DROPPED_HIGH.index]++;
        dropSum[DropStatus.DROPPED_HIGH.index] += droppedFrames;
    } else if (droppedFrames >= middleThreshold) {
        dropLevel[DropStatus.DROPPED_MIDDLE.index]++;
        dropSum[DropStatus.DROPPED_MIDDLE.index] += droppedFrames;
    } else if (droppedFrames >= normalThreshold) {
        dropLevel[DropStatus.DROPPED_NORMAL.index]++;
        dropSum[DropStatus.DROPPED_NORMAL.index] += droppedFrames;
    } else {
        dropLevel[DropStatus.DROPPED_BEST.index]++;
        dropSum[DropStatus.DROPPED_BEST.index] += (droppedFrames < 0 ? 0 : droppedFrames);
    }
}

sumFrameCost记录的是累计的帧耗时。sumDroppedFrames记录的是累计丢帧数。sumFrame是累计帧数。在记录这些数之后,按照丢帧的数值,记录到对应的丢帧状态数组中。在记录完毕之后,会在适当的时间被调用report方法进行上报,上报的代码就不是重点了。

matrix-trace-canary中有一个FrameDecorator的类,可以悬浮窗展示实时帧率,开箱即用,无需自己写逻辑。其底层实现与FrameTracer类似。

内部FrameBeat类实现了Choreographer.FrameCallback,可以感知每一帧的绘制时间。通过前后两帧的时间差判断是否有慢函数发生。

  @Override
    public void doFrame(long lastFrameNanos, long frameNanos) {
        if (isIgnoreFrame) {
            mActivityCreatedInfoMap.clear();
            setIgnoreFrame(false);
            getMethodBeat().resetIndex();
            return;
        }

        int index = getMethodBeat().getCurIndex();
        //判断是否有慢函数
        if (hasEntered && frameNanos - lastFrameNanos > mTraceConfig.getEvilThresholdNano()) {
            MatrixLog.e(TAG, "[doFrame] dropped frame too much! lastIndex:%s index:%s", 0, index);
            handleBuffer(Type.NORMAL, 0, index - 1, getMethodBeat().getBuffer(), (frameNanos - lastFrameNanos) / Constants.TIME_MILLIS_TO_NANO);
        }
        getMethodBeat().resetIndex();
        mLazyScheduler.cancel();
        mLazyScheduler.setUp(this, false);

    }

主线程长时间阻塞UI绘制的场景

在ANR监控中,若发生了ANR,则需要解析这段时间内的调用堆栈。这部分逻辑与上面慢方法监控EvilMethodTracer基本一致。

下面考虑ANR如何进行判定。我们在Message执行开始时抛出一个定时任务,若该任务执行到了,则可以认为发生了ANR。若该任务在Message执行完毕之后被主动清除了,则说明没有ANR发生。这种思想与系统ANR的判定有相似之处。

@Override
public void dispatchBegin(long beginMs, long cpuBeginMs, long token) {
    super.dispatchBegin(beginMs, cpuBeginMs, token);
    anrTask = new AnrHandleTask(AppMethodBeat.getInstance().maskIndex("AnrTracer#dispatchBegin"), token);
    if (traceConfig.isDevEnv()) {
        MatrixLog.v(TAG, "* [dispatchBegin] token:%s index:%s", token, anrTask.beginRecord.index);
    }
    // 抛炸弹
    anrHandler.postDelayed(anrTask, Constants.DEFAULT_ANR - (SystemClock.uptimeMillis() - token));
}

@Override
public void doFrame(String focusedActivityName, long start, long end, long frameCostMs, long inputCost, long animationCost, long traversalCost) {
    if (traceConfig.isDevEnv()) {
        MatrixLog.v(TAG, "--> [doFrame] activityName:%s frameCost:%sms [%s:%s:%s]ns", focusedActivityName, frameCostMs, inputCost, animationCost, traversalCost);
    }
}

@Override
public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
    super.dispatchEnd(beginMs, cpuBeginMs, endMs, cpuEndMs, token, isBelongFrame);
    if (traceConfig.isDevEnv()) {
        MatrixLog.v(TAG, "[dispatchEnd] token:%s cost:%sms cpu:%sms usage:%s",
                token, endMs - beginMs, cpuEndMs - cpuBeginMs, Utils.calculateCpuUsage(cpuEndMs - cpuBeginMs, endMs - beginMs));
    }
    // 拆炸弹
    if (null != anrTask) {
        anrTask.getBeginRecord().release();
        anrHandler.removeCallbacks(anrTask);
    }
}

LazyScheduler内有一个HandlerThread,调用LazyScheduler.setup方法会向这个HandlerThread的MQ发送一个延时5s的消息。若没有发生类似ANR的场景,在每一帧的doFrame回调中取消这个消息,同时发送一个新的延时5s的消息(正常情况下消息是得不到执行的);若发生类似ANR的情况,doFrame没有被回调,这个延时5s的消息得到执行,将回调到onTimeExpire方法

  @Override
    public void onTimeExpire() {
        // maybe ANR
        if (isBackground()) {
            MatrixLog.w(TAG, "[onTimeExpire] pass this time, on Background!");
            return;
        }
        long happenedAnrTime = getMethodBeat().getCurrentDiffTime();
        MatrixLog.w(TAG, "[onTimeExpire] maybe ANR!");
        setIgnoreFrame(true);
        getMethodBeat().lockBuffer(false);
        //有慢函数
        handleBuffer(Type.ANR, 0, getMethodBeat().getCurIndex() - 1, getMethodBeat().getBuffer(), null, Constants.DEFAULT_ANR, happenedAnrTime, -1);
    }

当检测到慢函数时,会在后台线程完成慢函数的分析

 private final class AnalyseTask implements Runnable {

        private final long[] buffer;
        private final AnalyseExtraInfo analyseExtraInfo;

        private AnalyseTask(long[] buffer, AnalyseExtraInfo analyseExtraInfo) {
            this.buffer = buffer;
            this.analyseExtraInfo = analyseExtraInfo;
        }

        private long getTime(long trueId) {
            return trueId & 0x7FFFFFFFFFFL;
        }

        private int getMethodId(long trueId) {
            return (int) ((trueId >> 43) & 0xFFFFFL);
        }

        private boolean isIn(long trueId) {
            return ((trueId >> 63) & 0x1) == 1;
        }

        @Override
        public void run() {
            analyse(buffer);
        }

        private void analyse(long[] buffer) {
            ...
            //分析逻辑主要是找出最耗时的方法,可自行阅读

}

FPS检测

目的:检测绘制过程中的FPS数量。

获取DectorView的ViewTreeObserver,感知UI绘制的开始

    private void addDrawListener(final Activity activity) {
        activity.getWindow().getDecorView().post(new Runnable() {
            @Override
            public void run() {
                activity.getWindow().getDecorView().getViewTreeObserver().removeOnDrawListener(FPSTracer.this);
                activity.getWindow().getDecorView().getViewTreeObserver().addOnDrawListener(FPSTracer.this);
            }
        });
    }
    
      @Override
    public void onDraw() {
        isDrawing = true;
    }

通过Choreographer.FrameCallback,感知UI绘制的结束

  @Override
    public void doFrame(long lastFrameNanos, long frameNanos) {
        if (!isInvalid && isDrawing && isEnterAnimationComplete() && mTraceConfig.isTargetScene(getScene())) {
            handleDoFrame(lastFrameNanos, frameNanos, getScene());
        }
        isDrawing = false;
    }

理论上用户更关心的是绘制过程中FPS过低导致的卡顿(UI静止的情况下,用户是感知不到FPS低的)

在doFrame方法中,记录每一帧的数据,其中scene这个字段标识一个页面

@Override
public void onChange(final Activity activity, final Fragment fragment) {
    this.mScene = TraceConfig.getSceneForString(activity, fragment);
}

onChange的默认实现是通过Application的ActivityLifecycleCallbacks回调感知Activity的变化

@Override
public void onActivityResumed(final Activity activity) {
    ...
    if (!activityHash.equals(mCurActivityHash)) {
        for (IObserver listener : mObservers) {
            listener.onChange(activity, null);
        }
        mCurActivityHash = activityHash;
    }
    ...
}

FPS数据默认是2分钟分析一次(前台情况下),切后台时后台轮询线程停止。

/**
 * report FPS
 */
private void doReport() {
    ...
    //数据分析逻辑可行阅读
}

卡顿检测

目的:检测UI绘制过程中的卡顿情况。

卡顿检测与FPS检测类似,在每一帧的`doFrame回调中判断是否有卡顿发生,如有卡顿将数据发送到后台分析线程处理。

@Override
public void doFrame(final long lastFrameNanos, final long frameNanos) {
    if (!isDrawing) {
        return;
    }
    isDrawing = false;
    final int droppedCount = (int) ((frameNanos - lastFrameNanos) / REFRESH_RATE_MS);
    if (droppedCount > 1) {
        for (final IDoFrameListener listener : mDoFrameListenerList) {
            listener.doFrameSync(lastFrameNanos, frameNanos, getScene(), droppedCount);
            if (null != listener.getHandler()) {
                listener.getHandler().post(new Runnable() {
                    @Override
                    public void run() {
                        listener.getHandler().post(new AsyncDoFrameTask(listener,
                                lastFrameNanos, frameNanos, getScene(), droppedCount));
                    }
                });

            }
        }

启动检测

目的:检测启动阶段耗时

firstMethod.i       LAUNCH_ACTIVITY   onWindowFocusChange   LAUNCH_ACTIVITY    onWindowFocusChange
^                         ^                   ^                     ^                  ^
|                         |                   |                     |                  |
|---------app---------|---|---firstActivity---|---------...---------|---careActivity---|
|<--applicationCost-->|
|<--------------firstScreenCost-------------->|
|<---------------------------------------coldCost------------------------------------->|
.                         |<-----warmCost---->|

之前插件在编译器为 Activity#onWindowFocusChanged 织入 AppMethodBeat.at 方法,这样可以获取每个 Activity 的 onWindowFocusChanged 回调时间。 然后在第一个 AppMethodBeat.i 方法调用时,记录此时的时间作为进程 zygote 后的时间;hook ActivityThread 中的 mH 中的 Callback ,通过检查第一个 Activity 或 Service 或 Receiver 的 what,以此时的时间作为 Application 创建结束时间,该时间与上面的时间之差记为 Application创建耗时。 在第一个 Activity 的 onWindowFocusChange 回调时,此时的时间减去 zygote 时间即为 首屏启动耗时 ; 第二个 Activity 的 onWindowFocusChange 回调时,时间减去 zygote 的时间即为 整个冷启动的时间。

我们顺着上面的这个线理一下代码,首先是AppMethBeat.i方法里面的相关代码。

public static void i(int methodId) {

    if (status <= STATUS_STOPPED) {
        return;
    }
    if (methodId >= METHOD_ID_MAX) {
        return;
    }

    if (status == STATUS_DEFAULT) {
        synchronized (statusLock) {
            if (status == STATUS_DEFAULT) {
                realExecute();
                status = STATUS_READY;
            }
        }
    }
    ...
}

status默认状态是STATUS_DEFAULT,因此第一次执行AppMethodBeat#i方法肯定会执行到realExecute()方法,这里面相当于就是初始化AppMethodBeat以及执行其他的一些操作了。

private static void realExecute() {
    MatrixLog.i(TAG, "[realExecute] timestamp:%s", System.currentTimeMillis());

    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;

    sHandler.removeCallbacksAndMessages(null);
    sHandler.postDelayed(sUpdateDiffTimeRunnable, Constants.TIME_UPDATE_CYCLE_MS);
    sHandler.postDelayed(checkStartExpiredRunnable = new Runnable() {
        @Override
        public void run() {
            synchronized (statusLock) {
                MatrixLog.i(TAG, "[startExpired] timestamp:%s status:%s", System.currentTimeMillis(), status);
                if (status == STATUS_DEFAULT || status == STATUS_READY) {
                    status = STATUS_EXPIRED_START;
                }
            }
        }
    }, Constants.DEFAULT_RELEASE_BUFFER_DELAY);

    // hook mH,为StartUpTracer提供支持
    ActivityThreadHacker.hackSysHandlerCallback();
    LooperMonitor.register(looperMonitorListener);
}

我们关注一下ActivityThreadHacker.hackSysHandlerCallback()这个方法,这里面 hook 了 mH 的 mCallback,这样可以 Application 初始化结束的时间。

public class ActivityThreadHacker {
    private static final String TAG = "Matrix.ActivityThreadHacker";
    // 进程启动的时间
    private static long sApplicationCreateBeginTime = 0L;
    // 四大组件首次执行到的时间
    private static long sApplicationCreateEndTime = 0L;
    // Activity最后一次launch的时间
    private static long sLastLaunchActivityTime = 0L;
    public static AppMethodBeat.IndexRecord sLastLaunchActivityMethodIndex = new AppMethodBeat.IndexRecord();
    public static AppMethodBeat.IndexRecord sApplicationCreateBeginMethodIndex = new AppMethodBeat.IndexRecord();
    public static int sApplicationCreateScene = -100;

    public static void hackSysHandlerCallback() {
        try {
            sApplicationCreateBeginTime = SystemClock.uptimeMillis();
            sApplicationCreateBeginMethodIndex = AppMethodBeat.getInstance().maskIndex("ApplicationCreateBeginMethodIndex");
            Class<?> forName = Class.forName("android.app.ActivityThread");
            Field field = forName.getDeclaredField("sCurrentActivityThread");
            field.setAccessible(true);
            Object activityThreadValue = field.get(forName);
            Field mH = forName.getDeclaredField("mH");
            mH.setAccessible(true);
            Object handler = mH.get(activityThreadValue);
            Class<?> handlerClass = handler.getClass().getSuperclass();
            Field callbackField = handlerClass.getDeclaredField("mCallback");
            callbackField.setAccessible(true);
            Handler.Callback originalCallback = (Handler.Callback) callbackField.get(handler);
            HackCallback callback = new HackCallback(originalCallback);
            callbackField.set(handler, callback);
            MatrixLog.i(TAG, "hook system handler completed. start:%s SDK_INT:%s", sApplicationCreateBeginTime, Build.VERSION.SDK_INT);
        } catch (Exception e) {
            MatrixLog.e(TAG, "hook system handler err! %s", e.getCause().toString());
        }
    }

    public static long getApplicationCost() {
        return ActivityThreadHacker.sApplicationCreateEndTime - ActivityThreadHacker.sApplicationCreateBeginTime;
    }

    public static long getEggBrokenTime() {
        return ActivityThreadHacker.sApplicationCreateBeginTime;
    }

    public static long getLastLaunchActivityTime() {
        return ActivityThreadHacker.sLastLaunchActivityTime;
    }


    private final static class HackCallback implements Handler.Callback {
        private static final int LAUNCH_ACTIVITY = 100;
        private static final int CREATE_SERVICE = 114;
        private static final int RECEIVER = 113;
        public static final int EXECUTE_TRANSACTION = 159; // for Android 9.0
        private static boolean isCreated = false;
        private static int hasPrint = 10;

        private final Handler.Callback mOriginalCallback;

        HackCallback(Handler.Callback callback) {
            this.mOriginalCallback = callback;
        }

        @Override
        public boolean handleMessage(Message msg) {

            if (!AppMethodBeat.isRealTrace()) {
                return null != mOriginalCallback && mOriginalCallback.handleMessage(msg);
            }

            boolean isLaunchActivity = isLaunchActivity(msg);
            if (hasPrint > 0) {
                MatrixLog.i(TAG, "[handleMessage] msg.what:%s begin:%s isLaunchActivity:%s", msg.what, SystemClock.uptimeMillis(), isLaunchActivity);
                hasPrint--;
            }
            if (isLaunchActivity) {
                ActivityThreadHacker.sLastLaunchActivityTime = SystemClock.uptimeMillis();
                ActivityThreadHacker.sLastLaunchActivityMethodIndex = AppMethodBeat.getInstance().maskIndex("LastLaunchActivityMethodIndex");
            }

            if (!isCreated) {
                if (isLaunchActivity || msg.what == CREATE_SERVICE || msg.what == RECEIVER) { // todo for provider
                    ActivityThreadHacker.sApplicationCreateEndTime = SystemClock.uptimeMillis();
                    ActivityThreadHacker.sApplicationCreateScene = msg.what;
                    isCreated = true;
                }
            }

            return null != mOriginalCallback && mOriginalCallback.handleMessage(msg);
        }

        private Method method = null;

        private boolean isLaunchActivity(Message msg) {
            if (Build.VERSION.SDK_INT > Build.VERSION_CODES.O_MR1) {
                if (msg.what == EXECUTE_TRANSACTION && msg.obj != null) {
                    try {
                        if (null == method) {
                            Class clazz = Class.forName("android.app.servertransaction.ClientTransaction");
                            method = clazz.getDeclaredMethod("getCallbacks");
                            method.setAccessible(true);
                        }
                        List list = (List) method.invoke(msg.obj);
                        if (!list.isEmpty()) {
                            return list.get(0).getClass().getName().endsWith(".LaunchActivityItem");
                        }
                    } catch (Exception e) {
                        MatrixLog.e(TAG, "[isLaunchActivity] %s", e);
                    }
                }
                return msg.what == LAUNCH_ACTIVITY;
            } else {
                return msg.what == LAUNCH_ACTIVITY;
            }
        }
    }
}

上面这个类里面的代码比较简单,没有过度分析的必要。有关StartUpTracer相关的代码都用高亮标注了一下。在计算出Application初始化的起始时间点后,我们继续看看StartUpTracer#onActivityFocused里面的代码:

@Override
public void onActivityFocused(String activity) {
    // 若coldCost为初始值0,则说明这段代码从来没有运行过,那么认为是冷启动
    if (isColdStartup()) {
        // 若firstScreenCost为初始值0,则说明这是第一个获取焦点的Activity,记录时间差为首屏启动耗时
        if (firstScreenCost == 0) {
            this.firstScreenCost = uptimeMillis() - ActivityThreadHacker.getEggBrokenTime();
        }
        // 若已经展示过了首屏Activity,则此Activity是真正的MainActivity,记录此时时间差为冷启动耗时
        if (hasShowSplashActivity) {
            coldCost = uptimeMillis() - ActivityThreadHacker.getEggBrokenTime();
        } else {
            // 若还没有展示过首屏Activity
            if (splashActivities.contains(activity)) {
                // 且声明的首屏Activity列表中包含此Activity,则设置标志位
                hasShowSplashActivity = true;
            } else if (splashActivities.isEmpty()) {
                // 声明的首屏Activity列表为空,则整个冷启动耗时就为首屏启动耗时
                MatrixLog.i(TAG, "default splash activity[%s]", activity);
                coldCost = firstScreenCost;
            } else {
                MatrixLog.w(TAG, "pass this activity[%s] at duration of start up! splashActivities=%s", activity, splashActivities);
            }
        }
        // 分析冷启动耗时
        if (coldCost > 0) {
            analyse(ActivityThreadHacker.getApplicationCost(), firstScreenCost, coldCost, false);
        }

    } else if (isWarmStartUp()) {
        // 是否是温启动,这里isWarmStartUp标志位还依赖于监听ActivityLifecycleCallbacks,这里代码没有贴出来
        // 温启动时间是当前时间减去最后一次 launch Activity 的时间
        isWarmStartUp = false;
        long warmCost = uptimeMillis() - ActivityThreadHacker.getLastLaunchActivityTime();
        if (warmCost > 0) {
            analyse(ActivityThreadHacker.getApplicationCost(), firstScreenCost, warmCost, true);
        }
    }

}

private boolean isColdStartup() {
    return coldCost == 0;
}

private boolean isWarmStartUp() {
    return isWarmStartUp;
}

至于analyse这个分析上报逻辑里面的部分,就是启动时间达到了阈值,则复制出函数调用堆栈并且分析的过程。

应用启动时,会直接对ActivityThread类hook

public class Hacker {
    private static final String TAG = "Matrix.Hacker";
    public static boolean isEnterAnimationComplete = false;
    public static long sApplicationCreateBeginTime = 0L;
    public static int sApplicationCreateBeginMethodIndex = 0;
    public static long sApplicationCreateEndTime = 0L;
    public static int sApplicationCreateEndMethodIndex = 0;
    public static int sApplicationCreateScene = -100;

    public static void hackSysHandlerCallback() {
        try {
            //这个类被加载的时间,认为是整个App的启动开始时间
            sApplicationCreateBeginTime = System.currentTimeMillis();
            sApplicationCreateBeginMethodIndex = MethodBeat.getCurIndex();
            Class<?> forName = Class.forName("android.app.ActivityThread");
            Field field = forName.getDeclaredField("sCurrentActivityThread");
            field.setAccessible(true);
            Object activityThreadValue = field.get(forName);
            Field mH = forName.getDeclaredField("mH");
            mH.setAccessible(true);
            Object handler = mH.get(activityThreadValue);
            Class<?> handlerClass = handler.getClass().getSuperclass();
            Field callbackField = handlerClass.getDeclaredField("mCallback");
            callbackField.setAccessible(true);
            Handler.Callback originalCallback = (Handler.Callback) callbackField.get(handler);
            HackCallback callback = new HackCallback(originalCallback);
            callbackField.set(handler, callback);
            MatrixLog.i(TAG, "hook system handler completed. start:%s", sApplicationCreateBeginTime);
        } catch (Exception e) {
            MatrixLog.e(TAG, "hook system handler err! %s", e.getCause().toString());
        }
    }
}

代理原有的Handler.Callback,感知Application onCreate的结束时间

public class HackCallback implements Handler.Callback {
    private static final String TAG = "Matrix.HackCallback";
    private static final int LAUNCH_ACTIVITY = 100;
    private static final int ENTER_ANIMATION_COMPLETE = 149;
    private static final int CREATE_SERVICE = 114;
    private static final int RECEIVER = 113;
    private static boolean isCreated = false;

    private final Handler.Callback mOriginalCallback;

    public HackCallback(Handler.Callback callback) {
        this.mOriginalCallback = callback;
    }

    @Override
    public boolean handleMessage(Message msg) {
//        MatrixLog.i(TAG, "[handleMessage] msg.what:%s begin:%s", msg.what, System.currentTimeMillis());
        if (msg.what == LAUNCH_ACTIVITY) {
            Hacker.isEnterAnimationComplete = false;
        } else if (msg.what == ENTER_ANIMATION_COMPLETE) {
            Hacker.isEnterAnimationComplete = true;
        }
        if (!isCreated) {
            if (msg.what == LAUNCH_ACTIVITY || msg.what == CREATE_SERVICE || msg.what == RECEIVER) {
                //发送启动Activity等消息,认为是Application onCreate的结束时间
                Hacker.sApplicationCreateEndTime = System.currentTimeMillis();
                Hacker.sApplicationCreateEndMethodIndex = MethodBeat.getCurIndex();
                Hacker.sApplicationCreateScene = msg.what;
                isCreated = true;
            }
        }
        if (null == mOriginalCallback) {
            return false;
        }
        return mOriginalCallback.handleMessage(msg);
    }
}

记录第一个Activity的onCreate时间

 @Override
    public void onActivityCreated(Activity activity) {
        super.onActivityCreated(activity);
        if (isFirstActivityCreate && mFirstActivityMap.isEmpty()) {
            String activityName = activity.getComponentName().getClassName();
            mFirstActivityIndex = getMethodBeat().getCurIndex();
            mFirstActivityName = activityName;
            mFirstActivityMap.put(activityName, System.currentTimeMillis());
            MatrixLog.i(TAG, "[onActivityCreated] first activity:%s index:%s", mFirstActivityName, mFirstActivityIndex);
            getMethodBeat().lockBuffer(true);
        }
    }

记录Activity获取焦点的时间(在编译期,在Activity子类的onWindowFocusChange方法中插入MethodBeat.at方法)

 public static void at(Activity activity, boolean isFocus) {
        MatrixLog.i(TAG, "[AT] activity: %s, isCreated: %b sListener size: %d,isFocus: %b",
                activity.getClass().getSimpleName(), isCreated, sListeners.size(), isFocus);
        if (isCreated && Thread.currentThread() == sMainThread) {
            for (IMethodBeatListener listener : sListeners) {
                listener.onActivityEntered(activity, isFocus, sIndex - 1, sBuffer);
            }
        }
    }

当Activity获取到焦点时,认为启动阶段结束(若有SplashActivity,则记录下一个Activity获取焦点的时间)

@Override
public void onActivityEntered(Activity activity, boolean isFocus, int nowIndex, long[] buffer) {
   ...启动数据分析
}