• DruidDataSource导致OOM问题处理


    DruidDataSource导致OOM问题处理

    起因

    一个平凡的工作日,我像往常一样完成产品提出的需求的业务代码,突然收到了监控平台发出的告警信息。本以为又是一些业务上的 bug 导致的报错,一看报错发现日志写着java.lang.OutOfMemoryError: Java heap space。

    接着我远程到那台服务器上,但是卡的不行。于是我就用top命令查了一下 cpu 信息,占用都快要到 99%了。再看看 GC 的日志发现程序一直在 Full GC,怪不得 cpu 占用这么高。

    这里就推测是有内存泄漏的问题导致 GC 无法回收内存导致OOM。为了先不影响业务,就先让运维把这个服务重启一下,果然重启后服务就正常了。

    分析日志

    先看一下报错日志详细写了一些什么错误信息,虽然一般OOM问题日志不能准确定位到问题,但是已经打开日志平台了,看一下作为参考也是不亏的。

    看到日志中写的OOM事发场景是在计算多个用户的总金额的时候出现的,大致伪代码如下:

    /**
     * OrderService.java
     */
    
    // 1. 根据某些参数获取符合条件的用户 id 列表
    List<Long> customerIds = orderService.queryCustomerIdByParam(param); 
    
    // 2. 计算这些用户 id 的金额总和
    long principal = orderMapper.countPrincipal(customerIds);
    
    
    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    <!-- 
    
     OrderMapper.xml
    
    -->
    
    <!-- 3.OrderMapper 的 xml 文件中写 mybatis 的 sql 逻辑 -->
    <select id="countPrincipal" resultType="java.lang.Long">
        select
        IFNULL(sum(remain_principal),0)
        from
        t_loan where
        <if test="null != customerIds and customerIds.size > 0">
            customer_id in
            <foreach collection="customerIds" item="item" index="index" open="("
                     close=")" separator=",">
                #{item}
            </foreach>
        </if>
    </select>
    
    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20

    感觉出问题的原因是由于计算金额总额时,查询参数customerIds太多了。由于前段时间业务的变更,导致在参数不变的情况下,查询出的customerIds列表由原来的几十几百个 id 变成了上万个,就我看的报错信息这里的日志打印出来这个 list 的大小就有三万多个customerId。不过就算查询条件为三万多个而导致 sql 执行的比较慢,但是这个方法只有内部的财务系统才会调用,业务量没那么大,也不应该导致OOM的出现啊。 所以接着再看一下JVM打印出来的 Dump 文件来定位到具体的问题。

    分析Dump文件

    得益于在 JVM 参数中加了-XX:+HeapDumpOnOutOfMemoryError参数,在发生OOM的时候系统会自动生成当时的 Dump 文件,这样我们可以完整的分析“案发现场”。这里我们使用 Eclipse Memory Analyzer 工具来帮忙解析 Dump 文件。
    在这里插入图片描述
    从 Overview 中的饼图可以很明显的看到有个蓝色区域占了最大头,这个类占了 245.6MB 的内存。再看左侧的说明写着DruidDataSource.
    在这里插入图片描述
    再通过 Domainator_Tree 界面可以看到是com.alibaba.druid.pool.DruidDataSource类下的com.alibaba.druid.stat.JdbcDataSourceStat$1对象里面有个 LinkedHashMap,这个 Map 持有了 600 多个 Entry,其中大约有 100 个 Entry 大小为 2000000 多字节(约 2MB)。而 Entry 的 key 是 String 对象,看了一下 String 的内容大约都是select IFNULL(sum remain_principal),0) from t_loan where customer_id in (?, ?, ?, ? …,果然就是刚才错误日志所提示的代码的功能。

    问题分析

    由于计算这些用户金额的查询条件有 3 万多个所以这个 SQL 语句特别长,然后这些 SQL 都被JdbcDataSourceStat中的一个 HashMap 对象所持有导致无法 GC,从而导致OOM的发生.

    处理

    接下来去看了一下JdbcDataSourceStat的源码,发现有个变量为LinkedHashMap sqlStatMap的 Map。并且还有个静态变量和静态代码块.

    private static JdbcDataSourceStat global;
    
    static {
    	String dbType = null;
    	{
    	String property = System.getProperty("druid.globalDbType");
    	if (property != null && property.length() > 0) {
    		dbType = property;
    	}
    	global = new JdbcDataSourceStat("Global", "Global", dbType);
    }
    
    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11

    这就意味着除非手动在代码中释放global对象或者remove掉sqlStatMap里的对象,否则sqlStatMap就会一直被持有不能被 GC 释放。

    已经定位到问题所在了,不过简单的从代码上看无法判定这个sqlStatMap具体是有什么作用,以及如何使其释放掉,于是到网上搜索了一下,发现在其 Github 的 Issues 里就有人提出过这个问题了。每个 sql 语句都会长期持有引用,加快 FullGC 频率。

    sqlStatMap这个对象是用于Druid的监控统计功能的,所以要持有这些 SQL 用于展示在页面上。由于平时不使用这个功能,且询问其他同事也不清楚为何开启这个功能,所以决定先把这个功能关闭。

    根据文档写这个功能默认是关闭的,不过被我们在配置文件中开启了,现在去掉这个配置就可以了.

    <bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource"
          init-method="init" destroy-method="close">
        ...
        
        
    bean>
    
    • 1
    • 2
    • 3
    • 4
    • 5
    • 6

    原文来源: https://zzzzbw.cn/article/20/

  • 相关阅读:
    并发性,时间和相对性(1)-确定前后关系
    深入探究 JVM 频繁 Full GC 的排查过程
    读懂这篇,让你了解CRM核心功能
    Goland环境配置——Goland上的第一个Go语言程序
    【高阶乐理】即兴演奏——和弦进行的重要原则(现代流行乐)
    0.开发中的问题与解决方案
    python基础-运算符
    【异步任务】异步线程后台执行解压缩,finished后通知调用者
    SpringBoot同时支持HTTPS与HTTP
    DC-6靶场下载及渗透实战详细过程(DC靶场系列)
  • 原文地址:https://blog.csdn.net/weixin_42202992/article/details/133697063