Netty 抛出的 io.netty.util.internal.OutOfDirectMemoryError

最近遇到一个奇怪的Java direct memory 导致的 OutOfDirectMemoryError. 我们的应用程序在启动的时候, 明明设置了-XX:MaxDirectMemorySize=1G, 并且我们有持续的监控数据看到 direct memory 才用了不到10M, 就怎么爆出了io.netty.util.internal.OutOfDirectMemoryError 呢?

症状

日志里看到很多这样的错误:

msg=Root cause=OutOfDirectMemoryError: failed to allocate 4194304 byte(s) of direct memory (used: 1069547527, max: 1073741824)&st=io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 4194304 byte(s) of direct memory (used: 1069547527, max: 1073741824)
    at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:802)
    at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:731)
    at io.netty.buffer.PoolArena$DirectArena.allocateDirect(PoolArena.java:649)
    at io.netty.buffer.PoolArena$DirectArena.newChunk(PoolArena.java:624)
    at io.netty.buffer.PoolArena.allocateNormal(PoolArena.java:203)
    at io.netty.buffer.PoolArena.tcacheAllocateSmall(PoolArena.java:173)
    at io.netty.buffer.PoolArena.allocate(PoolArena.java:134)
    at io.netty.buffer.PoolArena.allocate(PoolArena.java:126)
    at io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:394)
    at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
    at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
    at io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:140)
    at io.netty.channel.DefaultMaxMessagesRecvByteBufAllocator$MaxMessageHandle.allocate(DefaultMaxMessagesRecvByteBufAllocator.java:120)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:150)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)

初步诊断

上面的错误, 告诉我们以下一些细节:

Java 应用程序的 direct memory 不够用了;
direct memory 最大值是1G (1073741824), 已经使用1G (1069547527);
本次申请的用量是 4M (4194304 bytes);

大家知道 Java 提供了监控 direct memory 使用量的 MBean, 很多框架也支持持续导出这些数据形成时序 metrics. 下图是通过JDK 自带的 Jconsole 看到的 direct memory MBean 的数据: 6个 DirectByteBuffer, 共使用了49152 bytes.

在服务器上使用 JConsole 不方便, 但是有很多命令行工具可以帮我们查看 MBean. 我们公司的框架暴露了这些数据为时序数据, 通过这些时序数据我们很容易看到, 我们的 direct memory 使用量不足10M. 所以这里矛盾的地方就是虽然我们设置了最大1G 的 direct memory, MBean 暴露的数据显示使用不到10M, 可是 Netty 却一直告诉我们1G 已经用完, 并且抛出 OutOfDirectMemoryError.

读 Netty 代码

根据出错栈, 我们找到了 Netty 的代码: io.netty.util.internal.PlatformDependent.incrementMemoryCounter.

    private static void incrementMemoryCounter(int capacity) {
        if (DIRECT_MEMORY_COUNTER != null) {
            long newUsedMemory = DIRECT_MEMORY_COUNTER.addAndGet(capacity);
            if (newUsedMemory > DIRECT_MEMORY_LIMIT) {
                DIRECT_MEMORY_COUNTER.addAndGet(-capacity);
                throw new OutOfDirectMemoryError("failed to allocate " + capacity
                        + " byte(s) of direct memory (used: " + (newUsedMemory - capacity)
                        + ", max: " + DIRECT_MEMORY_LIMIT + ')');
            }
        }
    }

根据这段代码, 我们注意到: DIRECT_MEMORY_LIMIT 在我们的情况下, 就是我们设置的 MaxDirectMemorySize 的值, 就是1G. DIRECT_MEMORY_COUNTER 就是 Netty 使用的 direct memory 的数量.
我们最初看到的那个 OutOfDirectMemoryError 就是这段代码抛出的. 很明显, 再加上那申请的4M, 就超过了1G 的最大限制. 为了验证我们说的情况, 我们事后做了一个 heap dump, 虽然当时没有抛出OutOfDirectMemoryError, MBean 显示的 direct memory 也只使用了4M多. 可是 DIRECT_MEMORY_COUNTER 的值, 却显示已经使用了490M 多:

为什么MBean 报出的 direct memory 使用量和 Netty 的 DIRECT_MEMORY_COUNTER 的值不一样?

为了找出二者之间的差异, 我们要分别看下他们是怎么统计的.

MBean 的 direct memory 的统计方式

JDK 的 BufferPoolMXBean 统计 direct/mapper 的 memory 使用量, 它作为一个接口, 真正的实现类可以在 JDK 找到. sun.management.ManagementFactoryHelper (JDK8) 里面就有一个实现类:

private static BufferPoolMXBean
        createBufferPoolMXBean(final sun.misc.JavaNioAccess.BufferPool pool)
    {
        return new BufferPoolMXBean() {
            private volatile ObjectName objname;  // created lazily
            @Override
            public ObjectName getObjectName() {
                ObjectName result = objname;
                if (result == null) {
                    synchronized (this) {
                        result = objname;
                        if (result == null) {
                            result = Util.newObjectName(BUFFER_POOL_MXBEAN_NAME +
                                ",name=" + pool.getName());
                            objname = result;
                        }
                    }
                }
                return result;
            }
            @Override
            public String getName() {
                return pool.getName();
            }
            @Override
            public long getCount() {
                return pool.getCount();
            }
            @Override
            public long getTotalCapacity() {
                return pool.getTotalCapacity();
            }
            @Override
            public long getMemoryUsed() {
                return pool.getMemoryUsed();
            }
        };
    }

从上面代码可以看出, 真正的使用量, 都是从sun.misc.JavaNioAccess.BufferPool获得, 沿着这个线索找下去, 就在java.nio.Bits里面找到2个BufferPool的真正实现, 分别记录了 direct/mapper 的使用量. 其中, direct memory 的 count, totalCapacity 和 memory used 分别是由 Bits 的 count, totalCapacity 和 reservedMemory记录.

return new sun.misc.JavaNioAccess.BufferPool() {
    @Override
    public String getName() {
        return "direct";
    }
    @Override
    public long getCount() {
        return Bits.count.get();
    }
    @Override
    public long getTotalCapacity() {
        return Bits.totalCapacity.get();
    }
    @Override
    public long getMemoryUsed() {
        return Bits.reservedMemory.get();
    }
};

我们单追踪 Bits.reservedMemory 是怎么 track 已经使用量的:

DirectByteBuffer(int cap) {                   // package-private
        super(-1, 0, cap, cap);
        //省略其它无关代码
        Bits.reserveMemory(size, cap);
  }

从上面的代码可以看到, 每当 java.nio.DirectByteBuffer 初始化的时候, 它都会调用 Bits.reserveMemory 代码去 track 内存使用量. 这样当我们想查看 direct memory 使用量的时候, 只要查看 Bits 的记录数据就好了.

Netty 的 DIRECT_MEMORY_COUNTER 的统计方式

DIRECT_MEMORY_COUNTER 的统计方式比较直观, 它只在 PlatformDependent 内部被使用. 每当想要申请一块新的 direct 内存时候, 它就调用 incrementMemoryCounter 方法去增加 DIRECT_MEMORY_COUNTER 的值.

原因

所以, 虽然他们都以 MaxDirectMemorySize 为最大值, 但是都看不到对方的存在, 都只统计自己知道的使用量. 所以这导致我们看到 MBean 里面暴露的值和真正的使用量并不一样.

扩展 - 有关 ByteBuffer

JDK 里面的ByteBuffer 的数据结构有下图, Buffer 是一个抽象类, 定义了通用的一些方法, 比如 limit(), reset(), mark(), flip(), rewind(), isDirect(), 等. 然后 Buffer 下面定义了 primitive 类型对应的各种 Buffer 类. ByteBuffer 又分为在 heap 的 HeapByteBuffer 和在直接内存的 MappedByteBuffer & DirectByteBuffer. 下面以 R 结尾的 ByteBuffer 代表 read only 的 ByteBuffer.

扩展 - Netty 自己的 metrics 如何暴露这些数据的

Netty 本来提供了一个 metrics, 只是需要自己把这些 metrics 数据导出. metrics 数据通过PooledByteBufAllocatorMetric 暴露.

症状