记一次由于Nacos频繁GC导致的Java内存飚高问题排查

本菜熊又来查项目问题了，最近项目接口莫名奇妙的经常超时，这个问题排查了很久了一直没有找到原因，今天想一次性解决了。

1. Java程序内存飚高

• top命令查询资源使用情况

top

查询结果如下图所示，可以看到pid=18426这个进CPU狂飙到168%，但同时内存确只占有1%。

pid=18426的进程CPU使用率飙升到168%，但内存使用率仅占1%。这种现象说明了以下几点：

1. CPU密集型任务：该进程正在执行大量计算密集型任务，例如复杂的计算、数据处理或图形渲染等。这些任务通常需要大量的CPU资源，但可能不需要大量的内存。
2. 线程使用情况：CPU使用率超过100%通常表示该进程使用了多个线程。在多核CPU系统中，单个进程可以使用多个核心，因此CPU使用率可以超过100%。比如，168%可能表示该进程在一个四核系统中使用了接近1.68个核心的计算能力。
3. 内存需求低：该进程当前的操作或任务不需要大量的内存资源。这可能是因为它处理的数据量较小，或者数据的存取主要发生在缓存（如L1、L2缓存）而不是主内存。
4. 优化的代码：该进程可能使用了一些优化的算法或数据结构，使得它在执行过程中更加依赖于CPU计算而不是内存存取。

• 具体查看java程序对应的pid

ps -ef | grep java 

• 这边项目采用docker部署，所以需要去docker内查询

至此为止，我们查到docker中实际运行的java程序的pid是0，进一步我们可以去查询该进程到底出现了什么问题。

2. 排查gc问题

Java程序性能问题当中最大可能是GC问题导致的，这里首先排查GC是否有问题。

2.1 排查docker容器内部的问题

• jstat -gc 查询gc情况

该命令可以显示gc的信息，查看gc的次数，及时间。其中最后五项，分别是young gc的次数，young gc的时间，full gc的次数，full gc的时间，gc的总时间。

从 jstat -gc 1 命令输出中，可以看出Java虚拟机（JVM）垃圾回收（GC）的详细信息。下面是对各个字段的解释和分析：

• S0C 和 S1C：Survivor 0 区和 Survivor 1 区的容量（以KB为单位）。
• S0U 和 S1U：Survivor 0 区和 Survivor 1 区的使用量（以KB为单位）。
• EC：Eden 区的容量（以KB为单位）。
• EU：Eden 区的使用量（以KB为单位）。
• OC：老年代（Old Generation）的容量（以KB为单位）。
• OU：老年代（Old Generation）的使用量（以KB为单位）。
• MC：方法区（Metaspace）的容量（以KB为单位）。
• MU：方法区（Metaspace）的使用量（以KB为单位）。
• CCSC：压缩类空间（Compressed Class Space）的容量（以KB为单位）。
• CCSU：压缩类空间（Compressed Class Space）的使用量（以KB为单位）。
• YGC：从应用程序启动到采样时发生的年轻代（Young Generation）GC次数。
• YGCT：从应用程序启动到采样时年轻代GC所用的时间（以秒为单位）。
• FGC：从应用程序启动到采样时发生的完全GC（Full GC）次数。
• FGCT：从应用程序启动到采样时完全GC所用的时间（以秒为单位）。
• GCT：从应用程序启动到采样时垃圾回收总时间（以秒为单位）。

2.2 具体数据分析

• S0C 和 S1C（19456.0 KB）：两个Survivor区的容量都是19456 KB，说明每个Survivor区大约19 MB。
• S0U（980.5 KB）和 S1U（0.0 KB）：Survivor 0 区使用了980.5 KB，Survivor 1 区没有使用。
• EC（1753600.0 KB）和 EU（192574.8 KB）：Eden区的容量是1753600 KB（约1.75 GB），使用了192574.8 KB（约188 MB）。
• OC（1144320.0 KB）和 OU（540014.0 KB）：老年代的容量是1144320 KB（约1.1 GB），使用了540014 KB（约527 MB）。
• MC（184320.0 KB）和 MU（172109.0 KB）：方法区容量是184320 KB（约180 MB），使用了172109 KB（约168 MB）。
• CCSC（21248.0 KB）和 CCSU（19217.6 KB）：压缩类空间容量是21248 KB（约21 MB），使用了19217.6 KB（约18.8 MB）。
• YGC（6234）和 YGCT（60.432 秒）：年轻代GC次数为6234次，总共花费了60.432秒。
• FGC（6）和 FGCT（1.219 秒）：完全GC次数为6次，总共花费了1.219秒。
• GCT（61.651 秒）：垃圾回收总时间为61.651秒。

2.3 总结

1. 年轻代（Young Generation）使用情况：

   • Eden区使用量相对较小，占总容量的一小部分。
   • Survivor区几乎没有使用（S1U为0，S0U也很小）。

2. 老年代（Old Generation）使用情况：

   • 老年代使用量约为50%，这表明对象在年轻代的GC后被转移到老年代。
   • 老年代的GC次数和时间相对较少（6次，1.219秒），表明Full GC的频率和耗时较低。

3. 方法区（Metaspace）使用情况：

   • 方法区和压缩类空间的使用量接近总容量，可能需要监控以防止溢出。

4. 垃圾回收效率：

   • 年轻代GC非常频繁，但每次GC的耗时很短（总计6234次，60.432秒）。
   • 全局GC次数较少，总耗时较短（6次，1.219秒）。

从上面的结果看起来，目前GC性能看起来较好，但应持续监控老年代和方法区的使用情况，防止内存溢出。如果老年代的使用量持续增加，可能需要调整堆内存参数或优化应用程序代码，以减少Full GC的频率。也就说明，程序性能问题不是docker内部的GC问题导致的，我们需要看看是不是其它问题导致的。

2.2 排查服务器本身gc问题

• 使用命令top

top

观察服务器本身的top命令运行的情况，发现经常运行CMS垃圾回收器，这是一个老年代的垃圾回收器，说明服务本身出现了严重gc问题。Java进程在服务器上经常运行，并且使用了CMS（Concurrent Mark-Sweep）垃圾收集器，以下是可能原因：

1. 高负载的Java应用程序：应用程序本身可能在进行大量的计算或处理大量请求，导致CPU使用率高。
2. 频繁的垃圾收集：虽然CMS垃圾收集器旨在减少垃圾收集的暂停时间，但它在并发标记和清除阶段可能会消耗大量的CPU资源。尤其是当老年代（Old Generation）使用率高时，CMS可能频繁启动。
3. 内存不足：如果堆内存设置过小，可能导致频繁的GC（包括Minor GC和Full GC），进而增加CPU使用率。

• 使用命令ps -ef | grep java

ps -ef | grep java

从上面命令输出结果可以看出来，频繁的cms垃圾回收是由于nacos导致的，然后本熊一查nacos关于频繁gc的问题，一下子就出来了，以下是官方文档：

nacos.io/news/faq/na…

3. 调优nacos的JVM

Nacos频繁gc问题的解决有官方文档，如下：nacos.io/news/faq/na…

3.1 查看docker内部nacos的jvm设置

在Docker容器中查看正在运行的Java进程的JVM参数，可以使用以下方法：

1. 使用jcmd命令

jcmd命令可以用来查看JVM参数。如果容器中安装了jcmd，可以使用以下步骤查看JVM参数：

1. 进入Docker容器：

   docker exec -it <container_id> /bin/bash
   

   将<container_id>替换为你的Docker容器ID。

2. 查找Java进程的PID：

   ps -ef | grep java
   

3. 使用jinfo查看JVM参数：

   jinfo -flags <pid>
   

如上图所示的JVM参数当中，新生代和老年代的设置比例主要由以下参数决定：

• -Xms256m: 设置初始堆内存为256MB。
• -Xmx256m: 设置最大堆内存为256MB。
• -Xmn512m: 设置新生代内存为512MB。
• -XX:SurvivorRatio=8: 设置Eden区和Survivor区的比例为8:1:1（即Eden区是Survivor区的8倍，每个Survivor区占整个新生代的1/10）。

在Nacos的官方建议当中是调整到如下设置：

java -Xms512m -Xmx2048m -Xmn1024m -XX:+UseG1GC -jar nacos-server.jar

因此，本熊调整了自己项目当中的nacos的jvm参数的设置就解决了问题，具体docker启动nacos设置参数的方法如下： github.com/nacos-group…

服务器又恢复了往日的宁静：

THE END

这个问题其实困扰我蛮久了，一直怀疑是自己写的Java代码有内存泄漏啥的，结果一排查是Nacos频繁GC导致的问题，希望能够给大家有类似问题的提供一个参考。