案例 2: 某寿险公司核心系统 GC 开销超限问题分析

简介: 案例 2: 某寿险公司核心系统 GC 开销超限问题分析

概述

某寿险公司的核心系统是运行在 x86 物理服务器上的, x86 物理服务器的性能都挺好,但是系统的性能却不尽如人意。而且之前某寿险公司的核心系统出过几次性能上的问题,但是我们总是找不到根本原因。每次都是重启完了事,也不清楚性能问题究竟对系统造成了什么样的影响。

装上 Dynatrace 之后,立马就有关于某寿险公司核心系统的性能告警,告警是关于 GC 对系统性能造成较大影响 (即 JVM 的 GC 开销超过限制),我们这才知道问题的严重性,也知道了从何下手。之后我们定位到导致系统问题的根源,一个是加载的一个用来监控应用各项参数的javamelody 的 jar 包,另一个是因为 system.gc() 频繁地调用 fullgc,导致系统“stop the world”时间过长。

分析过程

告警

某寿险公司核心系统安装上 Dynatrace 之后,立马出现如下的告警邮件:

GC 异常告警邮件

可以清楚的看到,告警邮件上已经明确的写出了原因,并指出对性能的影响:

原因:进程 XXXX_wls_hx_135a@appserver135:0 的垃圾回收运行状况不正常。 由于在垃圾回收过程中花费大量执行时间,因此应用程序进程的显著挂起时间会持续一段时间。

影响: 过去的 5 分钟内,该进程用于回收垃圾的时间,总是 多于其执行时间 15%

多于其执行时间 15%!是的,直到看到这个告警,我们才意识到性能问题居然这么严重,GC 所花费的时间,在某段时间内已经超过总的执行时间的 15%,而且此告警很频繁。具体如下:

核心大部分机器 gc 告警频繁且持续时间长

可以从上图看出,核心系统的大部分机器都出现了性能问题,并且很频繁,另外有时甚至在长达 1、2 个小时内,GC 时间占用执行时间超过 15%!这是很严重的性能问题。而该问题直到我们使用了 Dynatrace 才首次意识到。

GC 问题优化

针对该问题,为了进一步分析,我们使用了 Dynatrace 自带的仪表图–应用程序进程图表。具体如下:

核心应用程序进程 GC 图表

从这儿可以看出,告警的时候 major gc 垃圾收集时间较长,而 Dynatrace 的 major gc 就是指会导致“stop the world”的 GC。

接下来我们分析了对应的 GC 日志,发现日志中存在大量的system.gc()(就是程序里手动调用该方法),并且每次调用都是执行 full gc。关于 SystemGC 触发 full gc 的解释,我们查到的原因如下:

如果应用使用到 NIO 框架、DirectByteBuffer 或者 MappedByteBuffer 等功能时,上述情况产生的内存是堆外内存,SystemGC 就需要 Full GC 来回收

之后查看资料,发现一种具体的改进方法,具体如下:

加入参数-XX:+ExplicitGCInvokesConcurrent ,该参数并不会禁用 SystemGC,SystemGC 还是会被触发,只是加上该参数后,会使得 system gc 时执行 CMS GC,效率会提高,减少因为 Full GC 引起的 STW 时间。

之后我们在其中一台上添加了该参数,添加之后与其他没有添加的做对比,利用 dynatrace 的自定义仪表板的功能,直接抓取“Suspension Time"(每个时间间隔中 GC 导致的挂起时间)这一参数做对比画出曲线图。发现加了后 GC 导致的暂停时间大幅下降!由于比较早,该图找不到了,附上一张使用另一个小工具分析的结论:

gc 加与不加参数的对比

GC 参数加与不加对比 -2

可以看到,不加该参数,GC 导致的暂停时间有 129.56s;加上该参数后,GC 导致的暂停时间只有 25.04s,是原来暂停时间的 1/5 - 1/6。且加了该参数后,fullGC 从 89 次降到了 0 次。

简而言之:加了之后 GC “stop the world” 时间降低了 100 多秒,full gc 次数为 0。

确认加上该参数可以改善 gc 性能后,我们在核心系统的所有 jvm 里都添加了该参数。加入后,除了其中一台机器还会告警,其他机器运行正常。而那台告警的机器,我们发现还有其他的问题。

javamelody

其中一台,即使加入了上边提到的参数,gc 的性能还是有问题。具体如下图:

其中一台与其他的对比 --gc 暂停时间

可以看到,GC 暂停时间,其他 jvm 都是位于 10ms 左右的数量级,而另一台则是 6000ms 左右的数量级!这对应用造成了较大的影响,具体可以通过 dynatrace 的下图看出:

GC 暂停时间长对应用性能影响

直接导致应用,具体到该系统前端用户的某一请求,由于 gc “stop the world” 导致响应时间大幅增加,原本 100 多 ms 就能完成的请求,直接由于 gc 导致的挂起 多花了7000ms

这次我们使用 dynatrace 自带的 CPU 采样热点分析和内存快照分析工具来进行分析。

  • 直接通过 dynatrace 对该台 jvm 做 heapdump 并直接在 dynatrace 上进行分析,分析结果如下:下图 1-4 的实例都是由 javamelody 这个 jar 包产生的。

javamelody-heapdump

  • 通过 cpu 采样分析,结果如下:直接看出是 javamelody 占用了较多 cpu

javamelody-cpu hotspot

作为对比,其他 jvm 中根本没有加载 javamelody 这个包。

而联系项目组,得到的答复是:

javamelody-JVM 监控程序。可以用来分析具体的问题点。该 jar 包会 定时(较频繁)采集 应用的相关指定的数据,并且对数据进行 打包、压缩、发送

而 javamelody 的这些操作是既消耗 CPU 又消耗 jvm 内存资源。对系统的行能造成了较大的影响。而在我们的建议下,项目组拿掉了这个 jar 包。改用 Dynatrace 的仪表板和报告.

总结

通过 dynatrace,我们发现了核心系统的问题,并快速的分析解决了该问题。解决问题之后,核心系统运行起来平稳而高效。从以前每天都要关注,出了问题抓耳挠腮,变成了今天的风淡云清。

相关文章
|
6月前
|
缓存 Linux
kswapd0内存过高排查经历
kswapd0内存过高排查经历
437 1
|
运维 监控 Java
内存溢出+CPU占用过高:问题排查+解决方案+复盘(超详细分析教程)
全网最全的内存溢出CPU占用过高排查文章,包含:问题出现现象+临时解决方案+复现问题+定位问题发生原因+优化代码+优化后进行压测,上线+复盘
2303 5
|
1月前
|
存储 缓存 监控
HPC Guard | 如何彻底解决OOM及资源浪费的难题?
芯片设计中常遇内存不足、资源利用率低等问题,导致项目延期。MemVerge HPC Guard通过实时监控、任务保护与恢复、智能调度等技术,显著提升资源利用率和任务连续性,解决芯片设计中的常见难题,保障项目顺利进行。
56 0
|
3月前
|
监控 负载均衡 算法
线程数突增!领导说再这么写就GC掉我:深入理解与优化策略
【8月更文挑战第29天】在软件开发的世界里,性能优化总是开发者们绕不开的话题。特别是当面对“线程数突增”这样的紧急情况时,更是考验着我们的技术功底和问题解决能力。今天,我们就来深入探讨这一话题,分享一些工作学习中积累的技术干货,帮助大家避免被“GC”(垃圾回收,也常用来幽默地表示“被炒鱿鱼”)的尴尬。
47 2
|
3月前
|
缓存 监控 Java
"Java垃圾回收太耗时?阿里HBase GC优化秘籍大公开,让你的应用性能飙升90%!"
【8月更文挑战第17天】阿里巴巴在HBase实践中成功将Java垃圾回收(GC)时间降低90%。通过选用G1垃圾回收器、精细调整JVM参数(如设置堆大小、目标停顿时间等)、优化代码减少内存分配(如使用对象池和缓存),并利用监控工具分析GC行为,有效缓解了高并发大数据场景下的性能瓶颈,极大提升了系统运行效率。
76 4
|
4月前
|
缓存 Java Linux
开发与运维内存问题之线上遇到故障,使用jstat命令发现Old区持续增长如何解决
开发与运维内存问题之线上遇到故障,使用jstat命令发现Old区持续增长如何解决
46 2
|
4月前
|
Java BI 运维
开发与运维配置问题之升级机器配置后出现频繁的GC问题和超长的GC时间如何解决
开发与运维配置问题之升级机器配置后出现频繁的GC问题和超长的GC时间如何解决
35 1
|
6月前
|
Java
jvm性能调优 - 17案例实战_每日上亿请求量的电商系统 老轻代垃圾回收参数如何优化
jvm性能调优 - 17案例实战_每日上亿请求量的电商系统 老轻代垃圾回收参数如何优化
189 0
|
6月前
|
缓存 Java 双11
jvm性能调优 - 16案例实战_每日上亿请求量的电商系统 年轻代垃圾回收参数如何优化
jvm性能调优 - 16案例实战_每日上亿请求量的电商系统 年轻代垃圾回收参数如何优化
79 0
|
SQL canal 运维
JVM第六讲:线上环境 FGC 频繁,如何解决?
JVM第六讲:线上环境 FGC 频繁,如何解决?
293 0