Android 性能监控框架 Matrix(4)卡顿监控

6,345 阅读7分钟

使用

Matrix 中负责卡顿监控的组件是 TraceCanary,它是基于 ASM 插桩实现的,用于监控界面流畅性、启动耗时、页面切换耗时、慢函数及卡顿等问题。和 ResourceCanary 类似,使用前需要配置如下,主要包括帧率、耗时方法、ANR、启动等选项:

TraceConfig traceConfig = new TraceConfig.Builder()
        .dynamicConfig(dynamicConfig)
        .enableFPS(fpsEnable) // 帧率
        .enableEvilMethodTrace(traceEnable) // 耗时方法
        .enableAnrTrace(traceEnable) // ANR
        .enableStartup(traceEnable) // 启动
        .splashActivities("sample.tencent.matrix.SplashActivity;") // 可指定多个启动页,使用分号 ";" 分割
        .isDebug(true)
        .isDevEnv(false)
        .build();
TracePlugin tracePlugin = new TracePlugin(traceConfig);

接着在 Application / Activity 中启动即可:

tracePlugin.start();

除了以上配置之外,Trace Canary 还有如下自定义的配置选项:

enum ExptEnum {
    // trace
    clicfg_matrix_trace_care_scene_set, // 闪屏页
    clicfg_matrix_trace_fps_time_slice, // 如果同一 Activity 掉帧数 * 16.66ms > time_slice,就上报,默认为 10s
    clicfg_matrix_trace_evil_method_threshold, // 慢方法的耗时阈值,默认为 700ms

    clicfg_matrix_fps_dropped_normal, // 正常掉帧数,默认 [3, 9)
    clicfg_matrix_fps_dropped_middle, // 中等掉帧数,默认 [9, 24)
    clicfg_matrix_fps_dropped_high, // 高掉帧数,默认 [24, 42)
    clicfg_matrix_fps_dropped_frozen, // 卡顿掉帧数,默认 [42, ~)

    clicfg_matrix_trace_app_start_up_threshold, // 冷启动时间阈值,默认 10s
    clicfg_matrix_trace_warm_app_start_up_threshold, // 暖启动时间阈值,默认 4s
}

报告

相比内存泄漏,卡顿监控报告的信息复杂了很多。

ANR

出现 ANR 时,Matrix 上报信息如下:

{
    "tag": "Trace_EvilMethod",
    "type": 0,
    "process": "sample.tencent.matrix",
    "time": 1590397340910,
    "machine": "HIGH", // 设备等级
    "cpu_app": 0.001405802921652454, // 应用占用的 CPU 时间比例,appTime/cpuTime * 100
    "mem": 3030949888,   // 设备总运行内存
    "mem_free": 1695964, // 设备可用的运行内存,不绝对,可能有部分已经被系统内核使用
    "detail": "ANR",
    "cost": 5006,  // 方法执行总耗时
    "stackKey": "30|", // 关键方法
    "scene": "sample.tencent.matrix.trace.TestTraceMainActivity",
    "stack": "0,1048574,1,5006\n1,15,1,5004\n2,30,1,5004\n", // 方法执行关键路径
    "threadStack": " \nat android.os.SystemClock:sleep(120)\nat sample.tencent.matrix.trace.TestTraceMainActivity:testInnerSleep(234)\nat sample.tencent.matrix.trace.TestTraceMainActivity:testANR(135)\nat java.lang.reflect.Method:invoke(-2)\nat android.view.View$DeclaredOnClickListener:onClick(4461)\nat android.view.View:performClick(5212)\nat android.view.View$PerformClick:run(21214)\nat android.os.Handler:handleCallback(739)\nat android.os.Handler:dispatchMessage(95)\nat android.os.Looper:loop(148)\nat android.app.ActivityThread:main(5619)\n", // 线程堆栈
    "processPriority": 20, // 进程优先级
    "processNice": 0,      // 进程的 nice 值
    "isProcessForeground": true,  // 应用是否可见
    "memory": {
        "dalvik_heap": 17898, // 虚拟机中已分配的 Java 堆内存,kb
        "native_heap": 6796,  // 已分配的本地内存,kb
        "vm_size": 858132// 虚拟内存大小,指进程总共可访问的地址空间,kb
    }
}

其中,设备分级如下:

  1. BEST,内存大于等于 4 G
  2. HIGH,内存大于等于 3G,或内存大于等于 2G 且 CPU 核心数大于等于 4 个
  3. MIDDLE,内存大于等于 2G 且 CPU 核心数大于等于 2 个,或内存大于等于 1G 且 CPU 核心数大于等于 4 个
  4. LOW,内存大于等于 1G
  5. BAD,内存小于 1G

启动

正常启动情况下:

{
    "tag": "Trace_StartUp",
    "type": 0,
    "process": "sample.tencent.matrix",
    "time": 1590405971796, 
    "machine": "HIGH", 
    "cpu_app": 2.979125443261738E-4,
    "mem": 3030949888,
    "mem_free": 1666132,
    "application_create": 35, // 应用启动耗时
    "application_create_scene": 100, // 启动场景
    "first_activity_create": 318, // 第一个 activity 启动耗时
    "startup_duration": 2381, // 启动总耗时
    "is_warm_start_up": false, // 是否是暖启动
}

其中,application_create、first_activity_create、startup_duration 分别对应 applicationCost、firstScreenCost、coldCost:

firstMethod.i       LAUNCH_ACTIVITY   onWindowFocusChange   LAUNCH_ACTIVITY    onWindowFocusChange
^                         ^                   ^                     ^                  ^
|                         |                   |                     |                  |
|---------app---------|---|---firstActivity---|---------...---------|---careActivity---|
|<--applicationCost-->|
|<--------------firstScreenCost-------------->|
|<---------------------------------------coldCost------------------------------------->|
.                         |<-----warmCost---->|

启动场景分为 4 种:

  1. 100,Activity 拉起的
  2. 114,Service 拉起的
  3. 113,Receiver 拉起的
  4. -100,未知,比如 ContentProvider

如果是启动过慢的情况:

{
    "tag": "Trace_EvilMethod",
    "type": 0,
    "process": "sample.tencent.matrix",
    "time": 1590407016547,
    "machine": "HIGH",
    "cpu_app": 3.616498950411638E-4,
    "mem": 3030949888,
    "mem_free": 1604416,
    "detail": "STARTUP",
    "cost": 2388,
    "stack": "0,2,1,43\n1,121,1,0\n1,1,8,0\n2,99,1,0\n0,1048574,1,0\n0,1048574,1,176\n1,15,1,144\n0,1048574,1,41\n",
    "stackKey": "2|",
    "subType": 1 // 1 代表冷启动,2 代表暖启动
}

慢方法

{
    "tag": "Trace_EvilMethod",
    "type": 0,
    "process": "sample.tencent.matrix",
    "time": 1590407411286,
    "machine": "HIGH",
    "cpu_app": 8.439117339531338E-4,
    "mem": 3030949888,
    "mem_free": 1656536,
    "detail": "NORMAL",
    "cost": 804, // 方法执行总耗时
    "usage": "0.37%",  // 在方法执行总时长中,当前线程占用的 CPU 时间比例
    "scene": "sample.tencent.matrix.trace.TestTraceMainActivity",
    "stack": "0,1048574,1,804\n1,14,1,803\n2,29,1,798\n",
    "stackKey": "29|"
}

帧率

在出现掉帧的情况时,Matrix 上报信息如下:

{
    "tag": "Trace_FPS",
    "type": 0,
    "process": "sample.tencent.matrix",
    "time": 1590408900258,
    "machine": "HIGH",
    "cpu_app": 0.0030701181354057853,
    "mem": 3030949888,
    "mem_free": 1642296,
    "scene": "sample.tencent.matrix.trace.TestFpsActivity",
    "dropLevel": { // 不同级别的掉帧问题出现的次数
        "DROPPED_FROZEN": 0,
        "DROPPED_HIGH": 0,
        "DROPPED_MIDDLE": 3,
        "DROPPED_NORMAL": 14,
        "DROPPED_BEST": 451
    },
    "dropSum": { // 不同级别的掉帧问题对应的总掉帧数
        "DROPPED_FROZEN": 0,
        "DROPPED_HIGH": 0,
        "DROPPED_MIDDLE": 41,
        "DROPPED_NORMAL": 57,
        "DROPPED_BEST": 57
    },
    "fps": 46.38715362548828, // 帧率
    "dropTaskFrameSum": 0 // 意义不明,正常情况下值总是为 0
}

原理介绍

(注:这部分内容主要整理自 Matrix 的官方文档

开头说到,Matrix 的卡顿监控是基于 ASM 插桩实现的,其原理是通过代理编译期间的任务 transformClassesWithDexTask,将全局 class 文件作为输入,利用 ASM 工具对所有 class 文件进行扫描及插桩,插桩的意思是在每一个方法的开头处插入 AppMethodBeat.i 方法,在方法的结尾处插入 AppMethodBeat.o 方法,并记录时间戳,这样就能知道该方法的执行耗时。

插桩过程有几个关键点:

  1. 选择在编译任务执行时插桩,是因为 proguard 操作是在该任务之前就完成的,意味着插桩时的 class 文件已经被混淆过的。而选择 proguard 之后去插桩,是因为如果提前插桩会造成部分方法不符合内联规则,没法在 proguard 时进行优化,最终导致程序方法数无法减少,从而引发方法数过大问题

  2. 为了减少插桩量及性能损耗,通过遍历 class 方法指令集,判断扫描的函数是否只含有 PUT/READ FIELD 等简单的指令,来过滤一些默认或匿名构造函数,以及 get/set 等简单不耗时函数。

  3. 针对界面启动耗时,因为要统计从 Activity#onCreate 到 Activity#onWindowFocusChange 间的耗时,所以在插桩过程中需要收集应用内所有 Activity 的实现类,并覆盖 onWindowFocusChange 函数进行打点。

  4. 为了方便及高效记录函数执行过程,Matrix 为每个插桩的函数分配一个独立 ID,在插桩过程中,记录插桩的函数签名及分配的 ID,在插桩完成后输出一份 mapping,作为数据上报后的解析支持。为了优化内存使用,method id 及时间戳是通过一个 long 数组记录的,格式如下:

  1. 堆栈聚类问题: 如果将收集的原始数据进行上报,数据量很大而且后台很难聚类有问题的堆栈,所以在上报之前需要对采集的数据进行简单的整合及裁剪,并分析出一个能代表卡顿堆栈的 key,方便后台聚合。具体的方法是通过遍历采集的 buffer ,相邻 i 与 o 为一次完整函数执行,计算出一个调用树及每个函数执行耗时,并对每一级中的一些相同执行函数做聚合,最后通过一个简单策略,分析出主要耗时的那一级函数,作为代表卡顿堆栈的key。

帧率监控的方法是向 Choreographer 注册监听,在每一帧 doframe 回调时判断距离上一帧的时间差是否超出阈值(卡顿),如果超出阈值,则获取数组 index 前的所有数据(即两帧之间的所有函数执行信息)进行分析上报。

ANR 监控则更简单,在每一帧 doFrame 到来时,重置一个定时器,并往 buffer 数组里插入一个结点,如果 5s 内没有 cancel,则认为发生了 ANR,从之前插入的结点开始,到最后一个结点,收集中间执行过的方法数据,可以认为导致 ANR 的关键方法就在这里面,计算时间戳即可得到关键方法。

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