原创:扣钉日记(微信公众号ID:codelogs),欢迎分享,非公众号转载保留此声明。
上个月,我们一个java服务上线后,偶尔会发生内存OOM(Out Of Memory)问题,但由于OOM导致服务不响应请求,健康检查多次不通过,最后部署平台kill了java进程,这导致定位这次OOM问题也变得困难起来。
最终,在多次review代码后发现,是SQL意外地查出大量数据导致的,如下:
and `outer_id` = #{outerId} and `order_type` = #{orderType} ... select * from order
查询逻辑类似上面的示例,在Service层有个根据outer_id的查询方法,然后直接调用了Mapper层一个通用查询方法queryListByConditions。
但我们有个调用量极低的场景,可以不传outer_id这个参数,导致这个通用查询方法没有添加这个过滤条件,导致查了全表,进而导致OOM问题。
我们内部对这个问题进行了复盘,考虑到OOM问题还是蛮常见的,所以给大家也分享下。
事前
在OOM问题发生前,为什么测试阶段没有发现问题?
其实在编写技术方案时,是有考虑到这个场景的,但在提测时,忘记和测试同学沟通此场景,导致遗漏了此场景的测试验证。
关于测试用例不全面,其实不管是疏忽问题、经验问题、质量意识问题或人手紧张问题,从人的角度来说,都很难彻底避免,人没法像机器那样很听话的、不疏漏的执行任何指令。
既然人做不到,那就让机器来做,这就是单元测试、自动化测试的优势,通过逐步积累测试用例,可覆盖的场景就会越来越多。
当然,实施单元测试等方案,也会增加不少成本,需要权衡质量与研发效率谁更重要,毕竟在需求不能砍的情况下,质量与效率只能二选其一,这是任何一本项目管理的书都提到过的。
事中
在感知到OOM问题发生时,由于进程被部署平台kill,导致现场丢失,难以快速定位到问题点。
一般java里面是推荐使用-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/dump/
这种JVM参数来保存现场的,这两个参数的意思是,当JVM发生OOM异常时,自动dump堆内存到文件中,但在我们的场景中,这个方案难以生效,如下:
- 在堆占满之前,会发生很多次FGC,jvm会尽最大努力腾挪空间,导致还没有OOM时,系统实际已经不响应了,然后被kill了,这种场景无dump文件生成。
- 就算有时幸运,JVM发生了OOM异常开始dump,由于dump文件过大(我们约10G),导致dump文件还没保存完,进程就被kill了,这种场景dump文件不完整,无法使用。
为了解决这个问题,有如下2种方案:
方案1:利用k8s容器生命周期内的Hook
我们部署平台是套壳k8s的,k8s提供了preStop生命周期钩子,在容器销毁前会先执行此钩子,只要将jmap -dump
命令放入preStop中,就可以在k8s健康检查不通过并kill容器前将内存dump出来。
要注意的是,正常发布也会调用此钩子,需要想办法绕过,我们的办法是将健康检查也做成脚本,当不通过时创建一个临时文件,然后在preStop脚本中判断存在此文件才dump,preStop脚本如下:
if [ -f "/tmp/health_check_failed" ]; then echo "Health check failed, perform dumping and cleanups..."; pid=`ps h -o pid --sort=-pmem -C java|head -n1|xargs`; if [[ $pid ]]; then jmap -dump:format=b,file=/home/work/logs/applogs/heap.hprof $pid fielse echo "No health check failure detected. Exiting gracefully.";fi
注:也可以考虑在堆占用高时才dump内存,效果应该差不多。
方案2:容器中挂脚本监控堆占用,占用高时自动dump
#!/bin/bashwhile sleep 1; do now_time=$(date +%F_%H-%M-%S) pid=`ps h -o pid --sort=-pmem -C java|head -n1|xargs`; [[ ! $pid ]] && { unset n pre_fgc; sleep 1m; continue; } data=$(jstat -gcutil $pid|awk 'NR>1{print $4,$(NF-2)}'); read old fgc <<80{print $0}') ]]; then (( n++ )) else (( n=0 )) fi if [[ $n -ge 3 || $pre_fgc && $fgc -gt $pre_fgc && $n -ge 1 ]]; then jstack $pid > /home/dump/jstack-$now_time.log; if [[ "$@" =~ dump ]];then jmap -dump:format=b,file=/home/dump/heap-$now_time.hprof $pid; else jmap -histo $pid > /home/dump/histo-$now_time.log; fi { unset n pre_fgc; sleep 1m; continue; } fi pre_fgc=$fgcdone
每秒检查老年代占用,3次超过80%或发生一次FGC后还超过80%,记录jstack、jmap数据,此脚本保存为jvm_old_mon.sh文件。
然后在程序启动脚本中加入nohup bash jvm_old_mon.sh dump &
即可,添加dump参数时会执行jmap -dump
导全部堆数据,不添加时执行jmap -histo
导对象分布情况。
事后
为了避免同类OOM case再次发生,可以对查询进行兜底,在底层对查询SQL改写,当发现查询没有limit时,自动添加limit xxx,避免查询大量数据。
优点:对数据库友好,查询数据量少。
缺点:添加limit后可能会导致查询漏数据,或使得本来会OOM异常的程序,添加limit后正常返回,并执行了后面意外的处理。
我们使用了Druid连接池,使用Druid Filter实现的话,大致如下:
public class SqlLimitFilter extends FilterAdapter { // 匹配limit 100或limit 100,100 private static final Pattern HAS_LIMIT_PAT = Pattern.compile( "LIMIT\\s+[\\d?]+(\\s*,\\s*[\\d+?])?\\s*$", Pattern.CASE_INSENSITIVE); private static final int MAX_ALLOW_ROWS = 20000; /** * 若查询语句没有limit,自动加limit * @return 新sql */ private String rewriteSql(String sql) { String trimSql = StringUtils.stripToEmpty(sql); // 不是查询sql,不重写 if (!StringUtils.lowerCase(trimSql).startsWith("select")) { return sql; } // 去掉尾部分号 boolean hasSemicolon = false; if (trimSql.endsWith(";")) { hasSemicolon = true; trimSql = trimSql.substring(0, trimSql.length() - 1); } // 还包含分号,说明是多条sql,不重写 if (trimSql.contains(";")) { return sql; } // 有limit语句,不重写 int idx = StringUtils.lowerCase(trimSql).indexOf("limit"); if (idx > -1 && HAS_LIMIT_PAT.matcher(trimSql.substring(idx)).find()) { return sql; } StringBuilder sqlSb = new StringBuilder(); sqlSb.append(trimSql).append(" LIMIT ").append(MAX_ALLOW_ROWS); if (hasSemicolon) { sqlSb.append(";"); } return sqlSb.toString(); } @Override public PreparedStatementProxy connection_prepareStatement(FilterChain chain, ConnectionProxy connection, String sql) throws SQLException { String newSql = rewriteSql(sql); return super.connection_prepareStatement(chain, connection, newSql); } //...此处省略了其它重载方法}
本来还想过一种方案,使用MySQL的流式查询并拦截jdbc层ResultSet.next()
方法,在此方法调用超过指定次数时抛异常,但最终发现MySQL驱动在ResultSet.close()
方法调用时,还是会读取剩余未读数据,查询没法提前终止,故放弃之。