关于kafka:一个诡异的Kafka消息OOM问题趁机扒一扒StringBuilder

起源是某个客户线上环境的一次 OOM，据说这种诡异的 OOM 曾经第二次了。首先形容一下 OOM 的相干信息：

堆内存 13G；
应用 G1 垃圾收集器；
OOM 后主动生成的 dump 文件 7G；
利用大抵性能是生产 kafka 数据，通过一些业务解决而后再次发回 kafka【单条音讯据说 32M 左右】

客户的疑点：

堆内存 13G，dump 文件 7G，明明内存是够的，怎么就 OOM 了？

因为线上环境问题，不能随便复盘调试，只有一份内存 Dump 文件能够剖析。

此处无截图（遗记了），脑补😅。一度狐疑是 kafka 的本地缓存导致的 OOM。个别状况 RecordAccumulator 和KafkaProducer是一一对应的【KafkaProducer每次初始化的时候在结构行数中创立 RecordAccumulator 实例】。然而客户说 KafkaProducer 是存在 ThreadLocal 中的，不会无限度创立，即 RecordAccumulator 也不会无限度创立。

先保留此处问题可能性（而且 RecordAccumulator 透露的话也无法解释：明明内存是够的，怎么就 OOM 了？这个疑点）。

发现 kafka producer 的业务线程栈有 OOM 的内容：

kafka producer 回调函数中呈现 RecordTooLargeExeception 报错

kafka producer 开始记录谬误日志

剖析完一圈内存 Dump，我给了本人一个大胆的猜测，会不会是理论的堆内存够的，而是触发了某个别的什么条件，导致显示的抛出了 OutOfMemoryError 的报错。

带着这个纳闷，还是把注意力放在了线程栈上，再认真一看，忽然悟出了点什么。线程栈中是打印谬误日志的过程中抛出的 OOM 报错。而且是在构建日志音讯的过程中进行字符串拼接，进而进行 StringBuilder 扩容引起的数组拷贝，而后就是 OOM 了。至此，我把留神里转移到了 StringBuilder 上。

带着下面所以的猜测，认真翻阅了一下 StringBuilder 中append()的源码以及扩容机制。

在 StringBuilder 中，有一个字符数组叫 value【申明在父类 AbstractStringBuilder 中】，这个才是用来寄存字符串内容的（在 String 类中同样有）。

StringBuilder.append()办法最终会调用父类的 java.lang.AbstractStringBuilder#append(java.lang.String) 办法，源码如下：

public AbstractStringBuilder append(String str) {if (str == null)
            return appendNull();
        // 获取要追加的字符串长度
        int len = str.length();
        // 查看 StringBuilder 中字符数组的容量，以确保能够追加胜利
        ensureCapacityInternal(count + len);
        str.getChars(0, len, value, count);
        count += len;
        return this;
    }

接下来看 ensureCapacityInternal() 办法：

能够看到，如果新字符串长度大于原来的字符串长度就会进行一次数组的拷贝。而且留神下面的正文：如果数值溢出，会抛出OutOfMemoryError。感觉我的猜测马上要被印证了，冲动 ing。

认真看 newCapacity() 办法，

    /**
     * The maximum size of array to allocate (unless necessary).
     * Some VMs reserve some header words in an array.
     * Attempts to allocate larger arrays may result in
     * OutOfMemoryError: Requested array size exceeds VM limit
     */
    private static final int MAX_ARRAY_SIZE = Integer.MAX_VALUE - 8;

    /**
     * Returns a capacity at least as large as the given minimum capacity.
     * Returns the current capacity increased by the same amount + 2 if
     * that suffices.
     * Will not return a capacity greater than {@code MAX_ARRAY_SIZE}
     * unless the given minimum capacity is greater than that.
     *
     * @param  minCapacity the desired minimum capacity
     * @throws OutOfMemoryError if minCapacity is less than zero or
     *         greater than Integer.MAX_VALUE
     */
    private int newCapacity(int minCapacity) {
        // overflow-conscious code
        // 新数组的长度为原来数组长度的 2 倍➕2
        int newCapacity = (value.length << 1) + 2;
        // 如果追加新字符所需起码的数组长度 大于 newCapacity，则将 minCapacity 的值赋给 newCapacity
        // 这种状况只呈现在追加的字符串长度是原字符串长度的 2 倍多的多
        if (newCapacity - minCapacity < 0) {newCapacity = minCapacity;}
        // 如果 newCapacity 大于 Integer.MAX_VALUE - 8，则走 hugeCapacity 的逻辑
        // 否则间接返回 newCapacity
        return (newCapacity <= 0 || MAX_ARRAY_SIZE - newCapacity < 0)
            ? hugeCapacity(minCapacity)
            : newCapacity;
    }

MAX_ARRAY_SIZE的值是 Integer.MAX_VALUE – 8。并且正文给了提醒：这是数组最大的长度了（除非必要），调配大数组可能导致 OOM。

再看 hugeCapacity() 办法，

    private int hugeCapacity(int minCapacity) {
        // 如果追加新字符所需起码的数组长度 大于 Integer.MAX_VALUE，间接 OOM
        if (Integer.MAX_VALUE - minCapacity < 0) { // overflow
            throw new OutOfMemoryError();}
        /**
        * 如果追加新字符所需起码的数组长度 大于 Integer.MAX_VALUE - 8，* 则新数组长度是 minCapacity，否则数组长度就是 MAX_ARRAY_SIZE 的值
        * 在 minCapacity 大于 Integer.MAX_VALUE 一半的时候的最近一次扩容，* 新数组长度会间接应用 MAX_ARRAY_SIZE
        **/
        return (minCapacity > MAX_ARRAY_SIZE)
            ? minCapacity : MAX_ARRAY_SIZE;
    }

重点一句话总结下：字符串长度大于 Integer.MAX_VALUE 就会间接 OOM。

那问题又来了：

32M 的音讯，再怎么扩容也不会超过 Integer.MAX_VALUE 的值吧；
看上面的 demo，这尼玛和 Integer.MAX_VALUE 差太多了吧；

莫慌，咱们持续（手摇轮椅上路）🦽。

先说论断，这个其实和 以后可用堆内存有关系。

先放一组数据：Integer.MAX_VALUE大小的字符数组大略须要占用 4G 堆内存（2147483646*2/1024/1024/1024）。

先看下我本地做的两个试验，顺便温习一下 GC log。

启动参数（GC 没配置，jdk8 默认 PS 垃圾回收）：-Xmx8g -Xms8g -XX:+PrintGCDetails -XX:+PrintHeapAtGC -Xloggc:gc.log

✨GC 日志如下：

Java HotSpot(TM) 64-Bit Server VM (25.281-b09) for bsd-amd64 JRE (1.8.0_281-b09), built on Dec  9 2020 12:44:49 by "java_re" with gcc 4.2.1 Compatible Apple LLVM 10.0.0 (clang-1000.11.45.5)
Memory: 4k page, physical 33554432k(1613060k free)

/proc/meminfo:

CommandLine flags: -XX:InitialHeapSize=8589934592 -XX:MaxHeapSize=8589934592 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 2446848K, used 1436457K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 68% used [0x0000000715580000,0x000000076d04a5f8,0x0000000795600000)
  from space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
  to   space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
 ParOldGen       total 5592576K, used 3538944K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 63% used [0x00000005c0000000,0x0000000698000020,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
7.302: [GC (Allocation Failure) [PSYoungGen: 1436457K->1444K(2446848K)] 4975401K->3540396K(8039424K), 0.0133225 secs] [Times: user=0.16 sys=0.00, real=0.01 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 2446848K, used 1444K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x00000007957691e0,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 3538952K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 63% used [0x00000005c0000000,0x0000000698002020,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=2 (full 0):
 PSYoungGen      total 2446848K, used 1444K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x00000007957691e0,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 3538952K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 63% used [0x00000005c0000000,0x0000000698002020,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
7.316: [GC (Allocation Failure) [PSYoungGen: 1444K->1491K(2446848K)] 3540396K->3540451K(8039424K), 0.0185590 secs] [Times: user=0.23 sys=0.00, real=0.02 secs] 
Heap after GC invocations=2 (full 0):
 PSYoungGen      total 2446848K, used 1491K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x00000007aab00000,0x00000007aac74db8,0x00000007c0000000)
  to   space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
 ParOldGen       total 5592576K, used 3538960K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 63% used [0x00000005c0000000,0x0000000698004020,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=3 (full 1):
 PSYoungGen      total 2446848K, used 1491K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x00000007aab00000,0x00000007aac74db8,0x00000007c0000000)
  to   space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
 ParOldGen       total 5592576K, used 3538960K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 63% used [0x00000005c0000000,0x0000000698004020,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
7.334: [Full GC (Allocation Failure) [PSYoungGen: 1491K->0K(2446848K)] [ParOldGen: 3538960K->2360557K(5592576K)] 3540451K->2360557K(8039424K), [Metaspace: 3918K->3918K(1056768K)], 0.2781291 secs] [Times: user=2.89 sys=0.16, real=0.28 secs] 
Heap after GC invocations=3 (full 1):
 PSYoungGen      total 2446848K, used 0K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
  to   space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
 ParOldGen       total 5592576K, used 2360557K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065013b760,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=4 (full 1):
 PSYoungGen      total 2446848K, used 0K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
  to   space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
 ParOldGen       total 5592576K, used 2360557K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065013b760,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
7.613: [GC (Allocation Failure) [PSYoungGen: 0K->0K(2446848K)] 2360557K->2360557K(8039424K), 0.0177683 secs] [Times: user=0.22 sys=0.00, real=0.01 secs] 
Heap after GC invocations=4 (full 1):
 PSYoungGen      total 2446848K, used 0K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 2360557K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065013b760,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=5 (full 2):
 PSYoungGen      total 2446848K, used 0K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 2360557K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065013b760,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
7.630: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(2446848K)] [ParOldGen: 2360557K->2360504K(5592576K)] 2360557K->2360504K(8039424K), [Metaspace: 3918K->3918K(1056768K)], 0.0095262 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
Heap after GC invocations=5 (full 2):
 PSYoungGen      total 2446848K, used 0K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 0% used [0x0000000715580000,0x0000000715580000,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 2360504K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065012e1d8,0x0000000715580000)
 Metaspace       used 3918K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

Heap
 PSYoungGen      total 2446848K, used 52441K [0x0000000715580000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 2097664K, 2% used [0x0000000715580000,0x00000007188b67e8,0x0000000795600000)
  from space 349184K, 0% used [0x0000000795600000,0x0000000795600000,0x00000007aab00000)
  to   space 349184K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007c0000000)
 ParOldGen       total 5592576K, used 2360504K [0x00000005c0000000, 0x0000000715580000, 0x0000000715580000)
  object space 5592576K, 42% used [0x00000005c0000000,0x000000065012e1d8,0x0000000715580000)
 Metaspace       used 3926K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 430K, capacity 460K, committed 512K, reserved 1048576K

能够看到最初通过 Full GC 后，字符数组被挪到了老年代，此时老年代占用 2360504K，正好是长度为 1207959551 的字符数组的大小。此时如果要再进行扩容，新数组长度就是Integer.MAX_VALUE - 8，也就是须要在堆内存再调配将近 4G 的数组，然而不论是年老代还是老年代，都容不下这 4G 大小，因而也就 OOM 了。

启动参数（GC 没配置，jdk8 默认 PS 垃圾回收）：-Xmx16g -Xms16g -XX:+PrintGCDetails -XX:+PrintHeapAtGC -Xloggc:gc.log
【eden：5588992K ParOldGen：11185152K】

✨GC 日志如下：

Java HotSpot(TM) 64-Bit Server VM (25.281-b09) for bsd-amd64 JRE (1.8.0_281-b09), built on Dec  9 2020 12:44:49 by "java_re" with gcc 4.2.1 Compatible Apple LLVM 10.0.0 (clang-1000.11.45.5)
Memory: 4k page, physical 33554432k(942232k free)

/proc/meminfo:

CommandLine flags: -XX:InitialHeapSize=17179869184 -XX:MaxHeapSize=17179869184 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 4893184K, used 2788885K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 66% used [0x000000066ab00000,0x0000000714e85418,0x000000076ab00000)
  from space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
  to   space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
 ParOldGen       total 11185152K, used 10747904K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 96% used [0x00000003c0000000,0x0000000650000010,0x000000066ab00000)
 Metaspace       used 3914K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
18.887: [GC (Allocation Failure) [PSYoungGen: 2788885K->1488K(4893184K)] 13536789K->10749400K(16078336K), 0.0556800 secs] [Times: user=0.39 sys=0.21, real=0.05 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 4893184K, used 1488K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ac74010,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 10747912K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 96% used [0x00000003c0000000,0x0000000650002010,0x000000066ab00000)
 Metaspace       used 3914K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=2 (full 1):
 PSYoungGen      total 4893184K, used 1488K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ac74010,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 10747912K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 96% used [0x00000003c0000000,0x0000000650002010,0x000000066ab00000)
 Metaspace       used 3914K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
18.943: [Full GC (Ergonomics) [PSYoungGen: 1488K->0K(4893184K)] [ParOldGen: 10747912K->4195565K(11185152K)] 10749400K->4195565K(16078336K), [Metaspace: 3914K->3914K(1056768K)], 0.9751963 secs] [Times: user=2.33 sys=4.18, real=0.98 secs] 
Heap after GC invocations=2 (full 1):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 4195565K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 37% used [0x00000003c0000000,0x00000004c013b720,0x000000066ab00000)
 Metaspace       used 3914K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=3 (full 1):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389869K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c013b728,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
20.945: [GC (Allocation Failure) [PSYoungGen: 0K->0K(4893184K)] 8389869K->8389869K(16078336K), 0.0296937 secs] [Times: user=0.38 sys=0.00, real=0.03 secs] 
Heap after GC invocations=3 (full 1):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
  to   space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
 ParOldGen       total 11185152K, used 8389869K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c013b728,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=4 (full 1):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
  to   space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
 ParOldGen       total 11185152K, used 8389869K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c013b728,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
20.975: [GC (Allocation Failure) [PSYoungGen: 0K->0K(4893184K)] 8389869K->8389869K(16078336K), 0.0293211 secs] [Times: user=0.37 sys=0.00, real=0.04 secs] 
Heap after GC invocations=4 (full 1):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389869K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c013b728,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=5 (full 2):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389869K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c013b728,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
21.019: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(4893184K)] [ParOldGen: 8389869K->4195332K(11185152K)] 8389869K->4195332K(16078336K), [Metaspace: 3916K->3916K(1056768K)], 0.4611617 secs] [Times: user=5.40 sys=0.04, real=0.46 secs] 
Heap after GC invocations=5 (full 2):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 4195332K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 37% used [0x00000003c0000000,0x00000004c0101090,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=6 (full 2):
 PSYoungGen      total 4893184K, used 83886K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 2% used [0x000000066ab00000,0x000000066fceb868,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389636K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c0101098,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
21.963: [GC (Allocation Failure) [PSYoungGen: 83886K->0K(4893184K)] 8473522K->8389636K(16078336K), 0.0356100 secs] [Times: user=0.46 sys=0.00, real=0.04 secs] 
Heap after GC invocations=6 (full 2):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
  to   space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
 ParOldGen       total 11185152K, used 8389636K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c0101098,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=7 (full 2):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x0000000795580000,0x0000000795580000,0x00000007c0000000)
  to   space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
 ParOldGen       total 11185152K, used 8389636K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c0101098,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
21.999: [GC (Allocation Failure) [PSYoungGen: 0K->0K(4893184K)] 8389636K->8389636K(16078336K), 0.0234444 secs] [Times: user=0.30 sys=0.00, real=0.02 secs] 
Heap after GC invocations=7 (full 2):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389636K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c0101098,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=8 (full 3):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389636K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c0101098,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
22.023: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(4893184K)] [ParOldGen: 8389636K->4195323K(11185152K)] 8389636K->4195323K(16078336K), [Metaspace: 3916K->3916K(1056768K)], 0.4557171 secs] [Times: user=5.56 sys=0.04, real=0.46 secs] 
Heap after GC invocations=8 (full 3):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 4195323K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 37% used [0x00000003c0000000,0x00000004c00fedf8,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=9 (full 3):
 PSYoungGen      total 4893184K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 4194304K, 0% used [0x000000066ab00000,0x000000066ab00000,0x000000076ab00000)
  from space 698880K, 0% used [0x000000076ab00000,0x000000076ab00000,0x0000000795580000)
  to   space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
 ParOldGen       total 11185152K, used 8389627K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c00fee00,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
22.976: [GC (Allocation Failure) [PSYoungGen: 0K->0K(5590528K)] 8389627K->8389627K(16775680K), 0.0401370 secs] [Times: user=0.52 sys=0.00, real=0.04 secs] 
Heap after GC invocations=9 (full 3):
 PSYoungGen      total 5590528K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 0% used [0x000000066ab00000,0x000000066ab00000,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 8389627K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c00fee00,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=10 (full 3):
 PSYoungGen      total 5590528K, used 4194304K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 75% used [0x000000066ab00000,0x000000076ab00008,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 8389627K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c00fee00,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
25.776: [GC (Allocation Failure) --[PSYoungGen: 4194304K->4194304K(5590528K)] 12583931K->12583931K(16775680K), 0.0263122 secs] [Times: user=0.32 sys=0.00, real=0.02 secs] 
Heap after GC invocations=10 (full 3):
 PSYoungGen      total 5590528K, used 4194304K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 75% used [0x000000066ab00000,0x000000076ab00008,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 8389627K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c00fee00,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

{Heap before GC invocations=11 (full 4):
 PSYoungGen      total 5590528K, used 4194304K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 75% used [0x000000066ab00000,0x000000076ab00008,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 8389627K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 75% used [0x00000003c0000000,0x00000005c00fee00,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
25.802: [Full GC (Ergonomics) [PSYoungGen: 4194304K->0K(5590528K)] [ParOldGen: 8389627K->4195328K(11185152K)] 12583931K->4195328K(16775680K), [Metaspace: 3916K->3916K(1056768K)], 0.8243356 secs] [Times: user=1.74 sys=1.38, real=0.83 secs] 
Heap after GC invocations=11 (full 4):
 PSYoungGen      total 5590528K, used 0K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 0% used [0x000000066ab00000,0x000000066ab00000,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 4195328K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 37% used [0x00000003c0000000,0x00000004c0100008,0x000000066ab00000)
 Metaspace       used 3916K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 429K, capacity 460K, committed 512K, reserved 1048576K
}

Heap
 PSYoungGen      total 5590528K, used 4343344K [0x000000066ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5588992K, 77% used [0x000000066ab00000,0x0000000773c8c0c0,0x00000007bfd00000)
  from space 1536K, 0% used [0x00000007bfe80000,0x00000007bfe80000,0x00000007c0000000)
  to   space 1536K, 0% used [0x00000007bfd00000,0x00000007bfd00000,0x00000007bfe80000)
 ParOldGen       total 11185152K, used 4195328K [0x00000003c0000000, 0x000000066ab00000, 0x000000066ab00000)
  object space 11185152K, 37% used [0x00000003c0000000,0x00000004c0100008,0x000000066ab00000)
 Metaspace       used 3924K, capacity 4568K, committed 4864K, reserved 1056768K
  class space    used 430K, capacity 460K, committed 512K, reserved 1048576K

能够看到老年代占用为 4195328K，这个是扩容前字符数组所占大小，年老代 eden 区 4194304K，是扩容后长度 2147483646 的新数组的大小。因而在 16G 的堆上通过几次 Full GC 的整顿，最终可能实现 StringBuilder 的顶格扩容。

须要留神的是⚠️：demo 中只有一个 StringBuilder，在理论环境中势必存在很多其余的对象，因而根本不存在
StringBuilder 顶格扩容的状况。更多的是在 StringBuilder 扩容时，可能随同着其余对象的调配，而导致
Arrays#copyOf 办法抛出 OOM。

论断：
1. StringBuilder在扩容的时候，会进行字符数组拷贝，在数组长度小于 Integer.MAX_VALUE 一半的状况下，会创立一个新数组用于拷贝，新数组长度是原数组的 2 倍➕2【此时内存占用：原数组大小➕2* 原数组大小】；
2. 如果数组超过 Integer.MAX_VALUE 的一半的时候的最近一次扩容，新数组长度间接应用 MAX_ARRAY_SIZE（Integer.MAX_VALUE – 8）；
3. 在 16G 堆内存默认比例划分的状况下，字符数组能力胜利扩容至 Integer.MAX_VALUE 长度（⚠️留神，这里的 demo 仅仅只有 StringBuilder 对象，理论状况必定还有很多其余对象，因而理论环境很少有 StringBuilder 能够实现顶格扩容）；
4. 在扩容的过程中，新数组的大小如果 eden 区调配不下，则进行一次 Young GC，如果还是无奈调配，则间接在老年代调配；如果老年待也调配不下，则进行 Full GC【可能进行几轮 Full GC】，之后还是调配不下则 OOM（抛出的中央是在 java.util.Arrays#copyOf(char[], int) 的new char[newLength]创立新数组的时候）；

1. 前言

2. 线上 Dump 文件剖析

2.1 问题点 1 – kafka 的 RecordAccumulator 占用大量内存

2.2 问题点 1 – 线程栈里的 OOM 信息

2.3 问题点 2 – 线程栈中有 kafka 音讯发送失败的信息

2.4 问题点 3 – RecordTooLargeExeception

3. 扒一扒 StringBuilder 扩容

4. 对象调配

站内搜索