从零开始的线上故障排查
in with 0 comment

从零开始的线上故障排查

in with 0 comment

最近接手了一个旧服务,这个服务需要定时重启服务,否则内存占用会一直上涨直至 OOM。

经过几天的排查,发现是我对 Linux 和 JVM 的理解出现了问题。

本人对虚拟机的理解只停留在了读过深入理解 Java 虚拟机,并没有啥实战经验。没想到第一次排查线上故障就出现了这么搞笑的事情,主要是代码也不是我写的,给排查加大了难度。

问题排查

输入 top,按 m 按照进程占用内存排序,看下进程占用。

jvm1

容器的内存为 4G,确实是 Java 进程占用了绝大部分的内存,首先需要怀疑是堆内存泄漏。

先用 arthas 看一下,这个工具的界面比较直观,

curl -O https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar
dashboard

jvm3

在观察了一段时间以后发现对象都能正常回收,并没有什么问题。(其实如果我理解没问题的话已经发现可能存在的问题了

把存活对象 dump 下来看一下。这一步开始就因为自己的理解不足开始绕弯了

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

dump 下来的对象有2G多,存活对象只有 94M,可能是堆外内存泄漏了(并不是)

期间使用了 MAT 查看了一下堆内的对象,没有发现什么问题,就不详细展开了。

接下来尝试着排查下堆外内存的问题,在 JVM 参数中添加,然后重启服务。

-XX:NativeMemoryTracking=detail

运行命令(jcmd 相当于jps,忘记命令的时候可以使用 jcmd pid help查看)

先给服务创建一个 baseline,baseline 相当于记录下当前服务的状态,以方便与一段时间后对比。

jcmd pid VM.native_memory baseline

过一段时间后,查看一下内存变化

jcmd pid VM.native_memory summary.diff scale=mb

结果如下

Total: reserved=5190MB +110MB, committed=3945MB +109MB

堆内存使用情况,3.8G
-                 Java Heap (reserved=3800MB, committed=3800MB)
                            (mmap: reserved=3800MB, committed=3800MB)

用于存储类元数据信息使用到的原生内存,总共4015个类,整体实际使用了 26M 内存。
-                     Class (reserved=1049MB +2MB, committed=26MB)
                            (classes #4015 -5)
                            (malloc=1MB #10706 +917)
                            (mmap: reserved=1048MB +2MB, committed=25MB)
 
总共2064个线程,提交内存是 563M,一个线程 1M,由 Xss 设置。
-                    Thread (reserved=563MB +49MB, committed=563MB +49MB)
                            (thread #574 +51)
                            (stack: reserved=560MB +49MB, committed=560MB +49MB)
                            (malloc=2MB #2910 +255)
                            (arena=1MB #1146 +102)
                            
JIT的代码缓存,5702 个类 JIT 编译后代码缓存整体使用25M内存。	
-                      Code (reserved=247MB, committed=25MB +2MB)
                            (malloc=4MB #5702 +270)
                            (mmap: reserved=244MB, committed=22MB +2MB)

GC相关使用到的一些堆外内存,比如GC算法的处理锁会使用一些堆外空间。92M左右。	
-                        GC (reserved=92MB, committed=92MB)
                            (malloc=82MB #354 -11)
                            (mmap: reserved=10MB, committed=10MB)
 
JAVA 编译器自身操作使用到的一些堆外内存
-                  Compiler (reserved=1MB, committed=1MB)
                            (malloc=1MB #1431 +132)
 
Internal:命令行, JVMTI, properties 等占用的内存	
-                  Internal (reserved=166MB +57MB, committed=166MB +57MB)
                            (malloc=166MB +57MB #14410 +1000)
                            
 Symbol:保留字符串(Interned String)的引用与符号表引用放在这里,17M左右
-                    Symbol (reserved=6MB, committed=6MB)
                            (malloc=4MB #31203 -109)
                            (arena=2MB #1)
 
NMT本身占用的堆外内存,1M左右
-    Native Memory Tracking (reserved=1MB, committed=1MB)
                            (tracking overhead=1MB)
 
-               Arena Chunk (reserved=2MB +1MB, committed=2MB +1MB)
                            (malloc=2MB +1MB)
 
-                   Unknown (reserved=63MB, committed=63MB)
                            (mmap: reserved=63MB, committed=63MB)

可以看到 thread 部分涨的比较多。

这时候我看到了这一篇文章,

https://www.jianshu.com/p/0cbc4e44c596

里面有关键的几句话

一般情况下,JVM使用过的内存是不会归还给系统的。目的是牺牲内存来提高稳定性。 这是个大前提。 比如,我们查看java的堆内存占用的时候,因为GC的存在,所以堆内存占用其实一直在变,但是实际上RES并没有因为GC而减少。 因为进程向操作系统申请内存是一个昂贵的过程。

这里如果在某一瞬间大量创建线程,随后线程销毁,会发现内存得不到归还,导致内存一直高占用。使用newCachedThreadPool 就会踩到这个坑。

解决

破案了,应该是jvm虚拟机参数的问题,不知道谁给设置的参数大于了内存。

这里线程占用了 500 M 空间不算在堆或者元空间中,而上面 jvm 参数设置了 3.8 G的堆内存,由于 JVM 申请了内存不会归还,那么堆大小会逐渐接近 3.8 G,加上线程占用的内存,出现了 OOM。

解决方法:调小 xmx,设置参数 xss -2048m xmm -2048m xmn -1024m 结束

结论:排查的时候要仔细看 JVM 参数,JVM 堆大小不能设置的过大。

踩的坑和顺手学到的东西

虽然结论和解决方法很简单,但是没有白来一趟。从 dump 堆分析到尝试着用 pmap dump 堆外内
存,dump 线程查看问题,查看类加载器数量等等,翻了一大堆博客。从头走一遍内存泄漏的流
程,对排查内存问题的命令和工具的熟练度提升了。

MAT 的使用和一堆坑

MAT 这个垃圾真的是一堆问题,MAT 可以到这里下载单独的版本 mat

当用 MAT 打开堆时发现分析大小和堆大小对不上的时候可以开启配置

window–>Preferences–>memory Analuzer–>勾选keep unreachable objects–>apply and close

然后清除缓存重新打开。

MAT 在 mac 上应该是打不开的需要用特殊方法打开。

Mac Mat独立版本打开失败解决方案

在设置这个的时候可以顺手打开 MemoryAnalyzer.ini 把 MAT 的堆大小调大,默认的大小太小了。

推荐 MAT 的博客 https://zhuanlan.zhihu.com/p/56110317

vir 占用过高问题

这是啥 vir 为什么占了 40G

现代操作系统里面分配虚拟地址空间操作不同于分配物理内存。在64位操作系统上,可用的最大虚拟地址空间有16EB,即大概180亿GB。

Java 程序由于自己维护堆的使用,导致调用 glibc 去管理内存的次数较少。 Java 8 开始使用 metaspace 原空间取代永久代,而元空间是存放在操作系统本地内存中,那线程一多,每个线程都要使用一点元空间,每个线程都分配一个 arena,每个都64MB,就会导致巨大的虚拟地址被分配。

工具

jcmd 的使用,pmap perf arthas 的简单使用
https://blog.csdn.net/qianshangding0708/article/details/100978730

参考博客

聊聊HotSpot VM的Native Memory Tracking https://juejin.im/post/6844903806468096013

Java堆外内存增长问题排查 https://blog.csdn.net/qianshangding0708/article/details/100978730

JVM源码分析之Metaspace解密 http://lovestblog.cn/blog/2016/10/29/metaspace/

深入理解堆外内存 Metaspace https://www.javadoop.com/post/metaspace

JVM内存占用情况深入分析 https://www.jianshu.com/p/0cbc4e44c596

JVM 堆外内存泄漏分析(二)https://coderbee.net/index.php/jvm/20190916/1936

Java 进程占用 VIRT 虚拟内存超高的问题研究 https://www.cnblogs.com/seasonsluo/p/java_virt.html