频繁FullGC的排查

2024-05-26 19:32
文章标签 排查 频繁 fullgc

本文主要是介绍频繁FullGC的排查,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!

相对来说,这种情况是最容易出现的,尤其是新功能上线时。

对于 Full GC 较多的情况,其主要有如下两个特征:

  • 线上多个线程的 CPU 都超过了 *** jstack 命令可以看到这些线程主要是垃圾回收线程。
  • 通过 jstat 命令监控 GC 情况,可以看到 Full GC 次数非常多,并且次数在不断增加。

首先我们可以使用 top 命令查看系统 CPU 的占用情况,如下是系统 CPU 较高的一个示例:

top - 08:31:10 up 30 min,  0 users,  load average: 0.73, 0.58, 0.34 
KiB Mem:   2046460 total,  1923864 used,   122596 free,    14388 buffers 
KiB Swap:  1048572 total,        0 used,  1048572 free.  1192352 cached Mem PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND 9 root      20   0 2557160 288976  15812 S  98.0 14.1   0:42.60 java 

可以看到,有一个 Java 程序此时 CPU 占用量达到了 98.8%,此时我们可以复制该进程 id9,并且使用如下命令查看该进程的各个线程运行情况:

top -Hp 9 

该进程下的各个线程运行情况如下:

top - 08:31:16 up 30 min,  0 users,  load average: 0.75, 0.59, 0.35 
Threads:  11 total,   1 running,  10 sleeping,   0 stopped,   0 zombie 
%Cpu(s):  3.5 us,  0.6 sy,  0.0 ni, 95.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st 
KiB Mem:   2046460 total,  1924856 used,   121604 free,    14396 buffers 
KiB Swap:  1048572 total,        0 used,  1048572 free.  1192532 cached Mem PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND 10 root      20   0 2557160 289824  15872 R 79.3 14.2   0:41.49 java 11 root      20   0 2557160 289824  15872 S 13.2 14.2   0:06.78 java 

可以看到,在进程为 9 的 Java 程序中各个线程的 CPU 占用情况,接下来我们可以通过 jstack 命令查看线程 id 为 10 的线程为什么耗费 CPU ***。

需要注意的是, 在 jsatck 命令展示的结果中,线程 id 都转换成了十六进制形式

可以用如下命令查看转换结果,也可以找一个科学计算器进行转换:

root@a39de7e7934b:/# printf "%x\n" 10 
a 

这里打印结果说明该线程在 jstack 中的展现形式为 0xa,通过 jstack 命令我们可以看到如下信息:

"main" #1 prio=5 os_prio=0 tid=0x00007f8718009800 nid=0xb runnable [0x00007f871fe41000] java.lang.Thread.State: RUNNABLE at com.aibaobei.chapter2.eg2.UserDemo.main(UserDemo.java:9) "VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable 

这里的 VM Thread 一行的***显示 nid=0xa,这里 nid 的意思就是操作系统线程 id 的意思,而 VM Thread 指的就是垃圾回收的线程。

这里我们基本上可以确定,当前系统缓慢的原因主要是垃圾回收过于频繁,导致 GC 停顿时间较长。

我们通过如下命令可以查看 GC 的情况:

root@8d36124607a0:/# jstat -gcutil 9 1000 10 S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT 0.00   0.00   0.00  75.07  59.09  59.60   3259    0.919  6517    7.715    8.635 0.00   0.00   0.00   0.08  59.09  59.60   3306    0.930  6611    7.822    8.752 0.00   0.00   0.00   0.08  59.09  59.60   3351    0.943  6701    7.924    8.867 0.00   0.00   0.00   0.08  59.09  59.60   3397    0.955  6793    8.029    8.984 

可以看到,这里 FGC 指的是 Full GC 数量,这里高达 6793,而且还在不断增长。从而进一步证实了是由于内存溢出导致的系统缓慢。

那么这里确认了内存溢出,但是如何查看你是哪些对象导致的内存溢出呢,这个可以 Dump 出内存日志,然后通过 Eclipse 的 Mat 工具进行查看。

如下图是其展示的一个对象树结构:

img

经过 Mat 工具分析之后,我们基本上就能确定内存中主要是哪个对象比较消耗内存,然后找到该对象的创建位置,进行处理即可。

这里主要是 PrintStream 最多,但是我们也可以看到,其内存消耗量只有 12.2%。

也就是说,其还不足以导致大量的 Full GC,此时我们需要考虑另外一种情况,就是代码或者第三方依赖的包中有显示的 System.gc() 调用。

这种情况我们查看 Dump 内存得到的文件即可判断,因为其会打印 GC 原因:

[Full GC (System.gc()) [Tenured: 262546K->262546K(349568K), 0.0014879 secs] 262546K->262546K(506816K), [Metaspace: 3109K->3109K(1056768K)], 0.0015151 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]  
[GC (Allocation Failure) [DefNew: 2795K->0K(157248K), 0.0001504 secs][Tenured: 262546K->402K(349568K), 0.0012949 secs] 265342K->402K(506816K), [Metaspace: 3109K->3109K(1056768K)], 0.0014699 secs] [Times: user=0.00 

比如这里***次 GC 是由于 System.gc() 的显示调用导致的,而第二次 GC 则是 JVM 主动发起的。

 

总结来说,对于 Full GC 次数过多,主要有以下两种原因:

  • 代码中一次获取了大量的对象,导致内存溢出,此时可以通过 Eclipse 的 Mat 工具查看内存中有哪些对象比较多。
  • 内存占用不高,但是 Full GC 次数还是比较多,此时可能是显示的 System.gc() 调用导致 GC 次数过多,这可以通过添加 -XX:+DisableExplicitGC 来禁用 JVM 对显示 GC 的响应。

这篇关于频繁FullGC的排查的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/1005378

相关文章

网络故障排查和tcpdump抓包

网络故障排查: ping一台服务器不通,你如何排查 检查本机ip地址设置  网关和dns服务器是否设置正确 或者ip地址冲突能否上网 看路由器是否有问题 ping服务器是否运行服务器禁止ping   防火墙设置 iptables -A INPUT -P ICMP -j DROPiptables -D INPUT -P ICMP -j DROP用户不能访问服务器 怎么排查 检查用户网络连接检查服

Arthas问题排查工具

简介 Arthas 是Alibaba开源的Java诊断工具,动态跟踪Java代码;实时监控JVM状态,可以在不中断程序执行的情况下轻松完成JVM相关问题排查工作 。支持JDK 6+,支持Linux/Mac/Windows。这个工具真的很好用,而且入门超简单,十分推荐。 使用场景 这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?我改的代码为什么没有执行到?难道是我没

日本某地发生了一件谋杀案,警察通过排查确定杀人凶手必为4个 嫌疑犯的一个。以下为4个嫌疑犯的供词。

日本某地发生了一件谋杀案,警察通过排查确定杀人凶手必为4个 嫌疑犯的一个。以下为4个嫌疑犯的供词。 A说:不是我。 B说:是C。 C说:是D。 D说:C在胡说 已知3个人说了真话,1个人说的是假话。 现在请根据这些信息,写一个程序来确定到底谁是凶手。  static void Main()         {             int killer = 0;             fo

linux运维排查常用命令(开发专享)

cd: 进入到某个目录下 cd hikvision ll:详细展示该目录下有的文件 ll su 用户名:切换用户名 例子: su root 根据字符串在文件中查找信息:Grep –a –i 字符串 文件名 例子: grep -a -i 'indexCode=4a28a0dfe0244c0cbabcd9b2c3b60327' nms.nmsweb.debug.log cat 文

一次关于生产环境服务无故宕机的排查过程

故事的开始 这个故事是在一年之前,当时我们的系统运行在客户的k8s环境上。然后很神奇的是每个月底我们都会服务宕机,当然我们开启了多个实例。当时的容器线条就像心跳图一样(或许有些描述的不太准确,我没有找到当时那个像心电图一样的容器资源监控图)。 第一次的排查 当时我们还是很有信心去解决这个问题的。由于每个月的月底都是业务使用的高峰时段,也就是说,从表象上来看,qps一高,容器就挂。 业务日

排查 MyBatis XML 配置中的 IF 语句与传值名称不匹配的 Bug

文章目录 本文档只是为了留档方便以后工作运维,或者给同事分享文档内容比较简陋命令也不是特别全,不适合小白观看,如有不懂可以私信,上班期间都是在得 前言,在改一个bug得时候发现一个有意思得问题,就是mybatis得xml中if判断得问题,传值名字不匹配依旧可以进行判断,如下图 传值userName,但是有意思得事情出现了,进了if,并且没有报错,尝试了两次都是这

Address localhost:1099 is already in use:tomcat频繁重启端口占用问题

错误提示 Unable to open debugger port (127.0.0.1:58198): java.net.SocketException "Socket closed" Address localhost:1099 is already in use 端口被占用 报错原因 由于短时间内频繁运行tomcat服务器。 为了避免出现这一错误。可以点击刷新uodate

日志框架log4j打印异常堆栈信息携带traceId,方便接口异常排查

一、异常堆栈无traceId 排查定位问题异常痛苦        在日常项目开发中,我们会自定义一个traceId方便,链路追踪。在log4j2.xml 我们可能是这样去配置日志打印格式。 <Console name="CONSOLE" target="SYSTEM_OUT"><PatternLayoutpattern="${APP_NAME} %-d{yyyy-MM-dd HH:mm:ss}

JVM避免频繁的GC

在编写代码时,完全避免垃圾收集(GC)是不可能的,因为Java(以及许多其他现代编程语言)的内存管理是基于自动垃圾收集的。然而,你可以通过一些最佳实践来减少GC的频率和开销,从而优化你的应用程序性能。以下是一些建议: 减少对象创建 尽可能重用对象,而不是每次需要时都创建新对象。 使用对象池来管理可重用对象的生命周期。 优化数据结构 选择合适的数据结构来存储数据,以减少内存占用和访问时间

BeanUtils.copyProperties复制属性失效排查

旁边的同事代码出现了bug, BeanUtils.copyProperties复制失败, 导致target类的值全是null BeanUtils.copyProperties复制是按照字段名称匹配的 首先注意字段名称是否完全对应, 以及对应的字段类型target的get和set类不全, 同事是因为类上没写@Data, 摸鱼帮忙排查了一些, 然后恍然大悟…