sql 未做限制导致的应用 fullGc 排查过程

雨翔河

首页列表关于

2021-11-25 14:27

>  因为怕踩高压线的缘故很多内容不敢发，这篇文章记录的事件实际是在2020年10月发生的.

这是工作以来见到的第N+起sql未做限制导致的内存溢出，依稀还记得上一次看到这类问题时写的文章：

[双十一期间查询服务某节点 OOM 原因分析](https://yuxianghe.net/blog/66)

晚上19点40，同事报了测试环境某服务挂了，当时第一想法是重启，但是重启之后又出现了类似的问题，应用启动后所有的接口不通。

看了下应用日志，没有明显的报错日志刷新，但是ssh到机器上明显感到卡顿，top命令一看，cpu占用非常高。

![](https://cdn.yuxianghe.net/image/blog/84-1.png)

`top -H -p pid` 看了下进程对应的线程：

![](https://cdn.yuxianghe.net/image/blog/84-2.png)

![](https://cdn.yuxianghe.net/image/blog/84-3.png)

将线程id转换为16进制之后在jstack查了下，对应的全是gc线程占用cpu80%以上。

```
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f0ca401e000 nid=0x539 runnable

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f0ca4020000 nid=0x53a runnable

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f0ca4021800 nid=0x53b runnable

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f0ca4023800 nid=0x53c runnable

```

看了下gc日志，3秒一次fullgc，一次gc平均2秒，说明此时去看jstack已经意义不大，应该关注下堆栈情况，什么对象多导致了频繁的gc。

![](https://cdn.yuxianghe.net/image/blog/84-4.png)

先简单的执行了下jmap看个大概：

`jmap -histo:live 1335`
结果如下：

![](https://cdn.yuxianghe.net/image/blog/84-5.png)

八九不离十就是这个对象的问题了：

```
xxx.xxx.xxx.xxx.db.ProductAdRecognitionHistory
```

因为是测试环境，所以用jmap命令没有影响，其次应用此时已经无法提供服务了（生产环境慎重，会stw整个应用）。

导出整个堆栈：

```
jmap -dump:format=b,file=xxxxxheapdump.hprof pid
```

下载好eclipse的mat图形化工具： MemoryAnalyzer

https://www.eclipse.org/mat/

因为堆栈文件有点大，需要设置下mat工具的最大分配堆内存，
修改 MemoryAnalyzer.ini 文件的最大堆内存为 -Xmx8000m

打开 xxxxxheapdump.hprof ，加载完成后查看内存泄漏报告，
发现里面是这样的：

![](https://cdn.yuxianghe.net/image/blog/84-6.png)

```
xxx.xxx.xxx.xxx.db.impl.ProductAdRecognitionHistoryDaoImpl$$EnhancerBySpringCGLIB$$44b54bd5.findByTraceId(Ljava/lang/String;)Ljava/util/List; (Unknown Source)
at xxx.xxx.xxx.xxx.ProductAdRecognitionHistoryServiceImpl.updateAidByTraceId(Ljava/lang/String;Ljava/lang/Long;)V (ProductAdRecognitionHistoryServiceImpl.java:xx)
at xxx.xxx.xxx.xxx.ProductIdentifyServiceImpl.updateRecognitionHistoryxxx(Ljava/lang/String;Ljava/lang/Long;)Z (ProductIdentifyServiceImpl.java:xx)
at xxx.xxx.xxx.xxx.ProductController.advertiseReturnxxx(Ljava/util/List;)xxx/xxx/xx/xx/xx/ServiceResponse; (ProductController.java:xx)
```

疑似内存泄漏的地方都指向了

```
ProductAdRecognitionHistoryServiceImpl.updateAidByTraceId
```

且里面的 ProductAdRecognitionHistory 对象一次执行就有 80w个。

看了下代码，updateAidByTraceId方法是这样的：

![](https://cdn.yuxianghe.net/image/blog/84-7.png)

问题就浮现了，当 traceId为空的时候，会把所有的为空的数据全部查询出来，数据量80w+，和我们的堆栈分析是吻合的。

### 总结
查询语句需要做改进，逻辑上要对这个查询字段进行判断校验，同时查询的sql也要限制查询结果的长度，这样可以防止查询出的数据过大，打爆内存。

类型：工作标签：sql,fullGc,java