JDK-8310480 : gc/cslocker/TestCSLocker.java times out with G1
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 22
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • OS: linux
  • CPU: x86_64
  • Submitted: 2023-06-20
  • Updated: 2023-12-05
  • Resolved: 2023-11-08
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 22
22Resolved
Related Reports
Duplicate :  
JDK-8318706 - Implement JEP 423: Region Pinning for G1
Relates :  
JDK-8308589 - gc/cslocker/TestCSLocker.java timed out
Relates :  
JDK-8321369 - Unproblemlist gc/cslocker/TestCSLocker.java
Sub Tasks
JDK-8318622 :  
ProblemList gc/cslocker/TestCSLocker.java on linux-x64 in Xcomp mode - Resolved
Description
The following test timed out in the JDK22 CI:

gc/cslocker/TestCSLocker.java

Here's a snippet from the log file:

#section:main
----------messages:(8/333)----------
command: main -Xmx256m gc.cslocker.TestCSLocker
reason: User specified action: run main/native/othervm -Xmx256m gc.cslocker.TestCSLocker 
started: Tue Jun 20 09:20:46 UTC 2023
Mode: othervm [/othervm specified]
Timeout information:
--- Timeout information end.
finished: Tue Jun 20 09:50:34 UTC 2023
elapsed time (seconds): 1788.412
----------configuration:(0/0)----------
----------System.out:(1/27)----------
Timeout refired 1200 times
----------System.err:(0/0)----------
----------rerun:(46/7379)*----------

<snip>

result: Error. Program `/opt/mach5/mesos/work_dir/jib-master/install/jdk-22+3-132/linux-x64-debug.jdk/jdk-22/fastdebug/bin/java' timed out (timeout set to 1200000ms, elapsed time including timeout handling was 1788401ms).
Comments
With region pinning implemented in JDK-8318706 there is no GC locker that can time out and test is not run with G1 any more.
08-11-2023
... and we have one test thread that locks the GCLocker: Thread 3 (Thread 0x7f9cbf209700 (LWP 27350)): #0 Java_gc_cslocker_CSLocker_lock (env=0x7f9c5001c170, obj=<optimized out>, array=0x7f9cbf2089f8) at /opt/mach5/mesos/work_dir/slaves/cd627e65-f015-4fb1-a1d2-b6c9b8127f98-S202447/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2aeeef78-36c2-46a5-99d0-bd9f81187633/runs/5250402e-1234-4ad1-a348-803643c2932e/workspace/open/test/hotspot/jtreg/gc/cslocker/libTestCSLocker.c:39 #1 0x00007f9ce4fc3b6b in ?? () and waits for the test's main thread to unlock the GCLocker. The main thread executes the sleep: // check timeout to success deadlocking sleep(timeoutMillis); csLocker.unlock(); that thread has this Java stack trace: "MainThread" #20 prio=5 tid=0x00007f9ce0378580 nid=27328 waiting on condition [0x00007f9cbf928000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked - java.lang.Thread.sleepNanos(long) @bci=1, line=486 (Interpreted frame) - java.lang.Thread.sleep(long) @bci=25, line=522 (Compiled frame) - gc.cslocker.TestCSLocker.main(java.lang.String[]) @bci=32, line=62 (Interpreted frame) - java.lang.invoke.LambdaForm$DMH+0x00007f9c7f001800.invokeStatic(java.lang.Object, java.lang.Object) @bci=10 (Compiled frame) - java.lang.invoke.LambdaForm$MH+0x00007f9c7f002c00.invoke(java.lang.Object, java.lang.Object, java.lang.Object) @bci=33 (Compiled frame) - java.lang.invoke.Invokers$Holder.invokeExact_MT(java.lang.Object, java.lang.Object, java.lang.Object, java.lang.Object) @bci=20 (Compiled frame) - jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.lang.Object, java.lang.Object[]) @bci=55, line=154 (Interpreted frame) - jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.lang.Object, java.lang.Object[]) @bci=23, line=103 (Interpreted frame) - java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) @bci=102, line=580 (Compiled frame) - com.sun.javatest.regtest.agent.MainWrapper$MainTask.run() @bci=134, line=138 (Interpreted frame) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1583 (Compiled frame) - java.lang.Thread.run() @bci=19, line=1570 (Compiled frame) which corresponds to this thread in gdb: Thread 5 (Thread 0x7f9cbf929700 (LWP 27328)): #0 0x00007f9cea6c3a35 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x00007f9ce948006c in PlatformMonitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #2 0x00007f9ce93d5ce5 in Monitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #3 0x00007f9ce89c0b7a in CompileBroker::wait_for_completion(CompileTask*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #4 0x00007f9ce89c5e43 in CompileBroker::compile_method(methodHandle const&, int, int, methodHandle const&, int, CompileTask::CompileReason, DirectiveSet*, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #5 0x00007f9ce89c6319 in CompileBroker::compile_method(methodHandle const&, int, int, methodHandle const&, int, CompileTask::CompileReason, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #6 0x00007f9ce8993146 in CompilationPolicy::compile_if_required(methodHandle const&, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #7 0x00007f9ce9200fd6 in LinkResolver::resolve_static_call(CallInfo&, LinkInfo const&, bool, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #8 0x00007f9ce92012fb in LinkResolver::resolve_invokestatic(CallInfo&, constantPoolHandle const&, int, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #9 0x00007f9ce9204410 in LinkResolver::resolve_invoke(CallInfo&, Handle, constantPoolHandle const&, int, Bytecodes::Code, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #10 0x00007f9ce8e361fc in InterpreterRuntime::resolve_invoke(JavaThread*, Bytecodes::Code) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #11 0x00007f9ce8e36f8b in InterpreterRuntime::resolve_from_cache(JavaThread*, Bytecodes::Code) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #12 0x00007f9ce48cc023 in ?? () #13 0x00007f9ce48cbf9d in ?? () #14 0x000000012a05f200 in ?? () #15 0x0000000000000000 in ?? () So, to reiterate the wait chain is Thread 3 waits for Thread 5 which waits for Thread 8 which waits for Thread 3.
28-09-2023
jstack fails on the timed out process, suggesting the VM is at a safepoint and so we can't attach. The native stack dump shows one compiler thread stuck here: Thread 8 (Thread 0x7f9cbfcfc700 (LWP 27226)): #0 0x00007f9cea6c3a35 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x00007f9ce948006c in PlatformMonitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #2 0x00007f9ce93d5ce5 in Monitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #3 0x00007f9ce8d10a3a in GCLocker::stall_until_clear() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #4 0x00007f9ce8c19c27 in G1CollectedHeap::try_collect_concurrently(GCCause::Cause, unsigned int, unsigned int) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #5 0x00007f9ce8c1abf1 in G1CollectedHeap::collect(GCCause::Cause) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #6 0x00007f9ce8891177 in ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, bool, bool, bool, int, RTMState) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #7 0x00007f9ce9491b03 in PhaseOutput::install_code(ciMethod*, int, AbstractCompiler*, bool, bool, RTMState) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #8 0x00007f9ce9491c74 in PhaseOutput::install() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #9 0x00007f9ce89b54a7 in Compile::Code_Gen() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #10 0x00007f9ce89b811e in Compile::Compile(ciEnv*, ciMethod*, int, Options, DirectiveSet*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #11 0x00007f9ce881192b in C2Compiler::compile_method(ciEnv*, ciMethod*, int, bool, DirectiveSet*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #12 0x00007f9ce89c3f30 in CompileBroker::invoke_compiler_on_method(CompileTask*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #13 0x00007f9ce89c4c58 in CompileBroker::compiler_thread_loop() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #14 0x00007f9ce8e82dfc in JavaThread::thread_main_inner() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #15 0x00007f9ce976a38a in Thread::call_run() () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #16 0x00007f9ce946f9ca in thread_native_entry(Thread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #17 0x00007f9cea6bfea5 in start_thread () from /lib64/libpthread.so.0 #18 0x00007f9cea1e4b2d in clone () from /lib64/libc.so.6 while others are waiting for compilation e.g. Thread 6 (Thread 0x7f9cbfa2a700 (LWP 27323)): #0 0x00007f9cea6c3a35 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x00007f9ce948006c in PlatformMonitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #2 0x00007f9ce93d5ce5 in Monitor::wait(unsigned long) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #3 0x00007f9ce89c0b7a in CompileBroker::wait_for_completion(CompileTask*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #4 0x00007f9ce89c5e43 in CompileBroker::compile_method(methodHandle const&, int, int, methodHandle const&, int, CompileTask::CompileReason, DirectiveSet*, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #5 0x00007f9ce89c6319 in CompileBroker::compile_method(methodHandle const&, int, int, methodHandle const&, int, CompileTask::CompileReason, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #6 0x00007f9ce8993146 in CompilationPolicy::compile_if_required(methodHandle const&, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #7 0x00007f9ce91fab2b in CallInfo::set_virtual(Klass*, methodHandle const&, methodHandle const&, int, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #8 0x00007f9ce920290f in LinkResolver::runtime_resolve_virtual_method(CallInfo&, methodHandle const&, Klass*, Handle, Klass*, bool, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #9 0x00007f9ce9202d0a in LinkResolver::resolve_virtual_call(CallInfo&, Handle, Klass*, LinkInfo const&, bool, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #10 0x00007f9ce9203067 in LinkResolver::resolve_invokevirtual(CallInfo&, Handle, constantPoolHandle const&, int, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #11 0x00007f9ce920449e in LinkResolver::resolve_invoke(CallInfo&, Handle, constantPoolHandle const&, int, Bytecodes::Code, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #12 0x00007f9ce8e361fc in InterpreterRuntime::resolve_invoke(JavaThread*, Bytecodes::Code) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #13 0x00007f9ce8e36f8b in InterpreterRuntime::resolve_from_cache(JavaThread*, Bytecodes::Code) () from /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+17-1330/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/libjvm.so #14 0x00007f9ce48cb663 in ?? () so the deadlock theory seems reasonable.
28-09-2023
Note the test is brittle and allocations at the wrong location in the test can cause dead locks. We excluded this test for Generational ZGC, but think that it could be a problem for other GCs as well.
21-06-2023