BlockCanary 源码分析

前言

BlockCanary 是一个 Android 平台的一个非侵入式的性能监控组件，它可以检测主线程上的各种卡慢问题。下面从源码角度来分析下该库，本文版本基于 1.5 。

基本使用

使用方式就是下面的一行代码，BlockCanaryContext 有些属性可以自定义。

public class MyApplication extends Application {
    @Override
    public void onCreate() {
        BlockCanary.install(this, new BlockCanaryContext()).start();
    }
}

默认如果主线程卡顿超过 1 秒就会提示（可以通过 BlockCanaryContext 进行自定义），并把当前主线程的堆栈信息一并打印出来。

源码分析

先从 BlockCanary#install 开始

public static BlockCanary install(Context context, BlockCanaryContext blockCanaryContext) {
    BlockCanaryContext.init(context, blockCanaryContext); // 保存 context 以及 blockCanaryContext
    setEnabled(context, DisplayActivity.class, BlockCanaryContext.get().displayNotification()); // 设置 DisplayActivity 是否可用
    return get(); // 创建单例对象 BlockCanary 并返回
}
private static void setEnabled(Context context, final Class<?> componentClass, final boolean enabled) {
    final Context appContext = context.getApplicationContext();
    executeOnFileIoThread(new Runnable() { // 由于这里是 IPC 调用，会阻塞线程，因此在子线程中执行
        public void run() {
            setEnabledBlocking(appContext, componentClass, enabled);
        }
    });
}
private static void setEnabledBlocking(Context appContext, Class<?> componentClass, boolean enabled) {
    ComponentName component = new ComponentName(appContext, componentClass);
    PackageManager packageManager = appContext.getPackageManager();
    int newState = enabled ? COMPONENT_ENABLED_STATE_ENABLED : COMPONENT_ENABLED_STATE_DISABLED;
    // 通知 PMS 启用或者禁用 DisplayActivity
    packageManager.setComponentEnabledSetting(component, newState, DONT_KILL_APP);
}

install 方法其实就是创建一个 BlockCanary 实例返回，接下来看看 start 做了什么。

注：可以通过 PackageManager#setComponentEnabledSetting 来启用或者禁用组件，比如禁用启动 Activity 那么桌面上就不会显示图标。

public void start() {
    if (!mMonitorStarted) {
        mMonitorStarted = true;
        Looper.getMainLooper().setMessageLogging(mBlockCanaryCore.monitor);
    }
}

这里只是想主线程的 Looper 设置了一个 MessageLogging，根据前面 Handler 源码分析 Looper 每次从消息队列中取出一个消息在执行前后都会调用 logging.println，那么两次调用的时间间隔不就是主线程处理该消息的时间嘛，继续看看这个 monitor 是哪里来的。通过查询代码发现在 BlockCanaryInternals 的构造器中设置了该 monitor。

public BlockCanaryInternals() {
	setMonitor(new LooperMonitor(new LooperMonitor.BlockListener() {
        public void onBlockEvent(long realTimeStart, long realTimeEnd,
                                 long threadTimeStart, long threadTimeEnd) {
            ArrayList<String> threadStackEntries = stackSampler
                .getThreadStackEntries(realTimeStart, realTimeEnd);
            if (!threadStackEntries.isEmpty()) {
                BlockInfo blockInfo = BlockInfo.newInstance()
                    .setMainThreadTimeCost(realTimeStart, realTimeEnd, threadTimeStart, threadTimeEnd)
                    .setCpuBusyFlag(cpuSampler.isCpuBusy(realTimeStart, realTimeEnd))
                    .setRecentCpuRate(cpuSampler.getCpuRateInfo())
                    .setThreadStackEntries(threadStackEntries)
                    .flushString();
                LogWriter.save(blockInfo.toString());
                if (mInterceptorChain.size() != 0) {
                    for (BlockInterceptor interceptor : mInterceptorChain) {
                        interceptor.onBlock(getContext().provideContext(), blockInfo);
                    }
                }
            }
        }
    }, getContext().provideBlockThreshold(), getContext().stopWhenDebugging()));
}

可以发现最终其实是设置了 LooperMonitor 类实例，查看其 println 方法，看看做了些什么。

public void println(String x) {
    if (mStopWhenDebugging && Debug.isDebuggerConnected()) { // 如果设置了 Debug 时停止检查并且当前处于 Debug 状态那么直接返回
        return;
    }
    if (!mPrintingStarted) {
        mStartTimestamp = System.currentTimeMillis();
        mStartThreadTimestamp = SystemClock.currentThreadTimeMillis();
        mPrintingStarted = true;
        startDump();
    } else {
        final long endTime = System.currentTimeMillis();
        mPrintingStarted = false;
        if (isBlock(endTime)) {
            notifyBlockEvent(endTime);
        }
        stopDump();
    }
}
private boolean isBlock(long endTime) {
    return endTime - mStartTimestamp > mBlockThresholdMillis;
}

方法内部逻辑也很简单，就是通过变量 mPrintingStarted 来判断是消息处理前还是处理后，然后在处理前记录开始时间，处理后记录结束时间，相减得出了该消息的处理时间，然后判断是否大于设置的阈值即可。不过问题来了，虽然通过这种方式我能检查到主线程上的是否存在耗时操作，但是我确没法定位到究竟是哪个方法耗时，但是 BlockCanary 却能检查出来，它是怎么做到的呢？通过逆向查找发现最终堆栈信息是通过 stackSampler.getThreadStackEntries 方法获取到的。

// StackSample.java
public ArrayList<String> getThreadStackEntries(long startTime, long endTime) {
    ArrayList<String> result = new ArrayList<>();
    synchronized (sStackMap) {
        for (Long entryTime : sStackMap.keySet()) {
            if (startTime < entryTime && entryTime < endTime) {
                result.add(BlockInfo.TIME_FORMATTER.format(entryTime)
                           + BlockInfo.SEPARATOR
                           + BlockInfo.SEPARATOR
                           + sStackMap.get(entryTime));
            }
        }
    }
    return result;
}

sStackMap 又是怎么来的，查询源码发现在 doSample 方法中添加元素的。

protected void doSample() {
    StringBuilder stringBuilder = new StringBuilder();
    for (StackTraceElement stackTraceElement : mCurrentThread.getStackTrace()) {
        stringBuilder
            .append(stackTraceElement.toString())
            .append(BlockInfo.SEPARATOR);
    }
    synchronized (sStackMap) {
        if (sStackMap.size() == mMaxEntryCount && mMaxEntryCount > 0) {
            sStackMap.remove(sStackMap.keySet().iterator().next());
        }
        sStackMap.put(System.currentTimeMillis(), stringBuilder.toString());
    }
}

通过线程对象获取堆栈信息？不对啊如果主线程正在执行耗时操作，这里的代码肯定执行不到，那怎么获取堆栈信息，难道这个方法是在子线程调用的？事实也正是如此，查看其父类 AbstractSample 发现其就是在子线程中被调用的。

abstract class AbstractSampler {
	private Runnable mRunnable = new Runnable() {
        public void run() {
            doSample();
            if (mShouldSample.get()) {
                HandlerThreadFactory.getTimerThreadHandler()
                        .postDelayed(mRunnable, mSampleInterval);
            }
        }
    };
    public void start() {
        if (mShouldSample.get()) {
            return;
        }
        mShouldSample.set(true);
        HandlerThreadFactory.getTimerThreadHandler().removeCallbacks(mRunnable);
        HandlerThreadFactory.getTimerThreadHandler().postDelayed(mRunnable,
                BlockCanaryInternals.getInstance().getSampleDelay());
    }
    public void stop() {
        if (!mShouldSample.get()) {
            return;
        }
        mShouldSample.set(false);
        HandlerThreadFactory.getTimerThreadHandler().removeCallbacks(mRunnable);
    }
}

这里的 HandlerThreadFactory.getTimerThreadHandler 其实是获取到通过子线程 Looper 构建的 Handler 对象，因此最终 doSample 会在子线程中被执行，默认的 mSampleInterval 为 0.8 倍的消息处理阈值，也就是说默认当主线程上每个消息开始执行前，子线程都会在 800 毫秒后获取一下主线程的堆栈信息（如果 800 毫秒内该消息执行完毕则不获取），当主线程消息执行时间超过了 1000 毫秒后就会获取到该 800 毫秒时获取的主线程堆栈信息。至此 BlockCanary 获取堆栈信息的原理也明白了。

不足与开销

不足

经过上述分析，由于拿到的只是某个消息的处理时间，因此子线程拿到的主线程的堆栈信息也不一定能明确的定位到耗时方法，举个例子比如主线程某个消息执行了 A 方法，而 A 方法内部又执行了三个方法 A1、A2、A3，其中 A1 耗时可能执行 790 毫秒，A2 不是很耗时执行 30 毫秒，A3 耗时执行 300 毫秒，最终 A 方法执行时间超出了 1000 毫秒，而子线程由于获取的是 800 毫秒时主线程的堆栈信息，因此最终定位到了 A2 方法，但是实际它是 A1、A2、A3 三个中最不耗时的。由于这个原因，因此使用 BlockCanary 一定要从该消息直接调用的方法开始排查，对于上述例子虽然堆栈信息不是很准确，但是至少能说明 A 方法是个耗时操作。

开销

经过上述分析，BlockCanary 内部是通过调用 setMessageLogging 来检测消息执行时间的，查阅源码发现如果设置了那么每次消息执行前后都会拼接字符串，然后将拼接的字符串传递过来。但是主线程的消息执行是非常频繁的，没执行一次都会创建两个 StringBuilder 对象其实又会存在一定的性能开销。就比如自定义 View 的 onDraw 方法中创建对象一样，会导致内存抖动。