Is JDK-8291919 refixed in JDK11u?
shanghe chen
chenshanghe at outlook.com
Thu Feb 29 04:54:30 UTC 2024
OK. Thank you for the suggestion, I will do that.
________________________________
发件人: Joseph D. Darcy <joe.darcy at oracle.com>
发送时间: Thursday, February 29, 2024 12:50:16 PM
收件人: shanghe chen <chenshanghe at outlook.com>; jdk-dev at openjdk.org <jdk-dev at openjdk.org>; jdk-updates-dev <jdk-updates-dev-retn at openjdk.org>
主题: Re: Is JDK-8291919 refixed in JDK11u?
The aliases you have mailed are not support aliases.
I suggest checking with your JDK vendor for assistance.
-Joe
On 2/28/2024 8:33 PM, shanghe chen wrote:
Hi! We are still suspecting that some peak allocation behavior of C2Compiler causes the memory used by java reach a peak memory exceeding the limit of docker and invokes the oom killer:
For continuing checking the docker oom occurred in our java web service hosted inside a docker container with 32GB memory limit, with version
openjdk version "11.0.14.1" 2022-02-08
OpenJDK Runtime Environment Temurin-11.0.14.1+1 (build 11.0.14.1+1)
OpenJDK 64-Bit Server VM Temurin-11.0.14.1+1 (build 11.0.14.1+1, mixed mode)
with the following java options:
-Xms28g
-Xmx28g
-Xss256k
-XX:+UseG1GC
-XX:MaxGCPauseMillis=200
-XX:ParallelGCThreads=12
-XX:MetaspaceSize=512m
-XX:MaxMetaspaceSize=512m
-XX:InitialCodeCacheSize=128m
-XX:ReservedCodeCacheSize=512m
-XX:MinHeapFreeRatio=30
-XX:MaxHeapFreeRatio=50
-XX:CICompilerCount=4
-XX:+UseCompressedOops
-XX:SoftRefLRUPolicyMSPerMB=0
-XX:-OmitStackTraceInFastThrow
-XX:+AggressiveOpts
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintClassHistogram
-XX:MaxTenuringThreshold=10
-XX:+IgnoreUnrecognizedVMOptions
-Djava.lang.Integer.IntegerCache.high=1000000
-Dcustomer.java.lang.Integer.IntegerCache.high=1000000
-Djava.util.concurrent.ForkJoinPool.common.parallelism=8
-Djdk.attach.allowAttachSelf=true
-Dfastjson.parser.safeMode=true
-Dlog4j2.formatMsgNoLookups=true
-Dio.netty.allocator.numDirectArenas=8
For checking this in a larger memory limit environment, using strace we found that there is a continous Arena growth during the following stack trace of C2Compiler::compile_method like:
[pid 24629] 20:40:44 mmap(NULL, 335544320, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c35378000
> /usr/lib64/libc-2.17.so(mmap64+0x3a) [0xf8fca]
> /opt/container/lib/libjemalloc.so(je_pages_map+0x47) [0x50657]
> /opt/container/lib/libjemalloc.so(je_extent_alloc_mmap+0x13) [0x4ab23]
> /opt/container/lib/libjemalloc.so(extent_grow_retained+0x709) [0x48ed9]
> /opt/container/lib/libjemalloc.so(je_extent_alloc_wrapper+0x5bf) [0x4997f]
> /opt/container/lib/libjemalloc.so(je_arena_extent_alloc_large+0x173) [0x20123]
> /opt/container/lib/libjemalloc.so(je_large_malloc+0xb9) [0x4b739]
> /opt/container/lib/libjemalloc.so(je_malloc_default+0x6c3) [0xf3f3]
> /usr/java/jdk11/lib/server/libjvm.so(os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xfc) [0xc5edec]
> /usr/java/jdk11/lib/server/libjvm.so(Arena::grow(unsigned long, AllocFailStrategy::AllocFailEnum)+0x109) [0x44d1f9]
> /usr/java/jdk11/lib/server/libjvm.so(Arena::Arealloc(void*, unsigned long, unsigned long, AllocFailStrategy::AllocFailEnum)+0x201) [0x44d541]
> /usr/java/jdk11/lib/server/libjvm.so(Node_Array::grow(unsigned int)+0x56) [0xc348a6]
> /usr/java/jdk11/lib/server/libjvm.so(PhaseCFG::insert_anti_dependences(Block*, Node*, bool)+0x750) [0x827160]
> /usr/java/jdk11/lib/server/libjvm.so(PhaseCFG::schedule_late(VectorSet&, Node_Stack&)+0x447) [0x82a0c7]
> /usr/java/jdk11/lib/server/libjvm.so(PhaseCFG::global_code_motion()+0x314) [0x82d564]
> /usr/java/jdk11/lib/server/libjvm.so(PhaseCFG::do_global_code_motion()+0x49) [0x82dea9]
> /usr/java/jdk11/lib/server/libjvm.so(Compile::Code_Gen()+0x1d4) [0x66cc64]
> /usr/java/jdk11/lib/server/libjvm.so(Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool, bool, DirectiveSet*)+0xd4a) [0x6704da]
> /usr/java/jdk11/lib/server/libjvm.so(C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0xd3) [0x588193]
> /usr/java/jdk11/lib/server/libjvm.so(CompileBroker::invoke_compiler_on_method(CompileTask*)+0x445) [0x67a8c5]
> /usr/java/jdk11/lib/server/libjvm.so(CompileBroker::compiler_thread_loop()+0x5a7) [0x67c1f7]
> /usr/java/jdk11/lib/server/libjvm.so(JavaThread::thread_main_inner()+0x1b9) [0xed4899]
> /usr/java/jdk11/lib/server/libjvm.so(Thread::call_run()+0x14e) [0xed149e]
> /usr/java/jdk11/lib/server/libjvm.so(thread_native_entry(Thread*)+0xed) [0xc714cd]
> /usr/lib64/libpthread-2.17.so(start_thread+0xc4) [0x7ea4]
> /usr/lib64/libc-2.17.so(__clone+0x6c) [0xfeb0c]
the strace of mmap shows that (all with the above stack trace) that sums up to more than 1GB memory:
[pid 24629] 20:40:33 mmap(NULL, 29360128, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5ca6678000
[pid 24629] 20:40:35 mmap(NULL, 50331648, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c9ee78000
[pid 24629] 20:40:36 mmap(NULL, 58720256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c9b678000
[pid 24629] 20:40:36 mmap(NULL, 67108864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c97678000
[pid 24629] 20:40:36 mmap(NULL, 83886080, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c92678000
[pid 24629] 20:40:39 mmap(NULL, 100663296, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c8c678000
[pid 24629] 20:40:41 mmap(NULL, 134217728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c7d678000
[pid 24629] 20:40:42 mmap(NULL, 167772160, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c73678000
[pid 24629] 20:40:42 mmap(NULL, 201326592, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c67678000
[pid 24629] 20:40:43 mmap(NULL, 234881024, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c59378000
[pid 24629] 20:40:43 mmap(NULL, 268435456, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c49378000
[pid 24629] 20:40:44 mmap(NULL, 335544320, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5c35378000
And in /proc/$pid/status we see that the metric VmHWM grows from 31.04GB to 32.12GB at the same time, which means at some moment the process used memory at much 32.12GB. But in the NativeMemoryTool we only sample a record with java.nmt.compiler.committed=122MB.
With -XX:+PrintCompilation option it seems no too much methods being compiled (20:40:33 to 20:40:44 is of range seconds 1937 to 1948, names of some packages replaced)
1936335 58263 4 com.wecorp.webiz.product.service.v1.PublicParametersEntity::put (4606 bytes)
1936376 52134 3 org.apache.catalina.valves.AbstractAccessLogValve$RequestURIElement::addElement (24 bytes) made not entrant
1936507 58259 3 com.wecorp.webiz.facade.mapper.PublicParametersEntityMapper::mapToInternal (6527 bytes)
1936634 58262 4 com.wecorp.webiz.cache.DataBusinessV2::getHash (143 bytes)
1936986 56014 3 com.wecorp.webiz.cache.DataBusinessV2::getHash (143 bytes) made not entrant
1937112 58251 4 java.util.IdentityHashMap::containsKey (55 bytes)
1937141 898 3 java.util.IdentityHashMap::containsKey (55 bytes) made not entrant
1937288 58264 4 com.wecorp.webiz.business.dynamic.simplefilter.Filter$$Lambda$1463/0x0000000800b54040::apply (13 bytes)
1937334 36436 2 com.wecorp.webiz.business.dynamic.simplefilter.Filter$$Lambda$1463/0x0000000800b54040::apply (13 bytes) made not entrant
1938478 58267 4 com.wecorp.webiz.facade.mapper.WebizFacilitiesEntityMapper::mapToInternal (1541 bytes)
1938588 52139 ! 3 org.apache.catalina.core.StandardHostValve::invoke (402 bytes) made not entrant
1938739 58272 ! 4 io.grpc.internal.MessageDeframer::readRequiredBytes (558 bytes)
1939036 53988 4 com.wecorp.webiz.cache.BaseInfoBusinessV10::getByBaseId (109 bytes) made not entrant
1942257 23486 ! 3 io.grpc.internal.MessageDeframer::readRequiredBytes (558 bytes) made not entrant
1942481 58276 4 com.wecorp.webiz.business.plan.ResourceTag::getSpecialTypes (552 bytes)
1942733 47364 3 com.wecorp.webiz.facade.mapper.WebizFacilitiesEntityMapper::mapToInternal (1541 bytes) made not entrant
1942768 58166 3 com.wecorp.webiz.business.plan.ResourceTag::getSpecialTypes (552 bytes) made not entrant
1943829 58278 4 com.wecorp.webiz.business.plan.model.hour.HourStgy::isHour (14 bytes)
1943841 58282 4 com.wecorp.webiz.business.plan.model.hour.CodeHour::isHour (73 bytes)
1944863 58167 3 com.wecorp.webiz.business.plan.model.hour.CodeHour::isHour (73 bytes) made not entrant
1944928 58168 3 com.wecorp.webiz.business.plan.model.hour.HourStgy::isHour (14 bytes) made not entrant
1945127 58271 4 com.wecorp.webiz.business.factory.lazy.LazyToWebizVMS::isSupport (39 bytes)
1945134 46559 3 com.wecorp.webiz.business.factory.lazy.LazyToWebizVMS::isSupport (39 bytes) made not entrant
1946397 58269 4 io.grpc.Deadline$SystemTicker::nanoTime (4 bytes)
1946418 23483 3 io.grpc.Deadline$SystemTicker::nanoTime (4 bytes) made not entrant
1947083 58295 4 com.wecorp.infra.kafka.common.protocol.types.Struct::instance (13 bytes)
1947448 54974 4 com.wecorp.webiz.business.dynamic.webizfilterrules.FilterSpecialWebiz::filter (174 bytes) made not entrant
1949042 40631 3 com.wecorp.infra.kafka.common.protocol.types.Struct::instance (13 bytes) made not entrant
1949471 58297 4 com.wecorp.webiz.business.dynamic.webizfilterrules.FilterSpecialWebiz::filter (174 bytes)
1949474 58306 4 com.wecorp.webiz.product.cache.Cache::isDataReady (26 bytes)
1949479 27680 3 com.wecorp.webiz.product.cache.Cache::isDataReady (26 bytes) made not entrant
May I ask why there is a continuous peak alloc in C2Compiler::compile_method, namely in PhaseCFG::insert_anti_dependences? it seems that the code of Arena::grow (in https://github.com/openjdk/jdk11u/blob/master/src/hotspot/share/memory/arena.cpp#L353) does not free each chunk? It means that at some point all the allocated memory is using?
And can we avoid this kind of continuously large size allocation in this limited memory environment in docker but still enable C2Compiler?
Thank you for any response!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/jdk-dev/attachments/20240229/f0a99fee/attachment-0001.htm>
More information about the jdk-dev
mailing list