一次线上OOM问题的个人复盘

上个月,我们一个java服务上线后,偶尔会发生内存OOM(Out Of Memory)问题,但由于OOM导致服务不响应请求,健康检查多次不通过,最后部署平台kill了java进程,这导致定位这次OOM问题也变得困难起来。

最终,在多次review代码后发现,是SQL意外地查出大量数据导致的,如下:

<sql id="conditions">
    <where>
        <if test="outerId != null">
            and `outer_id` = #{outerId}
        </if>
        <if test="orderType != null and orderType != ''">
            and `order_type` = #{orderType}
        </if>
        ...
    </where>
</sql>

<select id="queryListByConditions" resultMap="orderResultMap">
    select * from order <include refid="conditions"/> 
</select>

查询逻辑类似上面的示例,在Service层有个根据outer_id的查询方法,然后直接调用了Mapper层一个通用查询方法queryListByConditions。

但我们有个调用量极低的场景,可以不传outer_id这个参数,导致这个通用查询方法没有添加这个过滤条件,导致查了全表,进而导致OOM问题。

我们内部对这个问题进行了复盘,考虑到OOM问题还是蛮常见的,所以给大家也分享下。

事前

在OOM问题发生前,为什么测试阶段没有发现问题?

其实在编写技术方案时,是有考虑到这个场景的,但在提测时,忘记和测试同学沟通此场景,导致遗漏了此场景的测试验证。

关于测试用例不全面,其实不管是疏忽问题、经验问题、质量意识问题或人手紧张问题,从人的角度来说,都很难彻底避免,人没法像机器那样很听话的、不疏漏的执行任何指令。

既然人做不到,那就让机器来做,这就是单元测试、自动化测试的优势,通过逐步积累测试用例,可覆盖的场景就会越来越多。

当然,实施单元测试等方案,也会增加不少成本,需要权衡质量与研发效率谁更重要,毕竟在需求不能砍的情况下,质量与效率的关系是得此失彼,这是任何一本项目管理的书都提到过的。

事中

在感知到OOM问题发生时,由于进程被部署平台kill,导致现场丢失,难以快速定位到问题点。

一般java里面是推荐使用-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/dump/这种JVM参数来保存现场的,这两个参数的意思是,当JVM发生OOM异常时,自动dump堆内存到文件中,但在我们的场景中,这个方案难以生效,如下:

  1. 在堆占满之前,会发生很多次FGC,jvm会尽最大努力腾挪空间,导致还没有OOM时,系统实际已经不响应了,然后被kill了,这种场景无dump文件生成。
  2. 就算有时幸运,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
    fi
else
    echo "No health check failure detected. Exiting gracefully.";
fi 

注:也可以考虑在堆占用高时才dump内存,效果应该差不多。

方案2:容器中挂脚本监控堆占用,占用高时自动dump

#!/bin/bash

while 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 <<<"$data";
    echo "$now_time: $old $fgc";
    if [[ $(echo $old|awk '$1>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 1d; continue; }
    fi
    pre_fgc=$fgc
done

每秒检查老年代占用,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()方法调用时,还是会读取剩余未读数据,查询没法提前终止,故放弃之。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 216,258评论 6 498
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,335评论 3 392
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 162,225评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,126评论 1 292
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,140评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,098评论 1 295
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,018评论 3 417
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,857评论 0 273
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,298评论 1 310
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,518评论 2 332
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,678评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,400评论 5 343
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,993评论 3 325
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,638评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,801评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,661评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,558评论 2 352

推荐阅读更多精彩内容