调试 ART 垃圾回收

本文档介绍如何调试 Android 运行时 (ART) 垃圾回收 (GC) 的正确性和性能问题。本文档解释了如何使用 GC 验证选项、确定 GC 验证失败的解决方案,以及测量并解决 GC 性能问题。

有关处理 ART 的说明,请参阅 ART 和 DalvikDalvik 可执行格式以及 ART 和 Dalvik 部分的其他页面。有关验证应用行为的其他帮助信息,请参阅在 Android 运行时 (ART) 上验证应用行为

ART GC 概述

ART 是在 Android 4.4 中引入的一个开发者选项,也是 Android 5.0 及更高版本的默认 Android 运行时。我们已不再继续维护和提供 Dalvik 运行时,现在 ART 采用了其字节码格式。请注意,本节仅总结 ART 的 GC。有关其他信息,请观看在 Google I/O 2014 上进行的 Android 运行时演示。

ART 有多个不同的 GC 方案,这些方案包括运行不同垃圾回收器。默认方案是 CMS(并发标记清除)方案,主要使用粘性 CMS 和部分 CMS。粘性 CMS 是 ART 的不移动分代垃圾回收器。它仅扫描堆中自上次 GC 后修改的部分,并且只能回收自上次 GC 后分配的对象。除 CMS 方案外,当应用将进程状态更改为察觉不到卡顿的进程状态(例如,后台或缓存)时,ART 将执行堆压缩。

除了新的垃圾回收器之外,ART 还引入了一种基于位图的新内存分配程序,称为 RosAlloc(插槽运行分配器)。此新分配器具有分片锁,当分配规模较小时可添加线程的本地缓冲区,因而性能优于 DlMalloc。

与 Dalvik 相比,ART CMS 垃圾回收计划在很多方面都有一定的改善:

  • 与 Dalvik 相比,暂停次数从 2 次减少到 1 次。Dalvik 的第一次暂停主要是为了进行根标记,即在 ART 中进行并发标记,让线程标记自己的根,然后马上恢复运行。
  • 与 Dalvik 类似,ART GC 在清除过程开始之前也会暂停 1 次。两者在这方面的主要差异在于:在此暂停期间,某些 Dalvik 阶段在 ART 中并发进行。这些阶段包括 java.lang.ref.Reference 处理、系统弱清除(例如,jni 弱全局等)、重新标记非线程根和卡片预清理。在 ART 暂停期间仍进行的阶段包括扫描脏卡片以及重新标记线程根,这些操作有助于缩短暂停时间。
  • 相对于 Dalvik,ART GC 改进的最后一个方面是粘性 CMS 回收器增加了 GC 吞吐量。不同于普通的分代 GC,粘性 CMS 不移动。年轻对象被保存在一个分配堆栈(基本上是 java.lang. Object 数组)中,而非为其设置一个专用区域。这样可以避免移动所需的对象以维持低暂停次数,但缺点是容易在堆栈中加入大量复杂对象图像而使堆栈变长。

ART GC 与 Dalvik 的另一个主要区别在于 ART GC 引入了移动垃圾回收器。使用移动 GC 的目的在于通过堆压缩来减少后台应用使用的内存。目前,触发堆压缩的事件是 ActivityManager 进程状态的改变。当应用转到后台运行时,它会通知 ART 已进入不再“感知”卡顿的进程状态。此时 ART 会进行一些操作(例如,压缩和监视器压缩),从而导致应用线程长时间暂停。目前正在使用的两个移动 GC 是同构空间压缩和半空间压缩。

  • 半空间压缩将对象在两个紧密排列的碰撞指针空间之间进行移动。这种移动 GC 适用于小内存设备,因为它可以比同构空间压缩稍微多节省一点内存。额外节省出的空间主要来自紧密排列的对象,这样可以避免 RosAlloc/DlMalloc 分配器占用开销。由于 CMS 仍在前台使用,且不能从碰撞指针空间中进行收集,因此当应用在前台使用时,半空间还要再进行一次转换。这种情况并不理想,因为它可能引起较长时间的暂停。
  • 同构空间压缩通过将对象从一个 RosAlloc 空间复制到另一个 RosAlloc 空间来实现。这有助于通过减少堆碎片来减少内存使用量。这是目前非低内存设备的默认压缩模式。相比半空间压缩,同构空间压缩的主要优势在于应用从后台切换到前台时无需进行堆转换。

GC 验证和性能选项

如果您是原始设备制造商 (OEM),就可以更改 GC 类型。要执行该操作,您需要通过 adb 修改系统属性。请记住,这些属性只能在非用户版本或 root 版本上修改。

更改 GC 类型

您可以采用多种方法来更改 ART 使用的 GC 计划。更改前台 GC 计划的主要方法是更改 dalvik.vm.gctype 属性或传递 -Xgc: 选项。您可以通过以逗号分隔的格式传递多个 GC 选项。

为了导出可用 -Xgc 设置的完整列表,可以键入 adb shell dalvikvm -help 来输出各种运行时命令行选项。

以下是将 GC 更改为半空间并打开 GC 前堆验证的一个示例: adb shell setprop dalvik.vm.gctype SS,preverify

  • CMS 也是默认值,指定并发标记清除 GC 计划。该计划包括运行粘性分代 CMS、部分 CMS 和完整 CMS。该计划的分配器是适用于可移动对象的 RosAlloc 和适用于不可移动对象的 DlMalloc。
  • SS 指定半空间 GC 计划。该计划有两个适用于可移动对象的半空间和一个适用于不可移动对象的 DlMalloc 空间。可移动对象分配器默认设置为使用原子操作的共享碰撞指针分配器。但是,如果 -XX:UseTLAB 标记也被传入,则分配器使用线程局部碰撞指针分配。
  • GSS 指定分代半空间计划。该计划与半空间计划非常相似,但区别在于其会将存留期较长的对象提升到大型 RosAlloc 空间中。这样就可明显减少典型用例中需复制的对象。

验证堆

堆验证可能是调试 GC 相关错误或堆损坏的最有用的 GC 选项。启用堆验证会使 GC 在垃圾回收过程中在几个点检查堆的正确性。堆验证与更改 GC 类型的选项相同。启用堆验证后,堆验证会验证根,并确保可访问对象仅引用其他可访问对象。通过传入以下 -Xgc 值可以启用 GC 验证:

  • 如果启用 GC 验证,[no]preverify 将在 GC 启动之前执行堆验证。
  • 如果启用 GC 验证,[no]presweepingverify 将在启动垃圾回收器清除过程之前执行堆验证。
  • 如果启用 GC 验证,[no]postverify 将在 GC 完成清除后执行堆验证。
  • [no]preverify_rosalloc[no]postsweepingverify_rosalloc[no]postverify_rosalloc 也是附加 GC 选项,仅验证 RosAlloc 内部计算的状态。验证的主要内容是,魔数值是否与预期常量匹配,以及可用内存块是否已在 free_page_runs_ 映射中注册。

使用 TLAB 分配器选项

目前,只有 TLAB 选项可以更改分配器而不影响活动 GC 类型。此选项不可通过系统属性使用,但可以通过将 - XX:UseTLAB 传递给 dalvikvm 来启用。该选项的分配代码路径更短,因此分配速度更快。由于此选项需要使用暂停时间相当长的 SS 或 GSS GC 类型,因此默认情况下不启用。

性能

评测 GC 性能主要使用两种工具:GC 时间转储和 systrace。评测 GC 性能问题的最直观方法是使用 systrace 确定哪些 GC 会导致长时间暂停或抢占应用线程。尽管 ART GC 效率相对较高,但是过度分配或错误的变异器行为等都能造成性能问题。

人机工程学

与 Dalvik 相比,ART 在 GC 人机工程学方面存在一些重要差异。与 Dalvik 相比,其中一项重要改进是在我们延后启用并行 GC 时不再分配 GC。但是,此操作存在一个缺点:在某些情况下,不阻止 GC 会导致堆的增长速度比 Dalvik 快。好在 ART 具有堆压缩功能,可在进程变为后台进程状态时对堆进行碎片整理来缓解此问题。

CMS GC 人机工程学有两种定期运行的 GC。理想情况下,GC 人机工程学更多时间运行的是分代粘性 CMS,而非部分 CMS。GC 将一直运行粘性 CMS,直到最后一个 GC 的吞吐量(通过释放的字节数/GC 持续秒数计算得出)小于部分 CMS 的平均吞吐量。发生此情况时,人机工程学将下一个并发 GC 计划为部分 CMS,而非粘性 CMS。部分 CMS 完成后,人机工程学将下一个 GC 更改回粘性 CMS。粘性 CMS 在完成后不会调整堆占用空间限制,这是促使人机工程学发挥作用的一个关键因素。这样,粘性 CMS 的发生频率更高,直到吞吐量低于部分 CMS,最终导致堆增大。

使用 SIGQUIT 获取 GC 性能信息

通过将 SIGQUIT 发送到已运行的应用,或在启动命令行程序时通过将 -XX:DumpGCPerformanceOnShutdown 传递给 dalvikvm,可以获得应用的 GC 性能时序。当应用获得 ANR 请求信号 (SIGQUIT) 时,它将转储与锁定、线程堆栈和 GC 性能相关的信息。

获取 GC 时序转储的方法是使用以下命令:
$ adb shell kill -S QUIT

该操作将在 /data/anr/ 中创建一个 traces.txt 文件。此文件包含一些 ANR 转储信息以及 GC 时序。您可以通过搜索“转储累计 GC 时序”来确定 GC 时序。这些时序会显示一些相关内容。它会显示各 GC 类型的阶段和暂停的直方图信息。暂停信息通常比较重要。例如:

sticky concurrent mark sweep paused:	Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms

This 显示暂停的平均时间为 1.83 ms。该值足够低,在大多数应用中不会导致丢帧,因此无需担心。

需要关注的另一个问题是挂起时间。挂起时间测量在 GC 要求某个线程挂起后,线程到达挂起点所需的时间。该时间包含在 GC 暂停中,所以可用于确定长时间暂停是否是由 GC 缓慢或线程挂起缓慢造成。以下是 Nexus 5 上的正常挂起时间示例:

suspend all histogram:	Sum: 1.513ms 99% C.I. 3us-546.560us Avg: 47.281us Max: 601us

还有一些其他要关注的方面,例如总耗时、GC 吞吐量等。示例如下:

Total time spent in GC: 502.251ms
Mean GC size throughput: 92MB/s
Mean GC object throughput: 1.54702e+06 objects/s

转储已运行应用的 GC 时序的示例如下:

$ adb shell kill -s QUIT <pid>
$ adb pull /data/anr/traces.txt

此时,GC 时序包含在 trace.txt 中。Google 地图的输出示例如下:

Start Dumping histograms for 34 iterations for sticky concurrent mark sweep
ScanGrayAllocSpaceObjects:	Sum: 196.174ms 99% C.I. 0.011ms-11.615ms Avg: 1.442ms Max: 14.091ms
FreeList:	Sum: 140.457ms 99% C.I. 6us-1676.749us Avg: 128.505us Max: 9886us
MarkRootsCheckpoint:	Sum: 110.687ms 99% C.I. 0.056ms-9.515ms Avg: 1.627ms Max: 10.280ms
SweepArray:	Sum: 78.727ms 99% C.I. 0.121ms-11.780ms Avg: 2.315ms Max: 12.744ms
ProcessMarkStack:	Sum: 77.825ms 99% C.I. 1.323us-9120us Avg: 576.481us Max: 10185us
(Paused)ScanGrayObjects:	Sum: 32.538ms 99% C.I. 286us-3235.500us Avg: 986us Max: 3434us
AllocSpaceClearCards:	Sum: 30.592ms 99% C.I. 10us-2249.999us Avg: 224.941us Max: 4765us
MarkConcurrentRoots:	Sum: 30.245ms 99% C.I. 3us-3017.999us Avg: 444.779us Max: 3774us
ReMarkRoots:	Sum: 13.144ms 99% C.I. 66us-712us Avg: 386.588us Max: 712us
ScanGrayImageSpaceObjects:	Sum: 13.075ms 99% C.I. 29us-2538.999us Avg: 192.279us Max: 3080us
MarkingPhase:	Sum: 9.743ms 99% C.I. 170us-518us Avg: 286.558us Max: 518us
SweepSystemWeaks:	Sum: 8.046ms 99% C.I. 28us-479us Avg: 236.647us Max: 479us
MarkNonThreadRoots:	Sum: 5.215ms 99% C.I. 31us-698.999us Avg: 76.691us Max: 703us
ImageModUnionClearCards:	Sum: 2.708ms 99% C.I. 26us-92us Avg: 39.823us Max: 92us
ScanGrayZygoteSpaceObjects:	Sum: 2.488ms 99% C.I. 19us-250.499us Avg: 37.696us Max: 295us
ResetStack:	Sum: 2.226ms 99% C.I. 24us-449us Avg: 65.470us Max: 452us
ZygoteModUnionClearCards:	Sum: 2.124ms 99% C.I. 18us-233.999us Avg: 32.181us Max: 291us
FinishPhase:	Sum: 1.881ms 99% C.I. 31us-431.999us Avg: 55.323us Max: 466us
RevokeAllThreadLocalAllocationStacks:	Sum: 1.749ms 99% C.I. 8us-349us Avg: 51.441us Max: 377us
EnqueueFinalizerReferences:	Sum: 1.513ms 99% C.I. 3us-201us Avg: 44.500us Max: 201us
ProcessReferences:	Sum: 438us 99% C.I. 3us-212us Avg: 12.882us Max: 212us
ProcessCards:	Sum: 381us 99% C.I. 4us-17us Avg: 5.602us Max: 17us
PreCleanCards:	Sum: 363us 99% C.I. 8us-17us Avg: 10.676us Max: 17us
ReclaimPhase:	Sum: 357us 99% C.I. 7us-91.500us Avg: 10.500us Max: 93us
(Paused)PausePhase:	Sum: 312us 99% C.I. 7us-15us Avg: 9.176us Max: 15us
SwapBitmaps:	Sum: 166us 99% C.I. 4us-8us Avg: 4.882us Max: 8us
(Paused)ScanGrayAllocSpaceObjects:	Sum: 126us 99% C.I. 14us-112us Avg: 63us Max: 112us
MarkRoots:	Sum: 121us 99% C.I. 2us-7us Avg: 3.558us Max: 7us
(Paused)ScanGrayImageSpaceObjects:	Sum: 68us 99% C.I. 68us-68us Avg: 68us Max: 68us
BindBitmaps:	Sum: 50us 99% C.I. 1us-3us Avg: 1.470us Max: 3us
UnBindBitmaps:	Sum: 49us 99% C.I. 1us-3us Avg: 1.441us Max: 3us
SwapStacks:	Sum: 47us 99% C.I. 1us-3us Avg: 1.382us Max: 3us
RecordFree:	Sum: 42us 99% C.I. 1us-3us Avg: 1.235us Max: 3us
ForwardSoftReferences:	Sum: 37us 99% C.I. 1us-2us Avg: 1.121us Max: 2us
InitializePhase:	Sum: 36us 99% C.I. 1us-2us Avg: 1.058us Max: 2us
FindDefaultSpaceBitmap:	Sum: 32us 99% C.I. 250ns-1000ns Avg: 941ns Max: 1000ns
(Paused)ProcessMarkStack:	Sum: 5us 99% C.I. 250ns-3000ns Avg: 147ns Max: 3000ns
PreSweepingGcVerification:	Sum: 0 99% C.I. 0ns-0ns Avg: 0ns Max: 0ns
Done Dumping histograms
sticky concurrent mark sweep paused:	Sum: 63.268ms 99% C.I. 0.308ms-8.405ms
Avg: 1.860ms Max: 8.883ms
sticky concurrent mark sweep total time: 763.787ms mean time: 22.464ms
sticky concurrent mark sweep freed: 1072342 objects with total size 75MB
sticky concurrent mark sweep throughput: 1.40543e+06/s / 98MB/s
Total time spent in GC: 4.805s
Mean GC size throughput: 18MB/s
Mean GC object throughput: 330899 objects/s
Total number of allocations 2015049
Total bytes allocated 177MB
Free memory 4MB
Free memory until GC 4MB
Free memory until OOME 425MB
Total memory 90MB
Max memory 512MB
Zygote space size 4MB
Total mutator paused time: 229.566ms
Total time waiting for GC to complete: 187.655us

分析 GC 正确性问题的工具

造成 ART 内部崩溃的原因多种多样。读取或写入对象字段时出现崩溃可能表示存在堆损坏。如果 GC 在运行时崩溃,也可能是由堆损坏造成的。造成堆损坏的原因多种多样,最常见的原因可能是应用代码错误。好在可以使用相关工具调试与 GC 和堆相关的崩溃问题。此类工具包括上面指定的堆验证选项、valgrind 和 CheckJNI。

CheckJNI

验证应用行为的另一种方法是使用 CheckJNI。CheckJNI 是一种添加额外 JNI 检查的模式;出于性能考虑,这些选项在默认情况下并不会启用。此类检查将捕获一些可能导致堆损坏的错误,例如使用无效/过时的局部和全局引用。启用 CheckJNI 的方法如下:

$ adb shell setprop dalvik.vm.checkjni true

Forcecopy 模式是 CheckJNI 的另一部分,对检测超出数组区域末端的写入非常有用。启用后,forcecopy 会促使数组访问 JNI 函数时始终返回带有红色区域的副本。红色区域是返回指针结束/开始处的一个区域,该区域具有特殊值,并在数组释放时得到验证。如果红色区域中的值与预期值不匹配,则通常意味着发生缓冲区溢出或欠载。这将导致 CheckJNI 中止。启用 forcecopy 模式的方法如下:

$ adb shell setprop dalvik.vm.jniopts forcecopy

CheckJNI 应捕获错误的一个示例是超出从 GetPrimitiveArrayCritical 获取的数组末端的写入。该操作很可能会破坏 Java 堆。如果写入位于 CheckJNI 红色区域内,则在调用相应 ReleasePrimitiveArrayCritical 时,CheckJNI 将会捕获该问题。否则,写入将最终损坏 Java 堆中的一些随机对象,并可能会导致之后出现 GC 崩溃。如果崩溃的内存是引用字段,则 GC 可能会捕获错误并输出“Tried to mark not contained by any spaces”的错误消息。

当 GC 尝试标记无法找到空间的对象时,就会发生此错误。在此检查失败后,GC 会遍历根,并尝试查看无效对象是否为根。结果共有两个选项:对象为根或非根。

Valgrind

ART 堆支持可选的 valgrind 工具,这款工具提供了一种方法来检测对无效堆地址的读取和写入操作。ART 可检测应用何时在 valgrind 下运行,并在每个对象分配前后插入红色区域。如果对这些红色区域有任何读取或写入错误,valgrind 将输出错误消息。例如,如果您在通过 JNI 直接访问数组时,越过数组元素末端进行读取或写入,就会出现此类错误。由于 AOT 编译器使用隐式 null 检查,因此建议使用 eng 版本运行 valgrind。另外值得一提的是,valgrind 比正常执行速度慢一个数量级。

以下是一个使用示例:

# build and install
$ mmm external/valgrind
$ adb remount && adb sync
# disable selinux
$ adb shell setenforce 0
$ adb shell setprop wrap.com.android.calculator2
"TMPDIR=/data/data/com.android.calculator2 logwrapper valgrind"
# push symbols
$ adb shell mkdir /data/local/symbols
$ adb push $OUT/symbols /data/local/symbols
$ adb logcat

无效的根示例

如果对象实际上为无效根,则会输出一些有用信息: art E 5955 5955 art/runtime/gc/collector/mark_sweep.cc:383] Tried to mark 0x2 not contained by any spaces

art E  5955  5955 art/runtime/gc/collector/mark_sweep.cc:384] Attempting see if
it's a bad root
art E  5955  5955 art/runtime/gc/collector/mark_sweep.cc:485] Found invalid
root: 0x2
art E  5955  5955 art/runtime/gc/collector/mark_sweep.cc:486]
Type=RootJavaFrame thread_id=1 location=Visiting method 'java.lang.Object
com.google.gwt.corp.collections.JavaReadableJsArray.get(int)' at dex PC 0x0002
(native PC 0xf19609d9) vreg=1

在这种情况下,vreg 1(在 com.google.gwt.corp.collections.JavaReadableJsArray.get 内)应该包含一个堆引用,但实际上包含地址 0x2 的一个无效指针。这显然是一个无效根。要调试此问题,下一步是在 oat 文件中使用 oatdump,并查看具有无效根的方法。在这种情况下,结果证明错误在于 x86 后端的编译器错误。修正该错误的更改列表如下:https://android-review.googlesource.com/#/c/133932/

损坏的对象示例

如果对象不是根,则会输出类似于以下打印内容的消息:

01-15 12:38:00.196  1217  1238 E art     : Attempting see if it's a bad root
01-15 12:38:00.196  1217  1238 F art     :
art/runtime/gc/collector/mark_sweep.cc:381] Can't mark invalid object

当堆损坏不是无效根时,将很难进行调试。此错误消息表示堆中至少含有一个指向无效对象的对象。