Log4J日志打印引发的OOM问题排查

发表于 2022-09-11 更新于 2023-12-26 分类于 Question

使用Eclipse Memory Analyzer 排查 Log4J日志打印引发的OOM问题

问题排查

问题描述

服务在没有预警的情况下莫名重启; 经过查询日志平台, 发现以下的日志

java.lang.OutOfMemoryError: Java heap space
Dumping heap to /dump/service_name_a1b21.hprof …
Heap dump file created [1568487987 bytes in 9.043 secs]

问题分析

下载 service_name_a1b21.hprof 堆的 dump 文件
使用 Eclipse Memory Analyzer 打开 hprof 文件
打开 Leak Suspects 扇形图
查询错误栈信息
查看 Dominator Tree(支配树)
根据 Retain Heap 排序, 发现 char[]0x7c0400000;char[]0x7aa100000;char[]0x791500000, 三个字符串内容基本相同, 并且占用内存较大
结合错误栈信息和代码, 定位出是由于日志打印所需的字符串参数拼接时, 无法分配足够的内存导致的

解决方案

尽量减少打印内容(如为空字段无需打印)
调整打印方式, 对于大批量的数据, 分批次打印甚至不打印

相关

参考链接

Eclipse MAT 工具使用说明

Eclipse MAT 工具概念说明

MAT

下载

最新版本
 历史版本

最新可使用jdk8的版本: Memory Analyzer 1.10.0 Release

概念说明

outgoing references ：表示该对象的出节点（被该对象引用的对象）。
incoming references ：表示该对象的入节点（引用到该对象的对象）。

同类代码

import org.codehaus.jackson.map.ObjectMapper;
import org.slf4j.LoggerFactory;

import java.io.IOException;
import java.text.SimpleDateFormat;
import java.util.ArrayList;
import java.util.Date;
import java.util.List;
import java.util.Random;

/**
 * Jvm 参数: -Xmx30m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\develop\mat\workspace\test
 * <p>
 * <p>
 * -Xmx30m: 堆内存设置为 30M
 * -XX:+HeapDumpOnOutOfMemoryError 当JVM发生OOM时，自动生成 DUMP 文件。
 * -XX:HeapDumpPath=D:\develop\mat\workspace\test 参数表示生成 DUMP 文件的路径或者文件路径
 *
 * @author devinx3
 */
public class DumpTest {

    private static final int BYTE_TO_MB = 1024 * 1024;

    public static void main(String[] args) {
        Object data = mockData();
        int contentMemory = getContentMemory(toJSON(data));
        // 打印字节大小
        System.out.println("mock data json size = " + contentMemory + " Byte; " + contentMemory / 1024 / 1024.0 + " Mb");
        log(data);
    }

    /**
     * 字符串内容占用内存
     */
    public static int getContentMemory(String str) {
        return str.length() * 2;
    }

    /**
     * mock 数据
     */
    public static Object mockData() {
        Random random = new Random(BYTE_TO_MB);
        int times = 4;
        int total = BYTE_TO_MB / 2 * times - random.nextInt(BYTE_TO_MB / 8);
        int singleTimes = total / times;
        List<char[]> list = new ArrayList<>();
        for (int i = 0; i < times; i++) {
            // 2M
            char[] bytes = new char[singleTimes];
            for (int j = bytes.length - 1; j >= 0; j--) {
                bytes[j] = (char) ('0' + random.nextInt(10));
            }
            list.add(bytes);
        }
        return list;
    }

    /**
     * 转成 JSON 字符串
     */
    public static String toJSON(Object obj) {
        ObjectMapper objectMapper = new ObjectMapper();
        try {
            return objectMapper.writeValueAsString(obj);
        } catch (IOException e) {
            throw new RuntimeException(e);
        }
    }


    /**
     * 打印日志
     */
    public static void log(Object obj) {
        printMemory();
        // 问题发生点
        LoggerFactory.getLogger(DumpTest.class).debug("log_obj: {}", toJSON(obj));
        printMemory();
    }


    /**
     * 打印内存使用情况
     */
    public static void printMemory() {
        try {
            // 睡眠 100ms
            Thread.sleep(100);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
        String date = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date());
        // 虚拟机级内存情况查询
        Runtime rt = Runtime.getRuntime();
        long max = rt.maxMemory();
        long free = rt.freeMemory();
        long usable = max - free;
        System.out.println("================================================================" + date);
        System.out.println("JVM已使用内存 = " + (usable / BYTE_TO_MB));
        System.out.println("JVM未使用内存 = " + (free / BYTE_TO_MB));
        System.out.println("JVM最大(已分配)内存 = " + (max / BYTE_TO_MB));
        System.out.println("================================================================" + date);
    }
}

问题排查

问题描述

问题分析

解决方案

相关

参考链接

MAT

相关工具

同类代码