标签：一次 YGC 导致系统 XStream 排查 线程 new gc 日志

事件起因是一个mq消费服务出现了消息积压，查看系统请求日志，发现大量请求耗时两三秒以上，甚至10秒以上的消费时间。服务重启后就恢复正常，而且是有规律性的大概2天出现一次。根据以上情况初步判断是和JVM的垃圾回收有关。打印的GC日志如下：

从日志上可以看出一次YGC的时间大概是2.7秒左右，而且是每10秒出现一次，这个STW的时间和频率已经很不正常了，而且问题出在 Ext Root Scanning阶段，也就是堆外 gc roots扫描时间过长。这个Ext Root Scanning一时半会无法找出是什么原因，可能和同步锁有关，也可能和加载的类信息等有关，接下来可以打印出线程栈信息来分析。

    阿里有一款在线诊断利器arthas很好用，thread -n 3 -i 1000 打印出1000ms内最忙的3个线程栈，如下图：

前三个线程栈全指向同一个方法，那就是XStream的XML对象转换方法，查看代码发现这个XStream对象每次都会new一个，问题可能就是出在这里了。进XStream的构造方法看看，发现XStream初始化的对象还真多，里面出现了一个类加载器CompositeClassLoader，而且是每次new出来的

通过截图可以看出，每次操作xml都会通过Class.forName反射操作，java反射本身是有一定的性能开销的，每一次反射操作都会有安全性验证开销，而且也损失一些jvm的优化操作。不过，我认为这只是造成线程性能开销大的原因，gc的时间是耗在 gc roots的扫描上，个人认为这可能是和每一次都new一个CompositeClassLoader加载器有关，这一部分估计是垃圾无法回收的吧，随着时间的推移，每一次扫描耗时过长，从而造成STW耗时长。

    最终解决办法就是XStream对象改成单例的

标签：一次,YGC,导致系统,XStream,排查,线程,new,gc,日志
来源： https://blog.csdn.net/xiaofo258/article/details/121492230

本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享；
2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关；
3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关；
4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除；
5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。