本文首发于微信公众号「后厂技术官」

相关文章
Android性能优化系列
Java虚拟机系列

前言

Java虚拟机(三)垃圾标记算法与Java对象的生命周期这篇文章中,提到了Java虚拟机的GC日志。DVM和ART的GC日志与Java虚拟机的日志有较大的区别,这篇文章就对DVM和ART的GC日志进行分析。

1.DVM的GC日志

在 DVM 中,每次垃圾收集都会将GC日志打印到 logcat 中,具体的格式为:

D/dalvikvm: <GC_Reason> <Amount_freed>, <Heap_stats>, <External_memory_stats>, <Pause_time>

可以看到DVM的日志共有5个信息,其中GC Reason有很多种,这里将它单独拿出来进行介绍。

引起GC原因

GC Reason就是指引起GC原因,有以下几种:

  • GC_CONCURRENT:当堆开始填充时,并发GC可以释放内存。
  • GC_FOR_MALLOC:当堆内存已满时,app尝试分配内存而引起的GC,系统必须停止app并回收内存。
  • GC_HPROF_DUMP_HEAP:当你请求创建 HPROF 文件来分析堆内存时出现的GC。
  • GC_EXPLICIT:显示的GC,例如调用System.gc()(应该避免调用显示的GC,信任GC会在需要时运行)。
  • GC_EXTERNAL_ALLOC:仅适用于 API 级别小于等于10 ,用于外部分配内存的GC。

其他信息

除了引起GC原因,其他的信息为:

  • Amount_freed:本次GC释放内存的大小。
  • Heap_stats:堆的空闲内存百分比 (已用内存)/(堆的总内存)。
  • External_memory_stats:API 级别 10 及更低级别的内存分配 (已分配的内存)/(引起GC的阀值)。
  • Pause time:暂停时间,更大的堆会有更长的暂停时间。并发暂停时间显示了两个暂停:一个出现在垃圾收集开始时,另一个出现在垃圾收集快要完成时。

实例分析

D/dalvikvm: GC_CONCURRENT freed 2012K, 63% free 3213K/9291K, external 4501K/5161K, paused 2ms+2ms

这个GC日志的含义为:引起GC的原因是GC_CONCURRENT;本次GC释放的内存为2012K;堆的空闲内存百分比为63%,已用内存为3213K,堆的总内存为9291K;暂停的总时长为4ms。

2.ART的GC日志

ART的GC日志与DVM不同,ART 不会为没有明确请求的垃圾收集打印GC日志。只有在认为GC速度慢时才会打印GC日志,更确切来说,仅在GC暂停超过5ms 或GC持续时间超过 100ms 时才会打印GC日志。如果app未处于可察觉的暂停进程状态,那么它的GC不会被认为是慢速的。ART的GC日志始终会记录显式的垃圾收集。

ART的GC日志具体的格式为:

I/art: <GC_Reason> <GC_Name> <Objects_freed>(<Size_freed>) AllocSpace Objects,
<Large_objects_freed>(<Large_object_size_freed>) <Heap_stats> LOS objects, <Pause_time(s)>

引起GC原因

ART的引起GC原因(GC_Reason)要比DVM多一些,有以下几种:

  • Concurrent: 并发GC,不会使App的线程暂停,该GC是在后台线程运行的,并不会阻止内存分配。
  • Alloc:当堆内存已满时,App尝试分配内存而引起的GC,这个GC会发生在正在分配内存的线程。
  • Explicit:App显示的请求垃圾收集,例如调用System.gc()。与DVM一样,最佳做法是应该信任GC并避免显示的请求GC,显示的请求GC会阻止分配线程并不必要的浪费 CPU 周期。如果显式的请求GC导致其他线程被抢占,那么有可能会导致 jank(App同一帧画了多次)。
  • NativeAlloc:Native内存分配时,比如为Bitmaps或者RenderScript分配对象, 这会导致Native内存压力,从而触发GC。
  • CollectorTransition:由堆转换引起的回收,这是运行时切换GC而引起的。收集器转换包括将所有对象从空闲列表空间复制到碰撞指针空间(反之亦然)。当前,收集器转换仅在以下情况下出现:在内存较小的设备上,App将进程状态从可察觉的暂停状态变更为可察觉的非暂停状态(反之亦然)。
  • HomogeneousSpaceCompact:齐性空间压缩是指空闲列表到压缩的空闲列表空间,通常发生在当App已经移动到可察觉的暂停进程状态。这样做的主要原因是减少了内存使用并对堆内存进行碎片整理。
  • DisableMovingGc:不是真正的触发GC原因,发生并发堆压缩时,由于使用了 GetPrimitiveArrayCritical,收集会被阻塞。一般情况下,强烈建议不要使用 GetPrimitiveArrayCritical,因为它在移动收集器方面具有限制。
  • HeapTrim:不是触发GC原因,但是请注意,收集会一直被阻塞,直到堆内存整理完毕。

垃圾收集器名称

GC_Name指的是垃圾收集器名称,有以下几种:

  • Concurrent mark sweep (CMS):CMS收集器是一种以获取最短收集暂停时间为目标收集器,采用了标记-清除算法(Mark-Sweep)实现。 它是完整的堆垃圾收集器,能释放除了Image Space之外的所有的空间。
  • Concurrent partial mark sweep:部分完整的堆垃圾收集器,能释放除了Image Space和Zygote Spaces之外的所有空间。关于Image Space和Zygote Spaces可以查看Android内存优化(一)DVM和ART原理初探这篇文章。
  • Concurrent sticky mark sweep:分代收集器,它只能释放自上次GC以来分配的对象。这个垃圾收集器比一个完整的或部分完整的垃圾收集器扫描的更频繁,因为它更快并且有更短的暂停时间。
  • Marksweep + semispace:非并发的GC,复制GC用于堆转换以及齐性空间压缩(堆碎片整理)。

其他信息

  • Objects freed:本次GC从非Large Object Space中回收的对象的数量。
  • Size_freed:本次GC从非Large Object Space中回收的字节数。
  • Large objects freed: 本次GC从Large Object Space中回收的对象的数量。
  • Large object size freed:本次GC从Large Object Space中回收的字节数。
  • Heap stats:堆的空闲内存百分比 (已用内存)/(堆的总内存)。
  • Pause times:暂停时间,暂停时间与在GC运行时修改的对象引用的数量成比例。目前,ART的CMS收集器仅有一次暂停,它出现GC的结尾附近。移动的垃圾收集器暂停时间会很长,会在大部分垃圾回收期间持续出现。

实例分析

I/art : Explicit concurrent mark sweep GC freed 104710(7MB) AllocSpace objects, 
21(416KB) LOS objects, 33% free, 25MB/38MB, paused 1.230ms total 67.216ms

这个GC日志的含义为:引起GC原因是Explicit ;垃圾收集器为CMS收集器;释放对象的数量为104710个,释放字节数为7MB;释放大对象的数量为21个,释放大对象字节数为416KB;堆的空闲内存百分比为33%,已用内存为25MB,堆的总内存为38MB;GC暂停时长为1.230ms,GC总时长为67.216ms。

参考资料
Investigating Your RAM Usage