根据今天测试团队的反馈，我认为服务a的响应很慢，测试环境也会变慢。 所以我自己用postman点了接口，真的很慢，竟然需要2s左右。 一般在50ms左右。
因此，当我去测试服务器时，我发现服务器负载很高，服务器a占用了很高的cpu。 首先使用top命令来看load average，都是1.5左右(双核cpu )，某个java进程) 20798 )占用的cpu一直很高。 下图：
因此，在命令jps -l中查看java的20798，正好是服务a。
要说服务a在跑什么，毕竟是测试环境。 所以我们用top -Hp 20798看看哪个线程在跑。 下图：
发现线程20840占用了非常高的cpu，其他几乎都是0。 使用以下命令输出线程id(20840 )的十六进制数字。
printf '%x' 20840
输出如下。
线程id(20840 )的十六进制数为5186。
然后使用以下命令打印线程的堆栈信息。
jstack -l 20798 | grep -A 20 5168
键入以下内容：
知道占用cpu的进程是jvm的GC线程，推测cpu是否由于继续FGC而急剧增加，然后使用以下命令确定FGC的频率和时间：
jstat -gc 20798 1000
输出如下。
我果然发现FGC在不断地进行，每次FGC的时间都一直在上升。 什么在FGC呢？ 大对象一直在创建，不能回收吗？ 然后使用以下命令检查heap中对象的状态：
jap-histo:直播20798|head-20
输出如下。
某个业务类对象居然有150w个，而且占用了264M的堆大小，这是什么情况，以及这150w个对象是否还活着(使用jmap的时候，已经有了3360即时选项，可以生存) 所以赶紧用下面的命令弹出线程堆栈吧：
jstack -l 20798 jstack_tmp.txt
输出如下。
然后，使用以下命令根据输出线程堆栈中的对象类进行搜索：
grep-C30 ' omments ' jstack _ tmp.txt
输出如下。
推测是因为来自db load的CommentsEntity过多。
因此，我们使用以下命令发出dump，发出heapdump并反复确认：
jmap -dump:live，format=b，file=news_busy_live.hprof 20798
将heapdump文件news_busy_live.hprof下载到windows本地，使用mat工具进行分析，首次发现打开后无法打开。 结果，news_busy_live.hprof有3G那么大，mat报告说OOM无法直接打开。 在mat配置文件MemoryAnalyzer.ini中的配置-Xmx1024m、heap size仍为1G，因为发现太小，所以更改为-Xmx4096m，保存，重新打开mat，news _ bubue
发现mat正在分析可能的内存泄漏对象，233w个对象。 (之前用jmap命令输出的150W个是为了之后写文章而特别再现的操作。 这里的233w个是当时真的有问题时从dump中出来的heap dump文件。 ) ) )，太可怕了。
在以下操作中，请参阅
如果单击exclude all .则弱参照、软参照、虚参照等可以通过GC回收，因此exclude输出如下。
因为知道了共有6个线程参照了那个233w个对象，所以去了从前面的dump出来的线程堆栈追踪了以下线程的状况，在堆栈中正好这些线程也处理了comments相关的逻辑这只是碰巧，一般的线程id不匹配，最终在线程处理结束后才释放。 所以，让我们来看看上一个线程堆栈的信息。 此处发布了基于关键字“omment”检索到的线程堆栈的信息。 如下所示。
' xnio-5 task-77 ' # 248 prio=5os _ prio=0tid=0x 00007 fc 4511 be 800n id=0x8f7runn
able [0x00007fc3e5af2000] java.lang.Thread.State: RUNNABLE ... at cn.xxxxxx.news.commons.redis.RedisUtil.setZSet(RedisUtil.java:1080) at cn.xxxxxx.news.service.impl.CommentsServiceV2Impl.setCommentIntoRedis(CommentsServiceV2Impl.java:1605) at cn.xxxxxx.news.service.impl.CommentsServiceV2Impl.loadCommentsFromDB(CommentsServiceV2Impl.java:386) ... at cn.xxxxxx.xxxs.controller.vxxx.xxxxController.getxxxxxx(NewsContentController.java:404) at cn.xxxxxx.xxx.controller.vxxx.xxxxxController$$FastClassBySpringCGLIB$$e7968481.invoke(<generated>) ... at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Locked ownable synchronizers: - <0x00000000f671ecd0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
从上面的堆栈信息，结合前面的猜测（猜测是一次性从db load出太多的CommentsEntity），猜测应该是函数loadCommentsFromDB一次性从db load出太多CommentsEntity了。于是看了一下业务代码，发现load出来的commentsEntity会放到redis的某一个zset，于是使用redis destopmanger看一下这个zset的数据，发现这个zset有22w的数据，从中找出几条，发现对应的newsPk都是同一个，根据newsPk在db中找一下该newsPk的comments总记录，发现该newsPk的comments记录数是38w+条，那就是这个问题了，一次性从db中load了38w+的数据到内存。
一次性load那么多数据到内存，这肯定是一个慢查询，不管是db还是网络io，都肯定很慢。然后发现业务代码还会有一个for循环，把这个CommentsEntityList遍历一遍，一条一条放到redis，这也是一个非常慢的过程。
然后我去看了服务A的access log，发现在短时间内，请求了该newsPk多次数据，所以就导致了jvm的heap空间不够，然后出现不断FGC的现象，并且该newsPk的请求，由于超时，都在网关超时返回了。
为了验证这个问题，我把相关的redis缓存删除，然后调用该newsPk的接口获取数据，发现很慢，并且cpu立刻飚上去了，然后调多几次，并且不断地进行FGC，至此已经复现了该问题，和猜测的一样。等数据load到redis之后，再访问该接口，就很正常没问题。
上面发现问题的代码，找时间做一下优化才行，先重启服务A，让服务可用先。
欢迎关注微信公众号“ismallboy”，请扫码并关注以下公众号，并在公众号下面回复“FGC”，获得本文最新内容。