记录一次Java进程被“谋杀”的问题排查

白龙马云行技术团队
128 阅读6分钟

一、现象：进程突遭“谋杀”

‌问题表现

  • 公司新服务部署后，经常出现宕机。
  • demsg日志明确记录：Out of memory: Kill process [pid],但JVM自身未抛出OOM异常。 image.png

初步猜想

  • 矛盾点：Java堆内存稳定，宿主机RSS耗费到7G以上后，被内核Kill。

    • 机器配置为4C8G。JVM内存配置：-Xms4096m -Xmx4096m -XX:ThreadStackSize=256 -XX:MaxDirectMemorySize=1024m。

  • 排查方向：基于内存配置以及物理内存表现，猜测为堆外内存泄漏。

二、问题定位：抽丝剥茧内存分配-JIT编译

‌现象还原

  • 缩小压测量级，单机多次执行压测脚本，得到内存增长现象如下。

image.png

问题排查

排除堆内异常引用对象

  • 连续压测，并抓取dump，分析在内存增长各阶段，堆内引用对象量级变化。

jmap -dump:format=b,live,file=bcs.hprof pid

  • 使用JProfiler打开对比,并无明显异常

image.png

image.png

堆外内存使用分析

启动参数增加：-XX:NativeMemoryTracking=detail 注：必须增加到 java后，其余位置不生效。

压测过程中采集指标：jcmd pid VM.native_memory detail 多次执行后对比分布

image.png

  • 通过不同阶段的内存分布对比，初步可以锁定与编译有关。

Linux内存分配分析

pmap -x pid | sort -n -k3 执行后发现有大量的64M的地址

pmap -x pid |grep '65'

基于jcmd的结果，如jcmd中有本文类似的异常结果，可以使jcmd详情中的内存地址区间与pmap结果匹配。如jcmd无明显异常结果，就只能通过pmap 所有的内存地址在jcmd内存地址区间做匹配来确认Native Code申请的堆外内存。

image.png

追踪内存分配的进程线程

strace -o error.log -f -e trace=brk,mmap,munmap -p pid

cat error.log|grep '65'

image.png

根据第⼀列的pid(线程ID), 转为jstack 的16进制的nid: 确认空间由C1/2 Complier 线程分配

image.png

JIT优化排查

添加-XX:+PrintCompilation 打印jit优化的编译⽇志;

确定了执⾏编译优化的类⽂件及涉及的执⾏次数/编译数据⼤⼩；

image.png

  • 通过made not entrant基本确认Jit出现了反优化。

  • 排查对应的类文件，发现字段数对应get/set⽅法达到500+。

  • 排查jit优化主要涉及的两个场景：

    • ⽅法内联
    • ⼤循环逻辑

  • 优先排查⽅法内联，因为涉及到⼤量的get/set短⽅法，符合内联的场景。

    • 跟进代码发现，项目底层框架中为了实现通过配置表的方式进行字段转换，扩展了Jackson的能力。每次调用的get/set，均采用refectasm包中的MethodAccess.get 来进行字节码增强。 image.png
    • 最终类中的每一个get/set方法都生成了类似下图中的增强实现。这么做的原因是因为在执行invoke的时候，可以根据方法id进行调用,比反射更节省资源。 image.png
    • get/set高频次调用，确定符合内联场景，继续确定Jit优化次数是否符合。

java -XX:+PrintFlagsFinal -version | grep CompileThreshold

image.png 通过实体类中的字段和get/set的个数，在结合各阶段转换的次数，基本可达到c2默认的15000次调⽤。

  • 禁用jit内联优化，再次压测，内存增加的现象消失。

Java启动参数增加：-XX:Inline 【生产环境不能禁用。CPU会上升30%以上】

原因总结

  • 项目中实体的get/set较多，调用频次也比较高。
  • 使用时对每一个get/set都进行字节码增强，且增强后的方法体占用较大(MethodAccess.invoke)。
  • JIT对get/set进行内联优化。但最终是对一个超大方法体的MethodAccess.invoke方法执行了优化。
    • MethodAccess.invoke大方法编译的过程需要占用大量的内存。

修复方式

虽然还有些技术细节没有想明白，但基本已经定位是引入了字节码增强导致的。该机制最初是为了优化反射调用性能而引入，但并未充分考虑到对高频方法进行增强后带来的运行时编译开销。文中对于get/set的增强本质上来说是存在缺陷的，会增加方法体的复杂度和执行开销。鉴于临近上线，考虑到重新实现代码增强的成本和不确定因素，最终采用反射替换MethodAccess。

三、深入理解

为什么JIT占用的内存刚好是64M？

对于64M的问题，是一个非常经典的问题，在JVM中并没有这种大量分配64M大小的逻辑，因此可以排除JVM特定意义的分配。这其实是glibc里针对malloc函数分配内存的一种机制，glibc从2.10开始提供的一种机制，为了分配内存更加高效，glibc提供了arena的机制，默认情况下在64位下每一个arena的大小是64M。

glibc 使用内存池为 java 应用通过 malloc 申请堆外内存，当 jvm 回收内存归还操作系统时，操作系统在 free 的时候并不会真正释放内存，而是维护到 glibc 的内存池中供下次使用，从而避免重复申请。

为什么C2会一直分配内存？

针对这个问题百思不得其解，进行了各种google，直到发现已经被提交的Path。

image.png

image.png

image.png

  • 在本文的排查过程中发现，MethodAccess 的实现采用了字节码增强机制。从本质上来说，这种机制必然会触发 ClassRedefine 操作，进而致使 JIT出现 [made not entrant] 情况，并且会触发反优化操作，也就是 “撤销” 之前已经完成的编译。
  • 再结合官方给出的结论，即 “该 BUG 在某些极端情形下，C2 编译器会出现 OOM问题”，基本能够确定那些经过增强处理的 get/set 方法始终处于大方法编译状态，CompieldIC又没有被ResourceMark标记，不会复用内存，从而持续不断地申请新的内存资源。

四、总结

  • 字节码增强技术优势很大，可以实现无侵入式编程，但同样带来的不确定性也更多，在使用时需要保证对于规范和字节码优化机制的正确理解。

  • 相较与堆内，堆外内存的异常查询难度更高，基于本文的查询路径，总结思路如下：

    • 先确认最大堆是否受到控制[Xmx]，如果超出物理内存的75%，就需要调整。

      • 堆内监控手段较多，也可使用原生命令jcmd查看。

    • 再确认最大直接内存有无控制[-XX:MaxDirectMemorySize]。

      • NIO、DateBuffer内存占用

    • Arena区占用是否较多

      • 可以直接使用pmap查看64M的内存占用（这一步可以不挂载NativeMemoryTracking场景重启）。

    • 挂载NativeMemoryTracking detail查看内存分配

      • 如果有明确方向，就可以使用detail中的地址直接定位。
      • 如果没有明确方向，基本上就是native方法导致，需要从pmap结果中找出不属于deital中的内存地址值。

    • 使用strace查看OS申请的内存请求。

      • 这一步对于内存缓慢上升的现象需要长时间采集。

    • 如果到这里还定位不出来，只能使用终极工具jemalloc来排查。[内容太多，后续分享]。

五、参考资料

blog.csdn.net/dl962454/ar…

www.baeldung.com/graal-java-…

mail.openjdk.org/pipermail/j…

bugs.openjdk.org/browse/JDK-…

github.com/jemalloc

avatar
文章
阅读
粉丝