1. 前言

2018年12月25日，微信團(tuán)隊(duì)自研的APM利器，Matrix正式開源了。

?
Matrix 是一款微信研發(fā)并日常使用的 APM (Application Performance Manage) ，當(dāng)前主要運(yùn)行在 Android 平臺(tái)上。Matrix 的目標(biāo)是建立統(tǒng)一的應(yīng)用性能接入框架，通過對(duì)各種性能監(jiān)控方案快速集成，對(duì)性能監(jiān)控項(xiàng)的異常數(shù)據(jù)進(jìn)行采集和分析，輸出相應(yīng)問題的分析、定位與優(yōu)化建議，從而幫助開發(fā)者開發(fā)出更高質(zhì)量的應(yīng)用。
?

在精讀了Matrix的源碼之后，我發(fā)出了贊嘆和吐槽兩種聲音。值得贊揚(yáng)的是，「這個(gè)APM框架的設(shè)計(jì)思路確實(shí)鬼斧神工，有很多值得Android開發(fā)者學(xué)習(xí)的地方，深入了解它，能夠擴(kuò)寬我們的編程視野?！?/strong> 令人吐槽的就是，「從文檔的豐富性，代碼的可讀性，代碼的注釋量，開源的一條龍服務(wù)等方面講，他們做的還不太好?！?/strong> 作為國內(nèi)的頂尖開發(fā)團(tuán)隊(duì)，這些方面與國外的頂尖開源開發(fā)團(tuán)隊(duì)還是有不小的差距。

目前Matrix的集成確實(shí)很方便，參考官方文檔，大概10分鐘左右就能集成到項(xiàng)目中。「但是它有一個(gè)硬傷，對(duì)開發(fā)者很不友好，它集成很方便，但是分析和定位問題比較困難，開發(fā)者需要搭建一套數(shù)據(jù)采集和分析系統(tǒng)，大大地增加了開發(fā)者的使用門檻。」目前它在github上的star量是8.5k。如果微信團(tuán)隊(duì)能把采集系統(tǒng)和數(shù)據(jù)分析系統(tǒng)也開源出來，用戶的使用門檻將會(huì)大大降低，相信star量也能更上一個(gè)臺(tái)階。

吐槽歸吐槽。吐槽不是目的。希望國內(nèi)的開發(fā)者可以更真心實(shí)意地做出更好用的開源產(chǎn)品。「吐槽完畢，接下來我將聊聊Matrix官方文檔中沒有講到的一些設(shè)計(jì)細(xì)節(jié)。真的很驚艷。如果你對(duì)Matrix曾經(jīng)有任何偏見，不妨跟隨我打破偏見，突破微信團(tuán)隊(duì)給我們?cè)O(shè)置的使用門檻。」

2. Matrix功能簡(jiǎn)介

Matrix 當(dāng)前監(jiān)控范圍包括：「應(yīng)用安裝包大小，SQLite 操作優(yōu)化，幀率變化，卡頓，啟動(dòng)耗時(shí)，頁面切換耗時(shí)，慢方法，文件讀寫性能，I/O 句柄泄漏，內(nèi)存泄漏等?！?/strong>

更多詳細(xì)介紹請(qǐng)移步Matrix簡(jiǎn)介

「本文將著重講解檢測(cè)慢方法的實(shí)現(xiàn)原理，以及數(shù)據(jù)格式分析，數(shù)據(jù)格式是Matrix的重中之重，無論是采集過程生成數(shù)據(jù)，還是分析過程解析數(shù)據(jù)，都需要熟練理解數(shù)據(jù)格式。其它系列的文章隨著我對(duì)Matrix的理解程度加深，也會(huì)陸續(xù)在公眾號(hào)發(fā)布，敬請(qǐng)關(guān)注?！?/strong>

3. 慢方法演示

官方Demo，TestTraceMainActivity#testJankiess(View view)模擬在主線程調(diào)用方法超過700ms的場(chǎng)景。Matrix中慢方法的默認(rèn)閾值是700ms。用戶可配置。對(duì)應(yīng)的字段是

?
//Constants.java
public static final int DEFAULT_EVIL_METHOD_THRESHOLD_MS = 700;
?

點(diǎn)擊EVIL_METHOD按鈕，會(huì)調(diào)用testJankiess方法。打印Log如下

乍一看，有點(diǎn)丈二的和尚摸不著頭腦。出現(xiàn)這樣的日志，說明主線程調(diào)用時(shí)長(zhǎng)超過了700ms。把日志中content對(duì)應(yīng)的json格式化，得到如下結(jié)果：

{
  "machine":"UN_KNOW",
  "cpu_app":0,
  "mem":1567367168,
  "mem_free":851992,
  "detail":"NORMAL",
  "cost":2262,
  "usage":"0.35%",
  "scene":"sample.tencent.matrix.trace.TestTraceMainActivity",
  "stack":"0,1048574,1,2262\n
            1,117,1,2254\n
            2,121,1,2254\n
            3,124,1,384\n
            4,125,1,165\n
            5,126,1,21\n
            5,127,1,21\n
            5,128,1,19\n
            4,129,1,24\n
            3,130,1,65\n
            4,131,1,21\n
            4,132,1,6\n
            4,133,1,8\n
            3,134,1,1004\n",
  "stackKey":"121|",
  "tag":"Trace_EvilMethod",
  "process":"sample.tencent.matrix",
  "time":1620523013050
}

關(guān)于數(shù)據(jù)格式，官方也有一篇文章介紹，https://github.com/Tencent/matrix/wiki/Matrix-Android--data-format，感興趣的同學(xué)可以去看看。

本文重點(diǎn)關(guān)注stack字段。它的功能是上報(bào)對(duì)應(yīng)的堆棧。但是堆棧中為啥是一堆阿拉伯?dāng)?shù)字呢？先讓我們從頭說起了。

4.計(jì)算方法調(diào)用的時(shí)間花費(fèi)

4.1 計(jì)算一個(gè)方法調(diào)用花費(fèi)的時(shí)間

假設(shè)有方法A。我想計(jì)算它花費(fèi)的時(shí)間。我們一般會(huì)這樣做

public void A() {
  long startTime = SystemClock.uptimeMillis()
  SystemClock.sleep(1000);
  long endTime = SystemClock.uptimeMillis()
  System.out.println("cost time " + (endTime-startTime));
}

對(duì)于單個(gè)方法我們可以這樣做。「但是如果我想給Android項(xiàng)目中所有的方法都計(jì)算調(diào)用花費(fèi)時(shí)，我們需要用到字節(jié)碼插樁技術(shù)。在所有的方法開始處和結(jié)束處，添加記錄時(shí)間的代碼。而Matrix也正是使用插樁技術(shù)來計(jì)算方法的時(shí)間調(diào)用的?！?/strong>

項(xiàng)目工程中TestTraceMainActivity的A方法

使用Jadx工具反編譯apk中的TestTraceMainActivity。發(fā)現(xiàn)A方法前后增加了「AppMethoBeat.i(121)和AppMethoBeat.o(121)」

「i/o 方法參數(shù)121是什么意思呢？」

4.2 121含義講解

gradle插件，在處理方法時(shí)，會(huì)將方法名與從1開始遞增的數(shù)字對(duì)應(yīng)起來。「我們打開app/build/outputs/mapping/debug/methodMapping.txt文件。從圖片我們可以看到121對(duì)應(yīng)的方法名是sample.tencent.matrix.trace.TestTraceMainActivity A ()V」

?
前文堆棧中的數(shù)字0,1048574,1,2262\n 第二列1048574對(duì)應(yīng)的就是方法名對(duì)應(yīng)的數(shù)字。「這么做的好處是，數(shù)據(jù)采集節(jié)省流量?！?/strong>
?

4.3 獲取調(diào)用棧的耗時(shí)

有方法調(diào)用如下，假設(shè)A方法調(diào)用耗時(shí)1000ms。如何能夠確定調(diào)用棧中哪個(gè)子方法的調(diào)用最耗時(shí)？

public void A() {
  B();
  C();
  D();
}

?
Matrix框架已經(jīng)實(shí)現(xiàn)了調(diào)用棧耗時(shí)監(jiān)測(cè)，具體分析我放到后面講解。「重點(diǎn)就是后文6.2章節(jié)」
?

4.4 獲取主線程耗時(shí)

依賴主線程Looper，監(jiān)控每次dispatchMessage的執(zhí)行耗時(shí)

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

主線程所有執(zhí)行的任務(wù)都在 dispatchMessage 方法中派發(fā)執(zhí)行完成，「我們通過 setMessageLogging 的方式給主線程的 Looper 設(shè)置一個(gè) Printer ，因?yàn)?dispatchMessage 執(zhí)行前后都會(huì)打印對(duì)應(yīng)信息。我們可以計(jì)算出執(zhí)行前后的時(shí)間花費(fèi)?！?/strong>

5. Matrix如何實(shí)現(xiàn)插樁

本文只是簡(jiǎn)單介紹Matrix的插樁技術(shù)。淺嘗輒止。實(shí)現(xiàn)插樁的代碼是com/tencent/matrix/trace/MethodTracer.java，「它的內(nèi)部類TraceMethodAdapter實(shí)現(xiàn)了AppMethoBeat.i()和AppMethoBeat.o()的插入功能?！?/strong>

6. 慢方法監(jiān)測(cè)的原理

6.1 手畫調(diào)用棧樹

第三節(jié)提到的慢方法演示，它的代碼調(diào)用如下。

public void testJankiess(View view) {
    A();
}

private void A() {
    B();
    H();
    L();
    SystemClock.sleep(800);
}

private void B() {
    C();
    G();
    SystemClock.sleep(200);
}

private void C() {
    D();
    E();
    F();
    SystemClock.sleep(100);
}

private void D() {
    SystemClock.sleep(20);
}

private void E() {
    SystemClock.sleep(20);
}

private void F() {
    SystemClock.sleep(20);
}

private void G() {
    SystemClock.sleep(20);
}

private void H() {
    SystemClock.sleep(20);
    I();
    J();
    K();
}

private void I() {
    SystemClock.sleep(20);
}

private void J() {
    SystemClock.sleep(6);
}

private void K() {
    SystemClock.sleep(10);
}

private void L() {
    SystemClock.sleep(1000);
}

「它對(duì)應(yīng)的methodMapping文件如下：」

117,1,sample.tencent.matrix.trace.TestTraceMainActivity testJankiess (Landroid.view.View;)V
121,2,sample.tencent.matrix.trace.TestTraceMainActivity A ()V
122,4,sample.tencent.matrix.battery.TestBatteryActivity onDestroy ()V
123,9,sample.tencent.matrix.sqlitelint.TestSQLiteLintHelper qualityClose (Ljava.io.Closeable;)V
124,2,sample.tencent.matrix.trace.TestTraceMainActivity B ()V
125,2,sample.tencent.matrix.trace.TestTraceMainActivity C ()V
126,2,sample.tencent.matrix.trace.TestTraceMainActivity D ()V
127,2,sample.tencent.matrix.trace.TestTraceMainActivity E ()V
128,2,sample.tencent.matrix.trace.TestTraceMainActivity F ()V
129,2,sample.tencent.matrix.trace.TestTraceMainActivity G ()V
130,2,sample.tencent.matrix.trace.TestTraceMainActivity H ()V
131,2,sample.tencent.matrix.trace.TestTraceMainActivity I ()V
132,2,sample.tencent.matrix.trace.TestTraceMainActivity J ()V
133,2,sample.tencent.matrix.trace.TestTraceMainActivity K ()V
134,2,sample.tencent.matrix.trace.TestTraceMainActivity L ()V
1048574,1,android.os.Handler dispatchMessage (Landroid.os.Message;)V

「以上方法調(diào)用可以歸納成以下樹形結(jié)構(gòu)：」

?
「請(qǐng)注意,該樹形圖，是我直接根據(jù)調(diào)用次序畫出來的，程序是如何根據(jù)調(diào)用次序生成調(diào)用棧樹呢？」
?

6.2 生成調(diào)用棧樹

6.2.1 函數(shù)調(diào)用記錄在隊(duì)列中

編譯期已經(jīng)對(duì)全局的函數(shù)進(jìn)行插樁，在運(yùn)行期間每個(gè)函數(shù)的執(zhí)行前后都會(huì)調(diào)用 MethodBeat.i/o 的方法，如果是在主線程中執(zhí)行，則在函數(shù)的執(zhí)行前后獲取當(dāng)前距離 MethodBeat 模塊初始化的時(shí)間 offset 「（為了壓縮數(shù)據(jù)，存進(jìn)一個(gè)long類型變量中），」 并將當(dāng)前執(zhí)行的是 MethodBeat i或者o、mehtod id 及時(shí)間 offset，存放到一個(gè) long 類型變量中，記錄到一個(gè)預(yù)先初始化好的數(shù)組 long[] 中 index 的位置（預(yù)先分配記錄數(shù)據(jù)的 buffer 長(zhǎng)度為 100w，內(nèi)存占用約 7.6M）。數(shù)據(jù)存儲(chǔ)如下圖：

//AppMethodBeat.java
private static long[] sBuffer = new long[Constants.BUFFER_SIZE];

//Constants.java
public static final int BUFFER_SIZE = 100 * 10000; // 7.6M

「AppMethodBeat.i/o方法最終會(huì)調(diào)用到」

//AppMethodBeat.java
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) {
        trueId |= 1L << 63;
    }
    trueId |= (long) methodId << 43;
    trueId |= sCurrentDiffTime & 0x7FFFFFFFFFFL;
    sBuffer[index] = trueId;
    checkPileup(index);
    sLastIndex = index;
}