Native Memory Tracking Bug

[Jacob Schlather]

Upon further investigation it appears that NMT is not accurately tracking
the memory usage of the JVM. I ran NMT summary and got the following output

Total: reserved=9095231KB, committed=8746919KB

And then I ran pmap on the host to check memory usage

sudo pmap -x 89186 | tail -n 1
total kB        34497556 9397564 9352480

Is this sort of gap expected?


On Thu, Nov 14, 2019 at 12:18 PM Jacob Schlather <jschlather at hubspot.com>
wrote:

> Hi Zhengyu,
>
> This bug seems to happen every time for one of our web services running in
> production, but it doesn't happen in qa, so I don't think I'll be able to
> provide a reproducer. If there are some lightweight debugging options we
> could turn on and provide that output to you, I could do that.
>
> Having dug into the memory issue we're seeing, what it looks like is that
> in Java 8 the committed memory as shown by NMT is significantly less than
> the memory the JVM was actually using. Now on Java 11, the JVM seems to be
> using much closer to the committed memory. Do you happen to know of
> anything we could look into for that? Thanks.
>
> On Wed, Nov 13, 2019 at 10:14 PM Zhengyu Gu <zgu at redhat.com> wrote:
>
>> Hi Jacob,
>>
>> It looks like JDK-8204128 [1] strikes again. It would be very helpful if
>> you can provide a reproducer.
>>
>> Thanks,
>>
>> -Zhengyu
>>
>>
>> [1] https://bugs.openjdk.java.net/browse/JDK-8204128
>> <https://bugs.openjdk.java.net/browse/JDK-8204128>
>>
>>
>> On 11/13/19 9:56 PM, Jacob Schlather wrote:
>> > We're currently in the process of upgrading our Java applications from
>> Java
>> > 8 to Java 11. After deploying some of our production applications with
>> Java
>> > 11, we began to see the resident memory size grow without bound until
>> our
>> > orchestrator killed the applications for excessive memory usage. We've
>> > started to debug this issue, but noticed that the NMT output appears to
>> be
>> > incorrect. In particular the Compiler section is displaying
>> >
>> > Compiler (reserved=4528KB +1010KB, committed=4528KB +1010KB)
>> > (malloc=4896KB +1206KB #4132 +508)
>> > (arena=18014398509481617KB -196 #5)
>> >
>> > Obviously the arena value here is quite wrong and there's no way the
>> > reserved memory can be less than the malloc memory. Further there's
>> > a 276305KB gap in the RSS size reported by our metrics and the amount of
>> > memory NMT reports as committed. Here's our JVM args and JDK version,
>> I've
>> > additionally attached the full output of the NMT detailed diff.
>> >
>> > Running java11 with JVM arguments: -Djava.net.preferIPv4Stack=true
>> > -Xms6144m -Xmx6g -Xss256k -XX:MetaspaceSize=128m
>> > -XX:MaxMetaspaceSize=256m -XX:CompressedClassSpaceSize=128m
>> > -XX:+UseG1GC -XX:MaxGCPauseMillis=350 -XX:+UnlockExperimentalVMOptions
>> > -XX:G1NewSizePercent=20 -XX:G1MaxNewSizePercent=45
>> > -XX:ParallelGCThreads=8 -XX:ConcGCThreads=6
>> > -XX:InitiatingHeapOccupancyPercent=35 -XX:+PerfDisableSharedMem
>> > -XX:-UseBiasedLocking -XX:G1HeapRegionSize=4m
>> > -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=../logs
>> > -Djava.io.tmpdir=REDACTED -XX:+ExitOnOutOfMemoryError
>> > -XX:-OmitStackTraceInFastThrow
>> >
>> -javaagent:/usr/local/appoptics-6.5.1/appoptics-agent.jar=config=appoptics-agent.json
>> > -XX:-PreferContainerQuotaForCPUCount -XX:NativeMemoryTracking=detail
>> > -jar REDACTED
>> > openjdk version "11.0.5" 2019-10-15
>> > OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.5+10)
>> > OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.5+10, mixed mode)
>> >
>>
>