Раздел Java Native Memory «Другое» потребляет много памяти
Предпосылки
Приложение запускается в докер-контейнере с Java openjdk версии «13.0.1» со следующими параметрами:
-Xmx6G -XX:MaxHeapFreeRatio=30 -XX:MinHeapFreeRatio=10 -XX:+AlwaysActAsServerClassMachine -XX:+UseContainerSupport -XX:+HeapDumpOnOutOfMemoryError -XX:+ExitOnOutOfMemoryError -XX:HeapDumpPath==/.../crush.hprof -XX:+UnlockDiagnosticVMOptions -XX:NativeMemoryTracking=summary -XX:+PrintNMTStatistics -Xlog:gc*:file=/var/log/.../log.gc.log:time::filecount=5,filesize=100000
Когда я бегуjcmd 1 VM.native_memory, я получаю это:
Total: reserved=9081562KB, committed=1900002KB
- Java Heap (reserved=6291456KB, committed=896000KB)
(mmap: reserved=6291456KB, committed=896000KB)
- Class (reserved=1221794KB, committed=197034KB)
(classes #34434)
( instance classes #32536, array classes #1898)
(malloc=7330KB #121979)
(mmap: reserved=1214464KB, committed=189704KB)
( Metadata: )
( reserved=165888KB, committed=165752KB)
( used=161911KB)
( free=3841KB)
( waste=0KB =0.00%)
( Class space:)
( reserved=1048576KB, committed=23952KB)
( used=21501KB)
( free=2451KB)
( waste=0KB =0.00%)
- Thread (reserved=456661KB, committed=50141KB)
(thread #442)
(stack: reserved=454236KB, committed=47716KB)
(malloc=1572KB #2654)
(arena=853KB #882)
- Code (reserved=255027KB, committed=100419KB)
(malloc=7343KB #26005)
(mmap: reserved=247684KB, committed=93076KB)
- GC (reserved=316675KB, committed=116459KB)
(malloc=47311KB #70516)
(mmap: reserved=269364KB, committed=69148KB)
- Compiler (reserved=1429KB, committed=1429KB)
(malloc=1634KB #2498)
(arena=18014398509481779KB #5)
- Internal (reserved=2998KB, committed=2998KB)
(malloc=2962KB #5480)
(mmap: reserved=36KB, committed=36KB)
- Other (reserved=446581KB, committed=446581KB)
(malloc=446581KB #368)
- Symbol (reserved=36418KB, committed=36418KB)
(malloc=34460KB #906917)
(arena=1958KB #1)
- Native Memory Tracking (reserved=18786KB, committed=18786KB)
(malloc=587KB #8291)
(tracking overhead=18199KB)
- Shared class space (reserved=11180KB, committed=11180KB)
(mmap: reserved=11180KB, committed=11180KB)
- Arena Chunk (reserved=19480KB, committed=19480KB)
(malloc=19480KB)
- Logging (reserved=7KB, committed=7KB)
(malloc=7KB #271)
- Arguments (reserved=17KB, committed=17KB)
(malloc=17KB #471)
- Module (reserved=1909KB, committed=1909KB)
(malloc=1909KB #11057)
- Safepoint (reserved=8KB, committed=8KB)
(mmap: reserved=8KB, committed=8KB)
- Synchronization (reserved=1136KB, committed=1136KB)
(malloc=1136KB #6628)
Здесь мы видим, что раздел «Другое» потребляет 446581 КБ , тогда как общий объем выделенной памяти составляет 1900002 КБ .
Итак, раздел «Другое» занимает 23% всей выделенной памяти!
Также эта память не освобождается при запуске приложения.
Из-за этого я изменил флаг java-XX:NativeMemoryTracking=summaryк-XX:NativeMemoryTracking=detailчтобы проверить, где выделена память, и получил эти 2 странных блока памяти:
[0x00007f8db4b32bae] Unsafe_AllocateMemory0+0x8e
[0x00007f8da416e7db]
(malloc=298470KB type=Other #286)
[0x00007f8db4b32bae] Unsafe_AllocateMemory0+0x8e
[0x00007f8d9b84bc90]
(malloc=148111KB type=Other #82)
Анализировать
- Я попытался использовать асинхронный профилировщик для проверки события Unsafe_AllocateMemory0 .
Я запускаю async-profiler в качестве агента следующим образом:
java -agentpath:/async-profiler/build/libasyncProfiler.so=start,event=itimer,Unsafe_AllocateMemory0,file=/var/log/.../unsafe_allocate_memory.html
И получил этот флеймограф: https://stackru.com/images/bd9bdf240f66cab1b8f4e69becef77f4b354c15b.png
Кроме того, я пытался профилировать событияmalloc,mmap,mprotect.mallocпоказал тот же пламенный график, что и событиеUnsafe_AllocateMemory0, но флеймграфы дляmmapиmprotectбыли пусты.
Я подумал, что проблема может быть связана с компилятором C2 и отключил его, но после перезагрузки ничего не изменилось - раздел «Другое» по-прежнему занимал много памяти. Более того, это приложение долгоживущее и я не уверен, что отключение C2 может быть хорошей идеей.
- Я попытался использовать jeprof , чтобы проверить, какая часть кода выполняется.
os.malloc
Я запускаю java-приложение следующим образом:
LD_PRELOAD=/usr/local/lib/libjemalloc.so MALLOC_CONF=prof:true,lg_prof_interval:30,lg_prof_sample:17 exec java -jar /srv/app/myapp.jar
Через 10+ минут я использовал jeprof и получил это: https://stackru.com/images/5a6692a1d214d53e10df3a3ba587dbd070c2c129.gif
И снова есть 2 блока памяти, которые заняли много родной памяти.
Результат
Я не могу найти место, которое выделяет столько памяти.
Может быть, кто-то может порекомендовать, как определить основную причину этой проблемы? И какие шаги мне нужно предпринять, чтобы избежать этой проблемы?
ОБНОВЛЕНИЕ 1
Благодаря user3448419 я наконец-то нашел место, где столько памяти занято!
Это связано с Redisson / Lettuce , которые используют Netty под капотом: flamegraph
Я использовал экспериментальный собственный режим и запустил java:
java -agentpath:/async-profiler/build/libasyncProfiler.so=start,event=nativemem,file=/var/log/.../profile.jfr -jar /srv/app/myapp.jar
1 ответ
Ваши аргументы асинхронных профилировщиков кажутся неверными.
Изменятьevent=itimer,Unsafe_AllocateMemory0кevent=Unsafe_AllocateMemory0
async-profiler также имеет экспериментальныйnativememспециально для поиска утечек памяти. Подробнее см. https://github.com/jvm-profiling-tools/async-profiler/discussions/491 .
OtherРаздел в NMT обычно включает память вне кучи, выделенную с помощьюUnsafe.allocateMemory, в частности Direct ByteBuffers.