线上OOM堆外内存泄漏

73 阅读4分钟

1、问题

        最近有个sso 服务频繁的oom,而且并不是达到JVM上限导致的OOM,而是达到了K8S设置的上限,被K8S Kill掉的,所以没有dump日志。回去看了下日志,一共有两个实例,原先内存分配应该是3G 的时候,平均一个节点一天要被Kill掉十几次。。后来增大到6G 内存,也只是让他能多跑一会,有时候两三天才OOM 一次。

2、DUMP 日志排查   

 让运维协助加上了-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath= 和-Xmx 限制后重新启动了服务,希望让JVM 自己OOM退出并dump下来日志,观察了几天后都没有出现OOM,于是在后几天内存占用量高的时候dump出了日志并没有发现任何异常。

​编辑

​编辑

        这里占用较多的都是日志的对象,看了下代码里日志打印的也并不多,也没有打印任何大的对象 而且JVM HeapSize 限制占用并不高,但是POD占用内存已经3G多。于是也查了一圈资料后,发现可能 堆外内存泄漏的问题。

3、内存泄漏

        好在是SSO 服务,代码量不大,先利用了下AI 排查了出一处可疑 的地方。

 private static String getIp (String Ip) {
        //省略前后代码
           DbSearcher dbSearcher = extracted();
           DataBlock dataBlock = dbSearcher.memorySearch(ip);
        //。。。。

    }


 private static DbSearcher extracted() {
        try {
            DbConfig config = new DbConfig();
            DbSearcher dbSearcher = new DbSearcher(config,IPDBFILEPATH);
            return dbSearcher;
        } catch (Exception e) {
            log.info("创建ip地址搜索器失败[{}]", e);
            return null;
        }
    }

        某个接口调用方法获取IP归属地信息 用开源  ip2region 方法,从本地的DB 文件里搜索。 每次请求都创建了新的DBSearch 对象打开这个DB文件,并且最后也没有关闭。

       查看DBSearch 源码 发现底层调用的是 NIO下的 RandomAccessFile

​编辑

这是一个native 方法,属于GC ROOT 无法被垃圾回收,最终导致内存泄漏。

4、验证

          由于第一次排查这种问题,此前对JVM 也并不了解,根据查询的资料验证验证下是否和我理解一致,打算在测试环境测试一下。

4.1 测试前准备        

  调用前 的内存占用

​编辑

为了内看到内存内容提前 将内存地址打印出来

pmap -x 1 > pmap_$(date +"%Y%m%d_%H%M%S").log

 4.2 接口调用 

 这里通过工具调用了200次接口。

同时打印JVM 信息

​编辑

表头 含义如下:

  • S0C: Survivor 0区当前容量 (KB) - S1C: Survivor 1区当前容量 (KB)

  • S0U: Survivor 0区已使用 (KB) - S1U: Survivor 1区已使用 (KB)

  • EC: Eden区当前容量 (KB)- EU: Eden区已使用 (KB)

  • OC: Old区当前容量 (KB)- OU: Old区已使用 (KB)

  • MC: Metaspace(元空间)容量 (KB)- MU: Metaspace已使用 (KB)

  • CCSC: 压缩类空间容量 (KB)- CCSU: 压缩类空间已使用 (KB)

  • YGC: 年轻代垃圾回收次数- YGCT: 年轻代垃圾回收消耗时间 (s)

  • FGC: 老年代垃圾回收次数(Full GC)- FGCT: 老年代垃圾回收消耗时间 (s)

  • GCT: 垃圾回收总消耗时间 (s

这里可以看到 老年代 的用量飙升,并且通过FULLGC 也并没有好转。

同时top看到 应用占用的内存已经有 2.5G ​编辑

这里也通过了arthas  的memery 打印了内存信息

​编辑

可以看到与实际占用的内存还是要有差距,这里应该就是JNI 调用导致的堆外内存泄漏,接口调用的文件是9.5M ,刚好也和这里大小能对的上。

 于是现在再通过pmap 打印出当前的内存信息

pmap -x 1 > pmap_$(date +"%Y%m%d_%H%M%S").log

和执行前的文件进行比对

icdiff pmap_20250617_142345.log pmap_20250617_142729.log|less -SR

​编辑发现多了很多这些9M左右的内容,随便找了一个通gdb命令获取这内存中的内容

gdb -p 1 -batch -ex "dump memory dump.bin 0x00007f486c000000 0x00007f486c000000+$((9152*1024))" 2>/dev/null

拿到文件后打开虽然里面有很多乱码,但是能显示的部份还是能和那份DB文件对上,于是能确定这些新增的内存里存放的应该都是这份文件了。 

     **  补充:这里后来为了确认真的无法被GC 回收手动通过jcmd 调用了GC 也只能释放100M左右的内存**

4.3  修改后测试

        手动增加close 的代码

finally {
            try {
                dbSearcher.close();
            } catch (IOException e) {
                log.info("IPUtils close ERROR ", e);
            }
        }

再次测试 

调用前内存使用量top

​编辑调用后的top 如下​编辑

这里内存还是增加了

通过arthas 的内存打印结果如下

​编辑

于是我又打印出来了pmap 发现里面还是存在了那份文件。

这就让我比较疑惑,于是我通过手动调用

jcmd <pid> GC.run

发现内存有所下降大概有能降到 但是内存还是偏高了。 

(第一次GC 后能降到1G左右,在此调用200次后手动GC 在1.7G ,后面重复操作了两次都会让内存上升100M左右)

不过我这里的修改也不合理,毕竟每次接口都创建一次这个对象,并高的话可能导致频繁GC影响性能,甚至OOM。

  于是将DBSearch的创建改成了单例模式创建。 

    private static final Object lock = new Object();
    private static volatile DbSearcher dbSearcher;
    private static DbSearcher getDbSearcher() {
        if (dbSearcher == null) {
            synchronized (lock) {
                if (dbSearcher == null) {
                    try {
                        DbConfig config = new DbConfig();
                        dbSearcher  = new DbSearcher(config, IP2REGION);
                    } catch (Exception e) {
                        log.error("初始化DbSearcher失败", e);
                        throw new RuntimeException("IP地址库初始化失败", e);
                    }
                }
            }
        }
        return dbSearcher;
    }

再次测试后完美解决,高并发下内存也没有飙升。

image.png

image.png

5、总结

   由于之前没有这方面经验,并不清楚还有堆外内存的情况一致从dump 文件看,没发现任何异常。最终虽然解决了问题,但是第一次修改的后内存还是偏高的情况,还是没弄清楚,后面会再找时间专门研究下。