[Matrix系列-5]: AppMethodBeat 源码分析

1,126 阅读6分钟

之前的文章:

[Matrix系列-1]: matrix 启动流程源码解析

[Matrix系列-2]: TracePlugin 之 LooperAnrTrace源码分析

[Matrix系列-3]: TracePlugin 之 FrameTrace 源码分析

[Matrix系列-4]: TracePlugin 之 EvilMethodTracer 源码分析

背景

AppMethodBeat类是一个核心类,主要负责方法调用耗时的统计和存储、堆栈的获取等。 和 StartupTracer、LooperAnrTrace、EvilMethodTrace都有着密不可分的联系。

因此,很有必要去学习里面的逻辑。主要从初始化入口和提供的功能API入手。

一、初始化入口

1.1 realExecute()

该方法是在i()方法中触发的。肯定比onStart方法先走。为什么??

因为当应用的Application对象创建的时候会调用realExecute()。

Application的创建过程:

  1. ActivityThread.handleBindApplication->
  2. LoadApk.makeApplication->
  3. AppComponentFactory.instantiateApplication
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_READY
                status = STATUS_READY;
            }
        }
    }
    //省略...
 }

具体看realExecute()方法:

private static void realExecute() {
    MatrixLog.i(TAG, "[realExecute] timestamp:%s", System.currentTimeMillis());
    //1, 更新耗时偏移
    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
    //2,移除静态代码块中的第一次自毁task
    sHandler.removeCallbacksAndMessages(null);
    //3, 5ms 更新下时间戳。
    sHandler.postDelayed(sUpdateDiffTimeRunnable, Constants.TIME_UPDATE_CYCLE_MS);
    //4, 在第一个方法进入后的15s内如果app没有启用AppMethodBeat功能(也就是没有调用onStart方法,默认是true是启用的),那么我们就自己主动关闭,我愿意称之为第二次自毁task。
    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);
    //5, hook 系统的handlerCallback ,处理自己的逻辑
    ActivityThreadHacker.hackSysHandlerCallback();
    //6,注册looper的回调监听
    LooperMonitor.register(looperMonitorListener);
}
  • 总结: 做了6件事情:
  1. 更新耗时偏移量 sCurrentDiffTime
  2. 移除静态代码块中的第一次自毁task
  3. 5ms 更新耗时偏移量。
  4. 启动第二次自毁task
  5. hook 系统的handlerCallback
  6. 注册looper的回调监听

1.1.1 更新耗时偏移量 sCurrentDiffTime

sCurrentDiffTime 是用来干什么的呢??我们先看成员变量:

//偏移量
private volatile static long sCurrentDiffTime = SystemClock.uptimeMillis();
//sDiffTime 被赋值一次,后面不会变化。只需要通过在子线程中5s间隔,维护一个偏移量
private volatile static long sDiffTime = sCurrentDiffTime;

基本原理:

平时我们计算某个函数的耗时,就是在方法执行前后两次调用SystemClock.uptimeMillis(),计算差值即可。但是SystemClock.uptimeMillis()本身就存在耗时,matrix存在大量的计算耗时逻辑。如果直接调用势必会影响到调用链底层的方法耗时统计,造成误差。

因此,matrix做了如下优化: 通过维护基准计时变量sDiffTime(这个值是不会变的)。然后在通过开启一个子线程每隔5ms去更新这个值 sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime。所以,随着程序的运行,这个值会慢慢变大。

举个例子:

当某个方法A进入i方法时,我们存入sCurrentDiffTime值如:50ms。当A方法执行完毕时调用o方法,由于sCurrentDiffTime一直会被更新,此时为500ms。那么,我们直接做一次差值就知道A方法的耗时为: 450ms。这样虽然有5ms左右的误差,但是对于卡顿耗时来说并不影响。确实不错呀!

1.1.2 移除静态代码块中的第一次自毁task

我们先看静态代码块:


static {
    sHandler.postDelayed(new Runnable() {
        @Override
        public void run() {
            realRelease();
        }
        // 常量为15s
    }, Constants.DEFAULT_RELEASE_BUFFER_DELAY);
}

我们知道,静态代码块在类加载的时候就执行了,且执行一次。

private static void realRelease() {
    synchronized (statusLock) {
         // 15s后,如果还没方法进入则自我销毁吧
        if (status == STATUS_DEFAULT) {
            MatrixLog.i(TAG, "[realRelease] timestamp:%s", System.currentTimeMillis());
            sHandler.removeCallbacksAndMessages(null);
            //解绑
            LooperMonitor.unregister(looperMonitorListener);
            //停止更新线程
            sTimerUpdateThread.quit();
            //情况数组
            sBuffer = null;
            //修改状态为
            status = STATUS_OUT_RELEASE;
        }
    }
}

等待15后,如果还没有方法方法,就销毁资源。

因此,一旦我们进入realExecute方法就要先移除这个自毁task。

1.1.3 5ms 更新下偏移量。

上面已经分析了偏移量的更新原理。这里我们看sUpdateDiffTimeRunnable的具体代码:

/**
 * 更新时间
 * update time runnable
 */
private static Runnable sUpdateDiffTimeRunnable = new Runnable() {
    @Override
    public void run() {
        try {
            //死循环
            while (true) {
                while (!isPauseUpdateTime && status > STATUS_STOPPED) {
                    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
                    //5ms后在更新
                    SystemClock.sleep(Constants.TIME_UPDATE_CYCLE_MS);
                }
                //不需要更新时间偏移量,进入wait状态,不要浪费CPU。什么时候唤醒? 当消息分发主线或告诉你的时候!
                //进入等待状态:释放锁、释放CPU,等待其他线程唤醒
                synchronized (updateTimeLock) {
                    updateTimeLock.wait();
                }
            }
        } catch (Exception e) {
            MatrixLog.e(TAG, "" + e.toString());
        }
    }
};

通过死循环5ms去更新下耗时偏移量。但是!!并不是一直都在更新。当dispatcheEnd的时候就停止更新,为什么? 因为此时没有消息要处理,没必要更新浪费CPU资源。一旦有消息处理,则会开启isPauseUpdateTime标志,主线程会通过锁对象updateTimeLock来唤醒正在等待的更新线程。

private static void dispatchBegin() {
    //消息开始,更新偏移量
    sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
    //开始更新偏移量
    isPauseUpdateTime = false;
    //唤醒更新线程
    synchronized (updateTimeLock) {
        updateTimeLock.notify();
    }
}

private static void dispatchEnd() {
    //优秀啊,并不是时刻在更新时间戳的。
    isPauseUpdateTime = true;
}

暂停、开启更新的逻辑如上。

1.1.4 启动第二次自毁task

在第一个方法进入后的15s内如果app没有启用AppMethodBeat功能(也就是没有调用onStart方法,默认是true。是启用的),那么我们就自己主动关闭,我愿意称之为第二次自毁。

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);

1.1.5 hook 系统的handlerCallback

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();
        if (null != handlerClass) {
            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());
    }
}

主要工作:

  • 记录应用启动时间戳
  • 反射 ActivityThread类中的 mH handler变量。在反射mH中的mCallback对象。代理接管程序的所有handleMessage回调。
  • handleMessage中的第一个activity或者service或者receiver启动的时候,认为是application结束回调,记录结束时间戳。

具体内容可查看源码,比较简单。

1.1.6 注册looper的回调监听

通过监听消息处理的前后回调来控制耗时偏移量更新线程的开启和暂停。

1.2 onStart()

经过前面的分析,我们知道onStart方法是在tracePlugin的start方法中调用的:

>>>TracePlugin.java

public void start() {
    
    if (traceConfig.isAppMethodBeatEnable()) {
        AppMethodBeat.getInstance().onStart();
    } else {
        AppMethodBeat.getInstance().forceStop();
    }
}

onStart()方法:

@Override
public void onStart() {
    synchronized (statusLock) {
        if (status < STATUS_STARTED && status >= STATUS_EXPIRED_START) {
            //1,移除过期自毁程序!!
            sHandler.removeCallbacks(checkStartExpiredRunnable);
            if (sBuffer == null) {
                throw new RuntimeException(TAG + " sBuffer == null");
            }
            MatrixLog.i(TAG, "[onStart] preStatus:%s", status, Utils.getStack());
            //2, 修改状态
            status = STATUS_STARTED;
        } else {
            MatrixLog.w(TAG, "[onStart] current status:%s", status);
        }
    }
}
  1. 先移除第二次的自毁task
  2. 修改状态为STATUS_STARTED

至此,AppMethodBeat算是成功启动起来了。

二、功能API

2.1 i()方法

/**
 * hook method when it's called in.
 *
 * @param methodId
 */
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;
            }
        }
    }

    long threadId = Thread.currentThread().getId();
    if (sMethodEnterListener != null) {
        sMethodEnterListener.enter(methodId, threadId);
    }
    //主线程才会执行这个逻辑
    if (threadId == sMainThreadId) {
        if (assertIn) {
            android.util.Log.e(TAG, "ERROR!!! AppMethodBeat.i Recursive calls!!!");
            return;
        }
        assertIn = true;
        if (sIndex < Constants.BUFFER_SIZE) {
        //合并该方法调用信息为一个long数据
            mergeData(methodId, sIndex, true);
        } else {
        //index超过数组长度,则重新从0开始
            sIndex = 0;
            mergeData(methodId, sIndex, true);
        }
        //自增
        ++sIndex;
        assertIn = false;
    }
}

主要的工作是记录函数进入时候的方法id和耗时,封装为一个long数据存入到buffer数组中。然后index自增。

我们看下mergeData方法:

private static void mergeData(int methodId, int index, boolean isIn) {
    //前提: 消息分发前后都会调用到这里。传入的都是METHOD_ID_DISPATCH。作为一个消息消息帧。
    //在每个帧中间或者两帧之间的方法会被记录下来。
    if (methodId == AppMethodBeat.METHOD_ID_DISPATCH) {
        sCurrentDiffTime = SystemClock.uptimeMillis() - sDiffTime;
    }
    long trueId = 0L; //默认是out,方法结束标记。那么就是在long的高63位是0。
    if (isIn) { //如果是方法开始:,那么就是在long的高63位是1。
        trueId |= 1L << 63;   //共 1位
    }
    // 43~62位 是methodId的存储区间,共 20位
    trueId |= (long) methodId << 43;
    //0~42位 则是耗时存储的位置。 共 43位
    //& 0x7FFFFFFFFFFL ,得到是原值:sCurrentDiffTime。
    trueId |= sCurrentDiffTime & 0x7FFFFFFFFFFL;
    //把以上三个参数组成一个完整的long数据,存入下标中。
    sBuffer[index] = trueId;
    //标记链表数据为无效,
    checkPileup(index);
    // 上一次mergeData的下标, 整个数组长度是100万。
    sLastIndex = index;
}

总结:

  • isIn:true表示i方法,false是o方法 63位
  • methodId: 方法id,在编译期插桩分配的 43~62位
  • 耗时偏移量:sCurrentDiffTime 0~42位
  • 标记链表数据为无效

long的长度是8个字节,所以总共64位刚好存储一个方法的耗时信息。来个图片更形象(图片来自官方):

image.png

彩色部分表示一个long数据。灰色部分表示buffer数组。

2.1.1 checkPileup()方法

//避免重复堆积??是的!
private static void checkPileup(int index) {
    IndexRecord indexRecord = sIndexRecordHead;
    //遍历链表
    while (indexRecord != null) {
        if (indexRecord.index == index || (indexRecord.index == -1 && sLastIndex == Constants.BUFFER_SIZE - 1)) {
            //标记无效
            indexRecord.isValid = false;
            MatrixLog.w(TAG, "[checkPileup] %s", indexRecord.toString());
            //删除当前节点,更新头结点。继续遍历
            sIndexRecordHead = indexRecord = indexRecord.next;
        } else {
            //直到,不等则退出循环。至此,链表已经排除掉了旧数据。
            break;
        }
    }
}

总结: sIndexRecordHead代表链表的头结点。如果一直不获取链表中数据(也就是不发生卡顿),那么链表势必会变长,此时buffer数组中存储还是旧数据,当然此时数据也就没有用了。同时index当超过buffer的size后又会重新开始计数。所以当新的index下标处要插入新数据时候,必须要删除之前跟index绑定的链表节点,避免数据冗余。

2.2 o()方法

public static void o(int methodId) {
    if (status <= STATUS_STOPPED) {
        return;
    }
    if (methodId >= METHOD_ID_MAX) {
        return;
    }
    if (Thread.currentThread().getId() == sMainThreadId) {
        if (sIndex < Constants.BUFFER_SIZE) {
            mergeData(methodId, sIndex, false);
        } else {
            sIndex = 0;
            mergeData(methodId, sIndex, false);
        }
        ++sIndex;
    }
}

i方法逻辑,存入方法结束时的耗时信息。

2.3 at()方法

public static void at(Activity activity, boolean isFocus) {
    String activityName = activity.getClass().getName();
    if (isFocus) {
        if (sFocusActivitySet.add(activityName)) {
            synchronized (listeners) {
            //回调给startupTrace用来计算activity的启动耗时
                for (IAppMethodBeatListener listener : listeners) {
                    listener.onActivityFocused(activity);
                }
            }
            MatrixLog.i(TAG, "[at] visibleScene[%s] has %s focus!", getVisibleScene(), "attach");
        }
    } else {
        if (sFocusActivitySet.remove(activityName)) {
            MatrixLog.i(TAG, "[at] visibleScene[%s] has %s focus!", getVisibleScene(), "detach");
        }
    }
}

at()方法会在activity的onWindowFocusChange时候回调。

  • 维护一个activity列表,方便获取顶层activity名字
  • 回调给StartupTrace用来计算activity的启动耗时

2.4 IndexRecord 内部类

2.4.1 成员变量

public int index;
private IndexRecord next; //链表
public boolean isValid = true;
public String source;

从成员变量可以看出,这是一个链表结构的数据。

2.4.2 maskIndex()方法

public IndexRecord maskIndex(String source) {
    //链表为空,则新建一个节点。application调用的第一次肯定是null
    if (sIndexRecordHead == null) {
        //index是数组中的下标。
        sIndexRecordHead = new IndexRecord(sIndex - 1);
        sIndexRecordHead.source = source;
        return sIndexRecordHead;
    } else {
        IndexRecord indexRecord = new IndexRecord(sIndex - 1);
        indexRecord.source = source;
        IndexRecord record = sIndexRecordHead;
        IndexRecord last = null;
        while (record != null) {
            if (indexRecord.index <= record.index) {
                //last 为空条件:第一次循环
                if (null == last) {
                    // 新节点插到链表头部
                    IndexRecord tmp = sIndexRecordHead;
                    sIndexRecordHead = indexRecord;
                    indexRecord.next = tmp;
                } else {
                    // 把新节点插到last和 next节点的中间。
                    IndexRecord tmp = last.next;
                    last.next = indexRecord;
                    indexRecord.next = tmp;
                }
                return indexRecord;
            }
            //last保存的就是最后一个节点
            last = record;
            //遍历之前的链表节点,直到末尾
            record = record.next;
        }
        //新节点插入到链表末尾
        last.next = indexRecord;
        //返回新插入的节点
        return indexRecord;
    }
}

总结:

维护了一个链表结构,专门用来存储准备要(有可能不要,不发生卡顿就不需要获取了)获取堆栈的开始节点,绑定index。后面去获取堆栈的时候才知道开始节点(mask的节点)和结束节点(当前的index)。最后去数组中根据开始和结束的下标进行截取堆栈调用信息。

2.4.3 copyData()方法

public long[] copyData(IndexRecord startRecord) {
    // startRecord:之前标记的indexRecord。
    //endRecord: 当前indexRecord。
    return copyData(startRecord, new IndexRecord(sIndex - 1));
}

startRecord就是之前maskIndex()方法标记的节点。结束节点自然是跟当前index绑定的,且next节点为null。

private long[] copyData(IndexRecord startRecord, IndexRecord endRecord) {
    // 本质就是index--区间
    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);
            //正常逻辑。直接从buffer中拷贝堆栈段
            if (end > start) {
                length = end - start + 1;
                data = new long[length];
                System.arraycopy(sBuffer, start, data, 0, length);
            } else if (end < start) {// 超过buffer的size,后index重新计数导致
                length = 1 + end + (sBuffer.length - start);
                data = new long[length];
                //先获取start-->buffer末尾的数据
                System.arraycopy(sBuffer, start, data, 0, sBuffer.length - start);
                //再获取0-->end下标的数据
                System.arraycopy(sBuffer, 0, data, sBuffer.length - start, end + 1);
            }
            return data;
        }
        return data;
    } catch (OutOfMemoryError e) {
        MatrixLog.e(TAG, e.toString());
        return data;
    } finally {
        MatrixLog.i(TAG, "[copyData] [%s:%s] length:%s cost:%sms", Math.max(0, startRecord.index), endRecord.index, data.length, System.currentTimeMillis() - current);
    }
}

总结:

通过开始节点和结束节点,从buffer数组中获取调用链信息。注释比较详细~

三、总结

AppMethodBeat类,维护了方法耗时的统计和获取的核心逻辑,其中的一些设计如子线程更新耗时偏移量,避免获取时间戳本身的耗时就很巧妙~

matrix系列分析都是个人研究和学习,文中如有问题或者错误,还请指正,谢谢~