
本文通过一类 Android 机型上相机拍摄过程中的 native 内存 OOM 的问题展开,借助内存快照裁剪回捞和 Native 内存监控工具的赋能,来深入剖析此类问题。
背景
Raphael 是西瓜视频 Android 团队开发的一款 native 内存监控工具,在字节跳动内部产品(如西瓜、抖音、头条等)上广泛用于监控 native 内存泄漏问题。在抖音 7.8.0-8.3.0 上搜集到大量因虚拟内存触顶而 crash 的内存日志现场(如 pthread_create、GL error、EGL_BAD_ALLOC),其中 60%以上都是 camera 相关的内存泄漏,占整体 crash 的 15%以上(Java & Native)。同时也收到 OPPO 等厂商反馈抖音 app 在其新机型上 native crash 比其他机型高了 3 倍以上,分析厂商提供的日志发现基本都是虚拟内存触顶导致的 carsh,这其中 80%以上都有 camera 相关的内存分配失败的日志。
问题
通过对 native 内存监控搜集到的日志进行堆栈聚合和 so 级的内存占用统计,可以发现截止到 OOM 时工具拦截到的 native 内存总量已经达到了 1.3G 左右(32 位下应用可直接使用的 native 内存上限约 2G),这其中占比最大的是 CameraMetaData 对象间接引用的内存,native 内存泄漏十分严重。

由于 native 内存分配的频率过高,获取 Java 层堆栈又比较耗时,在拦截 native 内存分配时并不适合直接频繁抓取 Java 堆栈。Native 内存不同于 Java 内存,单从拦截到的数据很难直观给出结论。通常对于内存等资源不合理使用导致的资源不足而引发的问题都很难归因,从拦截到的数据来看,CameraMetaData 所引用的内存最大,嫌疑也最大,基于此决定剖析一下这个问题
初步分析
分析 native 内存的分配和释放
通过拦截到的堆栈可以看出,CameraMetaData 的创建堆栈的上层是 Java 调用,最终在 native 层进行的内存分配(boot-framework.oat & libandroid_runtime.so)。CameraMetaData 对象有两部分内存,对象本身 & mBuffer 指向的 camera_metadata_t 所引用的内存;通过源码可知,每个 CameraMetadata 对象的 mBuffer 所指向的 camera_metadata_t 是独立的,彼此是不重叠的。


既然工具能拦截到这么多的未释放的内存分配,一定是因为这些内存的释放逻辑出问题导致的,我们需要优先调查清楚 CameraMetadata.mBuffer 的释放逻辑。通过分析 CameraMetadata.cpp 的源码可知,CameraMetadata::release()并未释放 mBuffer 所指向的内存,而是把 mBuffer 所指向的内存赋值给了另一个 CameraMetadata 对象;CameraMetadata::clear()是真释放,而 clear 的调用有两个场景:一个是在 camera_metadata_t 复用时,另一个是 CameraMetadata 对象析构时。

前述结论可知 CameraMetadata.mBuffer 所指向的 camera_metadata_t 是彼此独立的。通过工具拦截到的堆栈和分配数量猜测,Native OOM 时内存中一定存在大量的 CameraMetadata 实例。C++对象的析构通常是调用 delete 来实现的,AOSP 里想搜索哪里 delete 了一个 CameraMetaData 对象是很难的,因为很难知道 delete 时的变量名。根据一个基本的 C++编程规范,内存通常在哪里创建的,应该就在那里释放,我们全局搜索 new CameraMetaData 字符串就可以很轻松的发现 CameraMetaData 对象的创建和释放均是在/frameworks/base/core/jni/android_hardware_camera2_CameraMetadata.cpp 里实现的。



通过 android_hardware_camera2_CameraMetadata.cpp 里的注册清单可以看到与这些函数关联的 Java 层 class 是 android/hardware/camera2/impl/CameraMetadataNative,CameraMetadata_close 函数在 Java 对应的是 nativeClose 函数。可以进一步发现 CameraMetaDataNative 里 nativeClose 函数是在 close 函数里调用的,而 close 函数又是在 finalize 函数调用的。


通过上述分析可知只有在 CameraMetaDataNative 对象执行 finalize 方法时才会回收与之对应的 native 内存,而 finalize 方法又是在 FinalizerDaemon 线程里执行的,猜测到如果发生了上述堆栈的 native OOM,Java 层一定存在大量还没有执行 finalize 方法的 CameraMetaDataNative 对象。
排查 Java 堆现场
幸运的是我们通过内存快照裁剪工具(Tailor)轻松拿到了大量这类 native OOM 时对应的 Java 堆内存快照文件。这些内存快照文件完美证实了之前的猜想,当发生这类 native OOM 时 Java 层的确存在大量的 CameraMetadataNative 对象。以下图为例,这些 CameraMetadataNative 对象里除 6 个被其他代码引用外,其余对象全部在 FinalizerDaemon 线程的队列里,等待执行 finalize 方法。同时,快照里有 6658 个对象,只有大约 600+对象的 mMetadataPtr 是等于 0 的,说明这部分对象对应的 Native 内存需要在 finalize 时释放,这跟工具拦截的数据是完全匹配的,也间接验证了 Native 内存监控的正确性和可靠性

深入分析
排查 Finalize 执行
虽然上述分析验证了问题,也证实了之前的猜想,但仍未找到导致此类问题的深层次原因,对于最终解决此类问题也仍然束手无策。为什么会有这么多的 CameraMetadataNative 对象等待执行 finalize 方法或许是下一步的调查方向。做过 Java 稳定性治理的同学应该都知道一类很有名的 TimeoutException 异常,这类异常的根本原因是 finalize 执行超时导致的,这个 case 会不会是某个对象的 finalize 执行超时导致的?

结合 FinalizerDaemon 的源码可以看到,每执行一个对象的 finalize 方法时,都会通过 finalizingObject 属性记录当前的对象。如果真的是 finalize 超时导致的,一定存在 finalizingObject 属性不为空的现场。我们在遍历完所有相关内存快照里的 FinalizerDaemon 线程状态后发现,这些现场的 finalizingObject 属性均为空。这个结果很意外,似乎并不是某个对象的 finalize 方法执行超时导致的。

通过分析 FinalizerDaemon 的源码猜测还有另外一种可能,就是该线程的核心逻辑可能 block 在某个同步逻辑上,根据判有两处代码有可能:一个是 FinalizerWatchdogDaemon.INSTANCE.goToSleep() 另一个是 finalizingReference = (FinalizerReference<?>)queue.remove()

源码显示 goToSleep 是个同步方法,可能会 block。但遍历所有相关快照发现所有的 needToWork 属性均是 false,证明已经走过(只有 FinalizerWatchdogDaemon.INSTANCE.goToSleep() 会置为 false,而且这个函数是 private 的,只在 FinalizerDaemon 线程里调用),所以 block 在这里的可能性几乎没有。

通过分析 finalizingReference = (FinalizerReference<?>)queue.remove() 发现这行代码后面的逻辑并没有对 finalizingReference 判空,说明这个地方一定不会返回空。既然不为空, queue.remove() 只能 block 等待,这个 ReferenceQueue.java 的源码也证实了猜想。

其实 block 在这里的原因通常是因为只有在 GC 时才会将需要执行 finalize 的对象加入到 FinalizerDaemon 的队列里。如果一段时间内没有 GC,且队列就为空时,上面的 remove 会一直 block,直到 GC 后才有对象加入到这个队列里。巧合的是我们在发生这类 native OOM 时会通过 Tailor 主动 dump Java 堆的内存快照,而 dump 快照时会触发 GC & suspend,这个最终导致大量的 CameraMetadataNative 对象被同时加入到 FinalizerDaemon.queue 的队列里。
分析 GC 策略
通过上述分析可知如果不是 GC,这些对象是不会被被加入到 FinalizerDaemon.queue 里的,这说明这类 native OOM 发生前的一段时间内一直没有 GC,才导致大量 CameraMetadataNative 对象没有及时执行 finalize,进而发生 native OOM。以上分析也在线下进入到拍摄页后静置观察实验中得到验证,这其中大概每隔 30s-40s 甚至更长时间 Java 堆才会主动触发一次 GC,在这期间 native 内存会不断增长,直到 GC 后才会大幅下降,Java & Native 内存才会恢复到正常水平。虽然问题不是 block 在 finalize 环节,但最终这个问题的原因被锁定在了 GC 逻辑上!


了解 GC 的同学可能会知道 ART 虚拟机的 GC cause 有很多种,kGcCauseForAlloc/kGcCauseBackground 是虚拟机最易频繁触发的。当停留在拍摄页不做任何操作时,程序逻辑相对简单,这期间只有相机服务周期(>=30 次/s)地通过 binder 在应用端触发创建 CameraMetadataNative 对象,并在拍摄页显示一张相机采集到的图像。这个过程 Java 堆只有 CameraMetadataNative 对象创建,而 CameraMetadataNative 自身占用内存比较小,一次 GC 之后 Java 堆内存比较富裕的情况下,虚拟机很长一段时间内不会主动触发 GC。如果这期间 native 内存的增幅过大,在下次 GC 之前触顶就发生 native OOM

综上,这类 native OOM 的根本原因是:当应用自身的 native 内存本身已处于高水位时,开启相机后,相机服务会持续通过 binder 通信在应用侧创建 CameraMetadataNative 对象,创建 CameraMetadataNative 对象的同时也会在应用侧通过 jni 接口在 native 层创建/复用一块存放 camera_metadata_t 的相对比较大的内存。由于 Java 层的 CameraMetadataNative 对象本身比较小,这种连续创建小对象的行为一定时间内很难触发 Java 层的 GC,导致其间接引用的 native 内存不断上涨,最终触发虚拟内存上限而 crash。
解决思路
问题的原因虽然相对比较简单,但如何解决这类问题还是比较难抉择的。既然是 GC 不及时导致的,一种简单的方案就是在拍摄页周期性触发 GC。但如果 GC 间隔比较小,GC 毕竟是耗时的,GC 过于频繁会严重影响拍摄体验;如果 GC 间隔时间比较长,还是会有大概率重蹈这类 native OOM 的覆辙。
主动触发 GC 的方案很难平衡对性能的影响。其实问题的重点不是 Java 层,而是 Java 对象引用的 native 内存,如果及时主动释放这部分内存就可以从根本上彻底解决此类问题。通过前面的分析可以知道,这部分内存原本是在 GC 时的 finalize 环节回收,但如果提前发现 CameraMetadataNative 不再使用时,主动触发来释放这部分内存就可以一劳永逸。通过分析源码可以发现 CameraMetadataNative 传递到应用层之后后续并未再使用,在应用层使用完 CameraMetadataNative 对象之后,通过反射调用 close 函数即可释放其所引用的 native 内存。

线下实验也可以发现,开启主动回收策略后,Native 内存的增长速度比之前大幅降低。这期间 Java 堆 & native 层仍有持续增加的小对象,但 native 的增长速度远小于 Java 层了,这种场景下 Java 内存会在 native 内存触顶之前先触发 GC,而大幅降低了发生 native OOM 的可能

最终该方案上线后,效果十分明显,此类 crash(Java & Native 总占比>15%)基本清零。后续搜集到的内存监控日志里 CameraMetadata 相关的内存基本都在 2M 以内,效果立竿见影!
总结
此类问题存在时间很久,至少从 Android 4.4 开始都是通过 CameraMetadataNative 的 finalize 函数来释放 native 内存。过去拍摄的需求比较简单,绝大多数时候都是使用 ROM 自带的相机应用来拍照,因为这类 app 比较简单,native 内存水位本身很低,很难触发到虚拟内存的上限,所以此类问题并没暴露出来。随着小视频等 app 的兴起,拍摄需求越来越重(特效 &美颜等),app 也越来越复杂,应用自身的 native 内存水位不断上涨,加上 native 内存泄漏等原因,当长时间停留在拍摄页时,这类问题就很容易触发。
此外,CameraMetadata 的内存分配失败时,并不会直接 crash,这个时候有其他内存分配请求时才会触发 crash(如线程创建、GL 内存分配等),这也是很多拍摄过程中相机黑屏问题的根本原因。该方案也不经意间解决了长期存在的拍摄时相机黑屏的疑难问题。
这类问题既有应用自身的原因,也有内存回收策略设计的原因。应用在尽可能减少泄漏的同时,也应该努力降低自身 native 内存水位。AOSP 里利用 Java 的 finalize 方法来释放其间接引用的 native 内存是个偷懒挖坑的设计,类似的案例在 AOSP 里比比皆是。我们在实际开发中,类似内存这种有限的资源应及时回收,甚至可以主动限定对象的生命周期,一旦完成使命就主动回收其占用的内存,避免使用 finalize 逻辑来释放 native 内存。
文中提高的两个工具(Native 内存监控工具 Raphael & Android 堆内存快照裁剪压缩工具)是西瓜视频 Android 团队在长期的内存优化治理中开发的两套高效实用的基础工具,在我司内部各大 app 中应用非常广泛,是内存优化 &稳定性治理的绝对首选。这两套工具我们也会在后续的监控工具建设 &优化治理实践等技术文章中介绍相关技术细节,敬请关注。
本文转载自公众号字节跳动技术团队(ID:toutiaotechblog)。
原文链接:
评论