Crash排查系列第三篇|自己开发一个trace辅助工具

乌柚
1,727 阅读10分钟

demo地址：github.com/wuyouuuu/wy…

背景

随着稳定性治理和性能优化的深入，发现现有trace在有些方面已经很难满足排查问题的需要

比如更深层次的启动优化,framework crash排查，release包trace查看,竞品流程分析等场景。

开发一个trace辅助工具

目前的trace工具

我们先整理一下我们常见trace各个方案的优缺点。

Traceview

优点:

  1. 可以用来查看整个过程有哪些函数调用

缺点:

  1. 工具本身带来的性能开销过大，有时无法反映真实的情况。比如一个函数本身的耗时是 1 秒，开启 Traceview 后可能会变成 5 秒，而且这些函数的耗时变化并不是成比例放大
  2. 手机贼卡

Traceview利用 Android Runtime 函数调用的 event 事件，将函数运行的耗时和调用关系写入 trace 文件中。它可以用来查看整个过程有哪些函数调用，但是工具本身带来的性能开销过大，有时无法反映真实的情况。比如一个函数本身的耗时是 1 秒，开启 Traceview 后可能会变成 5 秒，而且这些函数的耗时变化并不是成比例放大。在 Android 5.0 之后，新增了startMethodTracingSampling方法，可以使用基于样本的方式进行分析，以减少分析对运行时的性能影响。新增了 sample 类型后，就需要我们在开销和信息丰富度之间做好权衡

systrace+函数插桩

优点

  1. 有系统关键线程的函数调用，例如渲染耗时、线程锁，GC 耗时等，还有 I/O 操作、CPU 负载等事件
  2. 性能损耗可以接受。由于过滤了大部分的短函数，而且没有放大 I/O，所以整个运行耗时不到原来的两倍，基本可以反映真实情况

缺点：

  1. 无法知道整个过程有哪些函数调用，比如framwork代码。
  2. 函数查桩过多，生成trace过大可能连一个启动过程都无法整个分析。

systrace是 Android 4.1 新增的性能分析工具。我通常使用 systrace 跟踪系统的 I/O 操作、CPU 负载、Surface 渲染、GC 等事件。systrace 利用了 Linux 的ftrace调试工具，相当于在系统各个关键位置都添加了一些性能探针，也就是在代码里加了一些性能监控的埋点。Android 在 ftrace 的基础上封装了atrace，并增加了更多特有的探针，例如 Graphics、Activity Manager、Dalvik VM、System Server 等。systrace 工具只能监控特定系统调用的耗时情况，所以它是属于 sample 类型，而且性能开销非常低。但是它不支持应用程序代码的耗时分析，所以在使用时有一些局限性。由于系统预留了Trace.beginSection接口来监听应用程序的调用耗时,我们可以通过编译时给每个函数插桩的方式来实现，也就是在重要函数的入口和出口分别增加Trace.beginSection和Trace.endSection。当然出于性能的考虑，我们会过滤大部分指令数比较少的函数，这样就实现了在 systrace 基础上增加应用程序耗时的监控。通过这样方式的好处有：可以看到整个流程系统和应用程序的调用流程。包括系统关键线程的函数调用，例如渲染耗时、线程锁，GC 耗时等。性能损耗可以接受。由于过滤了大部分的短函数，而且没有放大 I/O，所以整个运行耗时不到原来的两倍，基本可以反映真实情况。

Nanoscope

优点

  1. 性能损毁小，使用过程感觉不到卡顿
  2. 可以做竞品分析

缺点

  1. 需要自己刷 ROM，并且当前只支持 Nexus 6P，或者采用其提供的 x86 架构的模拟器
  2. 默认只支持主线程采集，其他线程需要代码手动设置
  3. 考虑到内存大小的限制，每个线程的内存数组只能支持大约 20 秒左右的时间段

Uber 开源的Nanoscope。它的实现原理是直接修改 Android 虚拟机源码，在ArtMethod执行入口和执行结束位置增加埋点代码，将所有的信息先写到内存，等到 trace 结束后才统一生成结果文件。在使用过程可以明显感觉到应用不会因为开启 Nanoscope 而感到卡顿，但是 trace 结束生成结果文件这一步需要的时间比较长。另一方面它可以支持分析任意一个应用，可用于做竞品分析。但是它也有不少限制：需要自己刷 ROM，并且当前只支持 Nexus 6P，或者采用其提供的 x86 架构的模拟器。默认只支持主线程采集，其他线程需要代码手动设置。考虑到内存大小的限制，每个线程的内存数组只能支持大约 20 秒左右的时间段

(以上优缺点摘抄自极客时间android 开发高手课)

一个完美的方案

  1. 可以用来查看整个过程有哪些函数调用
  2. 有系统关键线程的函数调用，例如渲染耗时、线程锁，GC 耗时等，还有 I/O 操作、CPU 负载等事件
  3. 性能损毁小,耗时准确，使用过程感觉不到卡顿
  4. 可以做竞品分析
  5. 不受rom限制
  6. 可支持任意线程。
  7. 支持线上使用。

我们能做到吗？做不到

方案设计

trace工具目标

  1. 支持线下下分析函数执行流程，函数耗时。

  2. 在分析函数耗时的场景下要更加准确

  3. 在分析函数调用流程下

    1. 可以查看整个过程的函数调用，
    2. 能够指定监控的函数和线程有效过滤无用trace。
    3. 动态配置 不需要重新打包

  4. 可使用现成的UI分析工具，有系统关键线程的函数调用，例如渲染耗时、线程锁，GC 耗时等，还有 I/O 操作、CPU 负载等事件

  5. 可以支持android 9 - android 12 的机型覆盖

  6. 可以做竞品分析

流程图

image.png

寻找hook点

bbs.pediy.com/thread-2545…

在脱壳界有个fart的脱壳框架，他的一个原理就是把art切为解释执行，然后在interpreter.cc中的Execute函数中修改代码实现方法指令的dump

ArtMethod 执行流程

下面是一个art方法的执行流程图(图片来源于网络)

image.png

ART Runtime 解释器

  1. The C++ interpreter，也就是传统的基于switch结构的解释器，一般仅在调试环境、方法跟踪、指令不支持或者在字节码发生异常情况下（例如failed structured-locking verification）才走该分支
  2. The mterp fast interpreter，核心是引入了handler table做指令映射，并通过手写汇编以实现指令间的快速切换，提高了解释器性能。
  3. Nterp是Mterp的再次优化。Nterp省去了managed code stacks的维护，采用了和Native方法一样的栈帧结构，并且译码和翻译执行全程都由汇编代码实现，进一步拉进解释器和compiled code的性能差距

使用Inline hook

原理

mp.weixin.qq.com/s/9yUKeQVAx…

image.png

（1） 跳转指令的构建、从原指令跳转过去的底层桩函数，涉及系统汇编层，和Inline Hook的平台关系较大，既是ARM和THUMB、X86等均都有所不同；64位和32位也有所不同。

（2） 从底层桩函数跳转回原函数，既原理图中第3步跳转，去执行原指令2的时候，有个关键的点：如果原指令2涉及到PC操作，则需要进行指令修复。比如说是ADD R3, PC, R3, 两处指令的PC完全不一样，肯定不能直接复制，需要针对修复相应PC值。

（3） Inline Hook的指令覆盖顺序，原指令2的覆盖建议留在最后实现。既是完成了底层桩函数构造、原函数构造后，再一次性填写跳转指令覆盖原指令2。这样的好处是防止HOOK一些频繁执行的函数可能导致的崩溃。在Inline Hook的过程中走入了HOOK逻辑，而桩函数或者原函数可能未构造成功导致崩溃

github.com/bytedance/a…

找一个test方法 打印一下backtrace

image.png

#17 pc 000000000001b2ec [anon:dalvik-classes2.dex extracted in memory from /data/app/com.libs.demo-vfe181e7FTs0P_33VpxxsA==/base.apk!classes2.dex:00000070ae18f000] (com.modules.demo.MainActivity.test+16)

#18 pc 000000000059ffdc /apex/com.android.runtime/lib64/libart.so (MterpInvokeVirtual+1352)

#19 pc 0000000000130814 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_virtual+20)

#20 pc 000000000001afc4 [anon:dalvik-classes2.dex extracted in memory from /data/app/com.libs.demo-vfe181e7FTs0P_33VpxxsA==/base.apk!classes2.dex:00000070ae18f000] (com.modules.demo.MainActivity$2.onClick+84)

#21 pc 00000000005a17fc /apex/com.android.runtime/lib64/libart.so (MterpInvokeInterface+1788)

#22 pc 0000000000130a14 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_interface+20)

#23 pc 00000000001dd962 /system/framework/framework.jar (android.view.View.performClick+34)

#24 pc 000000000059ffdc /apex/com.android.runtime/lib64/libart.so (MterpInvokeVirtual+1352)

#25 pc 0000000000130814 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_virtual+20)

#26 pc 00000000001dd996 /system/framework/framework.jar (android.view.View.performClickInternal+6)

#27 pc 00000000005a22e8 /apex/com.android.runtime/lib64/libart.so (MterpInvokeDirect+1100)

#28 pc 0000000000130914 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_direct+20)

#29 pc 00000000001d92b4 /system/framework/framework.jar (android.view.View.access$3500)

#30 pc 00000000005a2a8c /apex/com.android.runtime/lib64/libart.so (MterpInvokeStatic+1040)

#31 pc 0000000000130994 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_static+20)

#32 pc 00000000001b8bcc /system/framework/framework.jar (android.view.View$PerformClick.run+16)

#33 pc 00000000005a17fc /apex/com.android.runtime/lib64/libart.so (MterpInvokeInterface+1788)

#34 pc 0000000000130a14 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_interface+20)

#35 pc 0000000000323d28 /system/framework/framework.jar (android.os.Handler.handleCallback+4)

#36 pc 00000000005a2a8c /apex/com.android.runtime/lib64/libart.so (MterpInvokeStatic+1040)

#37 pc 0000000000130994 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_static+20)

#38 pc 0000000000323b94 /system/framework/framework.jar (android.os.Handler.dispatchMessage+8)

#39 pc 000000000059ffdc /apex/com.android.runtime/lib64/libart.so (MterpInvokeVirtual+1352)

#40 pc 0000000000130814 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_virtual+20)

#41 pc 0000000000348a84 /system/framework/framework.jar (android.os.Looper.loop+484)

#42 pc 00000000005a2a8c /apex/com.android.runtime/lib64/libart.so (MterpInvokeStatic+1040)

#43 pc 0000000000130994 /apex/com.android.runtime/lib64/libart.so (mterp_op_invoke_static+20)

结合源码 我们hook下ExecuteMterpImpl

executeMterpImpl_stub = shadowhook_hook_sym_name(

"libart.so",

"ExecuteMterpImpl",

(void *) executeMterpImpl_proxy,

(void **) &executeMterpImpl_orig);

调试环境下的backtrace 结合源码 我们hook下ExecuteSwitchImplAsm

executeSwitchImplAsm_stub = shadowhook_hook_sym_name(

"libart.so",

"ExecuteSwitchImplAsm",

(void *) executeSwitchImplAsm_proxy,

(void **) &executeSwitchImplAsm_orig);

方法过滤

  1. 线程id匹配
  2. 方法栈层级限制
  3. 方法名匹配

trace打点方式

调用libandroid.so中的ATrace_beginSection和ATrace_endSection 这样就可以直接使用用systrace的ui查看trace

void *libandroid = xdl_open("libandroid.so", XDL_DEFAULT);

ATrace_beginSection = reinterpret_cast<fp_ATrace_beginSection>(

xdl_sym(libandroid, "ATrace_beginSection", nullptr));

ATrace_endSection = reinterpret_cast<fp_ATrace_endSection>(

xdl_sym(libandroid, "ATrace_endSection", nullptr));

xdl_close(libandroid);

快速开始

不需要重新打包! 不需要重新打包! 不需要重新打包 ! 可以抓到系统api 支持android9-android12

  1. 下载python文件raw.githubusercontent.com/google/perf…

  2. chmod u+x record_android_trace.py

  3. 打开app开发页面 动态配置trace开关，方法过滤

  4. 命令行运行 ./record_android_trace.py -o trace_file.perfetto-trace -a com.test.app -t 10s sched -b 64mb

  5. 打开需要trace的页面，等待浏览器打开ui页面

排查案例

获取应用名影响启动速度问题

启动过程发现主线程经常被其他线程锁住，看信息我们能知道是在complete_thread1的ResourcesManager.getOrCreateResources方法锁住了。用systrace+方法编译时插桩的trace 我们只能知道是com.test.stone相关，但是没法知道具体原因。

image.png 这边使用新的trace工具后。 能很方便的看出是一个子线程在不停的调用PackageItemInfo.loadLable,手机上有多少个应用就会调用几次。业务修改后 恢复正常。

image.png

image.png

xxx framwork crash 相关trace获取

image.png

image.png

image.png

其他app启动流程分析

trace结合xposed我们很容易做到其他app启动分析，对比效果. 非解释执行的方法没法hook 比如走oat和jit的方法，这边的解决方式是通过附加debug的方式强制让app走解释执行。

avatar
文章
阅读
粉丝