Matrix源码分析-TracePlugin(慢函数检测)

TracePlugin包含4个方向的检测: 慢函数检测、App启动和Activity启动、帧率检测、ANR检测

public class TracePlugin extends Plugin {
	// 1.慢函数检测
	private EvilMethodTracer evilMethodTracer;
    private StartupTracer startupTracer;
    private FrameTracer frameTracer;
    private AnrTracer anrTracer;
}

一、方法耗时数据采集

1.1 TracePlugin.start

@Override
public void start() {
    super.start();
    Runnable runnable = new Runnable() {
        @Override
        public void run() {
            if (!UIThreadMonitor.getMonitor().isInit()) {
                try {
                    UIThreadMonitor.getMonitor().init(traceConfig);
                } catch (java.lang.RuntimeException e) {
                    return;
                }
            }
            // 1.启动AMB
            AppMethodBeat.getInstance().onStart();
            ...
        }
    };
    if (Thread.currentThread() == Looper.getMainLooper().getThread()) {
        runnable.run();
    } else {
        MatrixHandlerThread.getDefaultMainHandler().post(runnable);
    }
}

1.2 AppMethodBeat.onStart

@Override
public void onStart() {
    synchronized (statusLock) {
    	// 1.如果没有启动或者启动已经过期, 则进行启动
        if (status < STATUS_STARTED && status >= STATUS_EXPIRED_START) {
            sHandler.removeCallbacks(checkStartExpiredRunnable);
            // 2.将标志位设置为启动状态
            status = STATUS_STARTED;
        } 
    }
}

1.3 AppMethodBeat.i

/**
 * 编译时期, 方法被调用时插入AppMethodBeat.i方法, 方法调用结束时插入AppMethodBeat.o方法
 */
public static void i(int methodId) {
    if (status <= STATUS_STOPPED) {
        return;
    }
    if (methodId >= METHOD_ID_MAX) {
        return;
    }
    // status默认为STATUS_DEFAULT, 第一次调用时会触发该方法
    if (status == STATUS_DEFAULT) {
        synchronized (statusLock) {
            if (status == STATUS_DEFAULT) {
            	// 
                realExecute();
                // realExecute()方法执行结束之后将status置为准备状态
                status = STATUS_READY;
            }
        }
    }
    long threadId = Thread.currentThread().getId();
    if (sMethodEnterListener != null) {
        sMethodEnterListener.enter(methodId, threadId);
    }
    if (threadId == sMainThreadId) {
        if (assertIn) {
            return;
        }
        assertIn = true;
        if (sIndex < Constants.BUFFER_SIZE) {
            mergeData(methodId, sIndex, true);
        } else {
            sIndex = 0;
            mergeData(methodId, sIndex, true);
        }
        ++sIndex;
        assertIn = false;
    }
}

1.4 AppMethodBeat.realExecute

// i()方法第一次被调用时会调用这个方法
private static void realExecute() {
	// 记录时间差
    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
	// 清空sHandler所有信息
    sHandler.removeCallbacksAndMessages(null);
    // 发送延迟消息, 5ms后执行sUpdateDiffTimeRunnable
    sHandler.postDelayed(sUpdateDiffTimeRunnable, Constants.TIME_UPDATE_CYCLE_MS);
    // 发送15ms的延迟消息, 这里结合i()中调用realExecute方法的上下文以及onStart方法中对status可知,
    // realExecute执行完之后会立即将status置为STATUS_READY状态, 并且在onStart中对status的
    // 状态进行判断, 并且将status置为STATUS_STARTED, 所以这里发送一个15ms的延迟消息用来等待
    // onStart的启动, 如果15ms之后onStart还没有被启动, 则将status置为STATUS_EXPIRED_START
    sHandler.postDelayed(checkStartExpiredRunnable = new Runnable() {
        @Override
        public void run() {
            synchronized (statusLock) {
                if (status == STATUS_DEFAULT || status == STATUS_READY) {
                    status = STATUS_EXPIRED_START;
                }
            }
        }
    }, Constants.DEFAULT_RELEASE_BUFFER_DELAY);
    ActivityThreadHacker.hackSysHandlerCallback();
    // 将Listener与Looper机制进行绑定, 监听looper事件的开始与结束
    LooperMonitor.register(looperMonitorListener);
}

1.5 AppMethodBeat.sUpdateDiffTimeRunnable

private static Runnable sUpdateDiffTimeRunnable = new Runnable() {
    @Override
    public void run() {
        while (true) {
            // 无限循环, 如果isPauseUpdateTime为false, 每隔5ms执行一次, 如果isPauseUpdateTime
            // 为true, 跳出while, 进入挂起状态
            while (!isPauseUpdateTime && status > STATUS_STOPPED) {
                // 每间隔5ms获取一次时间差
                sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
                SystemClock.sleep(Constants.TIME_UPDATE_CYCLE_MS);
            }
            synchronized (updateTimeLock) {
                updateTimeLock.wait();
            }
        }
    }
};

直接拷贝Matrix里面的原话:

考虑到每个方法执行前后都获取系统时间（System.nanoTime）会对性能影响比较大，而实际上，单个函数执行耗时小于 5ms 的情况，对卡顿来说不是主要原因，可以忽略不计，如果是多次调用的情况，则在它的父级方法中可以反映出来，所以为了减少对性能的影响，通过另一条更新时间的线程每 5ms 去更新一个时间变量，而每个方法执行前后只读取该变量来减少性能损耗。

备注: 以后有while(true)的相关需求时, 可以参考这段代码, 这里是对优化的优化, 将优化进行到底啊啊啊, 满足某个条件时, 进入无限循环, 不满足时就挂起, 这里就是借助Looper机制, 如果主线程的Looper正在处理消息, 则取消挂起进入无限循环, Looper没有处理消息时进入挂起状态, 监听的同时节省资源

1.6 AppMethodBeat.looperMonitorListener

private static LooperMonitor.LooperDispatchListener looperMonitorListener = new LooperMonitor.LooperDispatchListener() {
    @Override
    public boolean isValid() {
        return status >= STATUS_READY;
    }
    // Looper开始处理消息时回调该方法
    @Override
    public void dispatchStart() {
        super.dispatchStart();
        AppMethodBeat.dispatchBegin();
    }
    // Looper处理完消息回调该方法
    @Override
    public void dispatchEnd() {
        super.dispatchEnd();
        AppMethodBeat.dispatchEnd();
    }
};

1.7 AppMethodBeat.dispatchXXX

private static void dispatchBegin() {
    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
    isPauseUpdateTime = false;

    synchronized (updateTimeLock) {
        updateTimeLock.notify();
    }
}

private static void dispatchEnd() {
    isPauseUpdateTime = true;
}

  监听主线程的Looper, 保证主线程在空闲状态时停止更新sCurrentDiffTime, 从而减少资源的占用.

1.8 AppMethodBeat.mergeData

private static void mergeData(int methodId, int index, boolean isIn) {
    if (methodId == AppMethodBeat.METHOD_ID_DISPATCH) {
        sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
    }
    long trueId = 0L;
    if (isIn) {
    	// 如果是i(), 第64位标志为1, 反之如果是o(), 第64位为0
        trueId |= 1L << 63;
    }
    // 第44位 ~ 63位存储methodId
    trueId |= (long) methodId << 43;
    // 0 ~ 43位存储sCurrentDiffTime
    trueId |= sCurrentDiffTime & 0x7FFFFFFFFFFL;
    // 将存储了methodId, 方法i()/o(), sCurrentDiffTime的trueId存放到sBuffer中
    sBuffer[index] = trueId;
    checkPileup(index);
    sLastIndex = index;
}

看到这里时有两个疑惑:

• 1、sBuffer容量为1000000, 如果超过了这个容量应该怎么处理?
• 2、i()执行完成之后, 执行了++sIndex操作, 那么在调用o()时, sBuffer[index]要比i()里面执行的index大1, 慢函数分析时如何确认i()/o()

至此方法耗时采集完成, 接下来是对方法耗时进行分析

二、方法耗时分析

2.1 EvilMethodTracer.onAlive

@Override
public void onAlive() {
    super.onAlive();
    if (isEvilMethodTraceEnable) {
        UIThreadMonitor.getMonitor().addObserver(this);
    }
}

  添加主线程Looper的监听, 事件分发开始回调dispatchBegin, 事件分发结束回调dispatchEnd

2.2 EvilMethodTracer.dispatchBegin

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

2.4 AppMethodBeat.maskIndex

public IndexRecord maskIndex(String source) {
	...
    IndexRecord indexRecord = new IndexRecord(sIndex - 1);
}

关键点一: 构造IndexRecord时, 传入的参数为sIndex-1, i()执行完成之后, 有一个++sIndex操作, 这里传入sIndex-1与i()相对应

2.5 EvilMethodTracer.dispatchEnd

@Override
public void dispatchEnd(long beginMs, long cpuBeginMs, long endMs, long cpuEndMs, long token, boolean isBelongFrame) {
    super.dispatchEnd(beginMs, cpuBeginMs, endMs, cpuEndMs, token, isBelongFrame);
    MatrixLog.v(AppMethodBeat.TAG, "[EvilMethodTracer.dispatchEnd] indexRecord[%s]", indexRecord);
    long start = config.isDevEnv() ? System.currentTimeMillis() : 0;
    try {
        long dispatchCost = endMs - beginMs;
        // 对方法调用进行细化, 如果当前方法耗时 ≥ 700ms时, 才会去对方法进行分析
        if (dispatchCost >= evilThresholdMs) {
        	// 这里拷贝的就是i()与o()的时间差
            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);
        }
    }
}

2.6 AppMethodBeat.copyData

public long[] copyData(IndexRecord startRecord) {
    return copyData(startRecord, new IndexRecord(sIndex - 1));
}

private long[] copyData(IndexRecord startRecord, IndexRecord endRecord) {
    long current = System.currentTimeMillis();
    long[] data = new long[0];
    try {
    	if (startRecord.isValid && endRecord.isValid) {
            int length;
            int start = Math.max(0, startRecord.index);
            int end = Math.max(0, endRecord.index);
            if (end > start) {
                length = end - start + 1;
                data = new long[length];
                // 将sBuffer[]的startIndex~endIndex即i()、o()的时间差添加到data中
                System.arraycopy(sBuffer, start, data, 0, length);
            } else if (end < start) {
                length = 1 + end + (sBuffer.length - start);
                data = new long[length];
                System.arraycopy(sBuffer, start, data, 0, sBuffer.length - start);
                System.arraycopy(sBuffer, 0, data, sBuffer.length - start, end + 1);
            }
            return data;
        }
        return data;
    } catch (OutOfMemoryError e) {
    	// OOM是可以被捕获的.
        MatrixLog.e(TAG, e.toString());
        return data;
    } finally {
        MatrixLog.i(TAG, "[copyData] index[start:%s, end:%s] data[length:%s, 0:%d, 1:%d] cost:%sms", Math.max(0, startRecord.index), endRecord.index, data.length, data[0], data[1], System.currentTimeMillis() - current);
    }
}

  **关键点: **endRecord = new IndexRecord(sIndex-1), 对应o()方法结束时的sIndex++操作.

  oom是可以被捕获的, 但是其实实际上并没有太大的意义, 触发当前OOM的操作实际上只是压死骆驼的最后一根稻草, 并不代表这个操作是很耗内存的