BlockCanary原理解析

妖久發表於2024-01-11

一、背景

為了解決應卡頓,分析耗時。

二、原理

Looper中的loop方法:

public static void loop() {
    ...

    for (;;) {
        ...

        // This must be in a local variable, in case a UI event sets the logger
        Printer logging = me.mLogging;
        if (logging != null) {
            logging.println(">>>>> Dispatching to " + msg.target + " " +
                    msg.callback + ": " + msg.what);
        }

        msg.target.dispatchMessage(msg);

        if (logging != null) {
            logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
        }

        ...
    }
}

可以看到在執行訊息的時候,如果有設定logging,那麼它會在訊息開始與結束的時候列印出相關資訊。如果主執行緒卡住了,就是在dispatchMessage這裡卡住,所以我們可以透過計算這兩條log的時間差來判斷訊息的執行時間。

我們可以透過這個方法來設定Printer。

Looper.getMainLooper().setMessageLogging(mainLooperPrinter);

三、原始碼解析

application中呼叫初始化:
BlockCanary.install(this, AppBlockCanaryContext()).start()

最終會執行到:

    private BlockCanary() {
        BlockCanaryInternals.setContext(BlockCanaryContext.get());
        mBlockCanaryCore = BlockCanaryInternals.getInstance();
        mBlockCanaryCore.addBlockInterceptor(BlockCanaryContext.get());
        if (!BlockCanaryContext.get().displayNotification()) {
            return;
        }
        mBlockCanaryCore.addBlockInterceptor(new DisplayService());

    }

核心就是mBlockCanaryCore = BlockCanaryInternals.getInstance();它會對BlockCanaryInternals進行初始化。

    public BlockCanaryInternals() {

        stackSampler = new StackSampler(
                Looper.getMainLooper().getThread(),
                sContext.provideDumpInterval());

        cpuSampler = new CpuSampler(sContext.provideDumpInterval());

        setMonitor(new LooperMonitor(new LooperMonitor.BlockListener() {

            @Override
            public void onBlockEvent(long realTimeStart, long realTimeEnd,
                                     long threadTimeStart, long threadTimeEnd) {
                // Get recent thread-stack entries and cpu usage
                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()));

        LogWriter.cleanObsolete();
    }

  • stackSampler:記錄棧相關資訊
  • cpuSampler:記錄CPU相關資訊
  • LooperMonitor:繼承Printer
    private void setMonitor(LooperMonitor looperPrinter) {
        monitor = looperPrinter;
    }

當我們呼叫BlockCanary的start方法的時候,便將其設給了Looper的printer,然後我們便可以在LooperMonitor的print方法裡面去記錄列印的log的時間。

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

核心程式碼:

    @Override
    public void println(String x) {
        if (mStopWhenDebugging && Debug.isDebuggerConnected()) {
            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();
        }
    }

在開始執行訊息的時候去記錄相關資訊,結束訊息的時候停止記錄相關資訊,並且判斷訊息執行的時間是否超過了我們設定的閾值,超過了的話便執行notifyBlockEvent(endTime);取出記錄的相關訊息提示使用者。

說到此處,想到是不是可以用mainLooperPrinter來做更多事情呢?既然主執行緒都在這裡,那隻要parse出app包名的第一行,每次列印出來,是不是就不需要打點也能記錄出使用者操作路徑? 再者,比如想做onClick到頁面建立後的耗時統計,是不是也能用這個原理呢? 之後可以試試看這個思路(目前存在問題是獲取執行緒堆疊是定時3秒取一次的,很可能一些比較快的方法操作一下子完成了沒法在stacktrace裡面反映出來)。

我們看一下怎麼記錄棧以及cpu的訊息的。

    private void startDump() {
        if (null != BlockCanaryInternals.getInstance().stackSampler) {
            BlockCanaryInternals.getInstance().stackSampler.start();
        }

        if (null != BlockCanaryInternals.getInstance().cpuSampler) {
            BlockCanaryInternals.getInstance().cpuSampler.start();
        }
    }

StackSampler與CpuSampler都繼承與AbstractSampler:
AbstractSampler裡面的start方法:

    public void start() {
        if (mShouldSample.get()) {
            return;
        }
        mShouldSample.set(true);

        HandlerThreadFactory.getTimerThreadHandler().removeCallbacks(mRunnable);
        HandlerThreadFactory.getTimerThreadHandler().postDelayed(mRunnable,
                BlockCanaryInternals.getInstance().getSampleDelay());
    }

    private Runnable mRunnable = new Runnable() {
        @Override
        public void run() {
            doSample();

            if (mShouldSample.get()) {
                HandlerThreadFactory.getTimerThreadHandler()
                        .postDelayed(mRunnable, mSampleInterval);
            }
        }
    };


    long getSampleDelay() {
        return (long) (BlockCanaryInternals.getContext().provideBlockThreshold() * 0.8f);
    }

它其實是開了一個子執行緒每隔一定的時間就去記錄。

四、流程圖

image

五、總結

BlockCanary作為一個Android元件,目前還有侷限性,因為其在一個完整的監控系統中只是一個生產者,還需要對應的消費者去分析日誌,比如歸類排序,以便看出哪些卡慢更有修復價值,需要優先處理;又比如需要過濾機型,有些奇葩機型的問題造成的卡慢,到底要不要去修復是要斟酌的。扯遠一點的話,像是埋點除了統計外,完全還能用來做鏈路監控,比如一個完整的流程是A -> B -> D -> E, 但是某個時間節點突然A -> B -> D後沒有到達E,這時候監控平臺就可以發出預警,讓開發人員及時定位。很多監控方案都需要C/S兩端的配合。