Jetty hangs early on Java 12 on OSv with Threadlocal Handshakes ON - shorter version

Waldek Kozaczuk jwkozaczuk at gmail.com
Fri Aug 9 12:23:33 UTC 2019


Hi,

Thanks for your suggestions.

I have tried against  openjdk-jdk12-latest-linux-x86_64-release.tar.xz from
https://builds.shipilev.net/openjdk-jdk12/ and
openjdk-jdk13-latest-linux-x86_64-release.tar.xz
(Java 13) from https://builds.shipilev.net/openjdk-jdk13/  and I am seeing
same symptoms - hanging.

I have also tried to use the fast-debug distribution
- openjdk-jdk12-latest-linux-x86_64-fastdebug.tar.xz - but unfortunately I
hit this snag per gdb:
(gdb) bt
#0  0x00000000403ad582 in processor::cli_hlt () at arch/x64/processor.hh:247
#1  arch::halt_no_interrupts () at arch/x64/arch.hh:48
#2  osv::halt () at arch/x64/power.cc:26
#3  0x0000000040241ac4 in abort (fmt=fmt at entry=0x406666d9 "general
protection fault\n") at runtime.cc:132
#4  0x00000000403a8a25 in general_protection (ef=0xffff8000022cf068) at
arch/x64/exceptions.cc:322
#5  <signal handler called>
#6  0x0000200008cf9c6a in ?? ()


*#7  0x000010000264087f in SafeFetch32 (errValue=2748,
adr=0xabc0000000000abc)    at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/stubRoutines.hpp:461*#8
 test_safefetch32 () at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/stubRoutines.cpp:245
#9  StubRoutines::initialize2 () at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/stubRoutines.cpp:366
#10 0x00001000026410ba in stubRoutines_init2 ()
    at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/stubRoutines.cpp:375
#11 0x0000100001c6c944 in init_globals () at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/init.cpp:146
#12 0x000010000270c1c4 in Threads::create_vm (args=args at entry=0x2000002fff50,
canTryAgain=canTryAgain at entry=0x2000002ffe8f)
    at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/runtime/thread.cpp:3729
#13 0x0000100001de5ac5 in JNI_CreateJavaVM_inner (args=0x2000002fff50,
penv=0x2000002fff48, vm=0x2000002fff40)
    at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/prims/jni.cpp:3935
#14 JNI_CreateJavaVM (vm=0x2000002fff40, penv=0x2000002fff48,
args=0x2000002fff50)
    at
/home/buildbot/worker/jdk12u-linux/build/src/hotspot/share/prims/jni.cpp:4021
#15 0x0000100000a04144 in InitializeJVM (ifn=<synthetic pointer>,
penv=0x2000002fff48, pvm=0x2000002fff40)
    at
/home/buildbot/worker/jdk12u-linux/build/src/java.base/share/native/libjli/java.c:1529
#16 JavaMain (_args=<optimized out>) at
/home/buildbot/worker/jdk12u-linux/build/src/java.base/share/native/libjli/java.c:414
#17 0x000000004045eec6 in pthread_private::pthread::<lambda()>::operator()
(__closure=0xffffa000012d9d00)
    at libc/pthread.cc:114
#18 std::_Function_handler<void(), pthread_private::pthread::pthread(void*
(*)(void*), void*, sigset_t, const
pthread_private::thread_attr*)::<lambda()> >::_M_invoke(const
std::_Any_data &) (__functor=...) at
/usr/include/c++/8/bits/std_function.h:297
#19 0x0000000040401117 in sched::thread_main_c (t=0xffff8000022ca040) at
arch/x64/arch-switch.hh:271
#20 0x00000000403a71d3 in thread_main () at arch/x64/entry.S:113
which has to do with SafeFetch32 which seems on purpose to read data from
invalid address (
https://github.com/openjdk/jdk/blob/1e5a1997b0bbe4fa9f746338283d2f325324cdf4/src/hotspot/share/runtime/stubRoutines.cpp#L262-L273).
I am guessing some code in JDK (where?) sets up a SIGSEGV handler to catch
it. I am not sure why OSv handles it as general protection fault. Either
way I was wondering how critical that SafeFetch32 mechanism is and can it
be disabled? Should I simply build JDK frm source and comment those
relevant lines out?

Meanwhile, I managed to enable some logging with the original release Zulu
version of OpenJDK 12 but and here is the log info I am getting:
OSv v0.53.0-74-gef56fde7
eth0: 192.168.122.15
Booted up in 134.50 ms
[0.068s][debug][gc] ConcGCThreads: 1 offset 8
[0.070s][debug][gc] ParallelGCThreads: 4
[0.071s][debug][gc] Initialize mark stack with 4096 chunks, maximum 16384
[0.078s][info ][gc] Using G1
[0.204s][info ][gc] Periodic GC disabled
[0.267s][debug][vmthread] Adding VM operation: EnableBiasedLocking
[0.268s][debug][vmthread] Evaluating safepoint VM operation:
EnableBiasedLocking
[0.277s][debug][vmthread] Adding VM operation: RevokeBias
[0.278s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.301s][debug][vmthread] Adding VM operation: Deoptimize
[0.302s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[0.513s][debug][vmthread] Adding VM operation: Deoptimize
[0.514s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[0.584s][debug][vmthread] Adding VM operation: Deoptimize
[0.585s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
fpathconf() stubbed
2019-08-09 11:29:28.235:INFO::main: Logging initialized @691ms
[0.761s][debug][vmthread] Adding VM operation: Deoptimize
[0.762s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[0.776s][debug][vmthread] Adding VM operation: Deoptimize
[0.777s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[0.890s][debug][vmthread] Adding VM operation: G1CollectForAllocation
[0.891s][debug][vmthread] Evaluating safepoint VM operation:
G1CollectForAllocation
[0.900s][info ][gc      ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
14M->2M(32M) 7.546ms
[0.901s][debug][vmthread] Adding VM operation: RevokeBias
[0.902s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.904s][debug][vmthread] Adding VM operation: RevokeBias
[0.905s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.906s][debug][vmthread] Adding VM operation: RevokeBias
[0.907s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.909s][debug][vmthread] Adding VM operation: RevokeBias
[0.909s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.911s][debug][vmthread] Adding VM operation: RevokeBias
[0.911s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.912s][debug][vmthread] Adding VM operation: RevokeBias
[0.913s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.914s][debug][vmthread] Adding VM operation: RevokeBias
[0.915s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.921s][debug][vmthread] Adding VM operation: RevokeBias
[0.921s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.922s][debug][vmthread] Adding VM operation: RevokeBias
[0.923s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.926s][debug][vmthread] Adding VM operation: RevokeBias
[0.927s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.928s][debug][vmthread] Adding VM operation: RevokeBias
[0.929s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.931s][debug][vmthread] Adding VM operation: RevokeBias
[0.932s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.934s][debug][vmthread] Adding VM operation: RevokeBias
[0.936s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[0.948s][debug][vmthread] Adding VM operation: RevokeBias
[0.949s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.050s][debug][vmthread] Adding VM operation: Deoptimize
[1.051s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[1.066s][debug][vmthread] Adding VM operation: Deoptimize
[1.067s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
2019-08-09 11:29:28.637:WARN::main: demo test-realm is deployed. DO NOT USE
IN PRODUCTION!
[1.096s][debug][vmthread] Adding VM operation: RevokeBias
[1.097s][debug][vmthread] Evaluating safepoint VM operation:
RevokeBias2019-08-09 11:29:28.641:INFO:oejs.Server:main:
jetty-9.2.11.v20150529

[1.105s][debug][vmthread] Adding VM operation: Deoptimize
[1.106s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
2019-08-09 11:29:28.658:INFO:oejdp.ScanningAppProvider:main: Deployment
monitor [file:/jetty/demo-base/webapps/] at interval 1
[1.157s][debug][vmthread] Adding VM operation: Deoptimize
[1.158s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[1.184s][debug][vmthread] Adding VM operation: Deoptimize
[1.185s][debug][vmthread] Evaluating safepoint VM operation: Deoptimize
[1.226s][debug][vmthread] Adding VM operation: G1CollectForAllocation
[1.227s][debug][vmthread] Evaluating safepoint VM operation:
G1CollectForAllocation
[1.243s][info ][gc      ] GC(1) Pause Young (Normal) (G1 Evacuation Pause)
15M->3M(32M) 14.143ms
[1.244s][debug][vmthread] Adding VM operation: RevokeBias
[1.245s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.246s][debug][vmthread] Adding VM operation: RevokeBias
[1.247s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.248s][debug][vmthread] Adding VM operation: RevokeBias
[1.248s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.249s][debug][vmthread] Adding VM operation: RevokeBias
[1.250s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.251s][debug][vmthread] Adding VM operation: RevokeBias
[1.252s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.253s][debug][vmthread] Adding VM operation: RevokeBias
[1.254s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.255s][debug][vmthread] Adding VM operation: RevokeBias
[1.256s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.257s][debug][vmthread] Adding VM operation: RevokeBias
[1.258s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.260s][debug][vmthread] Adding VM operation: RevokeBias
[1.261s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.263s][debug][vmthread] Adding VM operation: RevokeBias
[1.263s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.264s][debug][vmthread] Adding VM operation: RevokeBias
[1.265s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.266s][debug][vmthread] Adding VM operation: RevokeBias
[1.267s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.269s][debug][vmthread] Adding VM operation: RevokeBias
[1.269s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.271s][debug][vmthread] Adding VM operation: RevokeBias
[1.272s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.273s][debug][vmthread] Adding VM operation: RevokeBias
[1.274s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.275s][debug][vmthread] Adding VM operation: RevokeBias
[1.276s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.277s][debug][vmthread] Adding VM operation: RevokeBias
[1.278s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.279s][debug][vmthread] Adding VM operation: RevokeBias
[1.280s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.373s][debug][vmthread] Adding VM operation: RevokeBias
[1.374s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.411s][debug][vmthread] Adding VM operation: RevokeBias
[1.412s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.413s][debug][vmthread] Adding VM operation: RevokeBias
[1.414s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.416s][debug][vmthread] Adding VM operation: RevokeBias
[1.417s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.418s][debug][vmthread] Adding VM operation: RevokeBias
[1.419s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.420s][debug][vmthread] Adding VM operation: RevokeBias
[1.421s][debug][vmthread] Adding VM operation: BulkRevokeBias
[1.422s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.423s][debug][vmthread] Evaluating coalesced safepoint VM operation:
BulkRevokeBias
[1.424s][debug][vmthread] Adding VM operation: RevokeBias
[1.425s][debug][vmthread] Adding VM operation: RevokeBias
[1.426s][debug][vmthread] Adding VM operation: RevokeBias
[1.427s][debug][vmthread] Adding VM operation: RevokeBias
[1.427s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.429s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.430s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.431s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.432s][debug][vmthread] Adding VM operation: RevokeBias
[1.433s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.434s][debug][vmthread] Adding VM operation: RevokeBias
[1.434s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.435s][debug][vmthread] Adding VM operation: RevokeBias
[1.436s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.437s][debug][vmthread] Adding VM operation: RevokeBias
[1.438s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.439s][debug][vmthread] Adding VM operation: RevokeBias
[1.440s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.441s][debug][vmthread] Adding VM operation: RevokeBias
[1.442s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.443s][debug][vmthread] Adding VM operation: RevokeBias
[1.443s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.445s][debug][vmthread] Adding VM operation: RevokeBias
[1.445s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.446s][debug][vmthread] Adding VM operation: RevokeBias
[1.447s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.448s][debug][vmthread] Adding VM operation: RevokeBias
[1.449s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.450s][debug][vmthread] Adding VM operation: RevokeBias
[1.451s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.452s][debug][vmthread] Adding VM operation: RevokeBias
[1.453s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.454s][debug][vmthread] Adding VM operation: RevokeBias
[1.454s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.456s][debug][vmthread] Adding VM operation: RevokeBias
[1.456s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.457s][debug][vmthread] Adding VM operation: RevokeBias
[1.458s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.459s][debug][vmthread] Adding VM operation: RevokeBias
[1.460s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.461s][debug][vmthread] Adding VM operation: RevokeBias
[1.462s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.464s][debug][vmthread] Adding VM operation: BulkRevokeBias
[1.464s][debug][vmthread] Evaluating safepoint VM operation: BulkRevokeBias
[1.466s][debug][vmthread] Adding VM operation: RevokeBias
[1.466s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.467s][debug][vmthread] Adding VM operation: RevokeBias
[1.468s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.469s][debug][vmthread] Adding VM operation: RevokeBias
[1.470s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.472s][debug][vmthread] Adding VM operation: RevokeBias
[1.473s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.474s][debug][vmthread] Adding VM operation: RevokeBias
[1.475s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.476s][debug][vmthread] Adding VM operation: RevokeBias
[1.477s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.479s][debug][vmthread] Adding VM operation: RevokeBias
[1.480s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.481s][debug][vmthread] Adding VM operation: RevokeBias
[1.482s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.484s][debug][vmthread] Adding VM operation: RevokeBias
[1.485s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.490s][debug][vmthread] Adding VM operation: RevokeBias
[1.491s][debug][vmthread] Adding VM operation: RevokeBias
[1.492s][debug][vmthread] Adding VM operation: BulkRevokeBias
[1.493s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.493s][debug][vmthread] Adding VM operation: RevokeBias
[1.496s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.502s][debug][vmthread] Evaluating coalesced safepoint VM operation:
BulkRevokeBias
[1.504s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.506s][debug][vmthread] Adding VM operation: RevokeBias
[1.507s][debug][vmthread] Adding VM operation: RevokeBias
[1.508s][debug][vmthread] Adding VM operation: RevokeBias
[1.510s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.510s][debug][vmthread] Adding VM operation: RevokeBias
[1.513s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.514s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.516s][debug][vmthread] Evaluating coalesced safepoint VM operation:
RevokeBias
[1.518s][debug][vmthread] Adding VM operation: RevokeBias
[1.519s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.520s][debug][vmthread] Adding VM operation: RevokeBias
[1.521s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.522s][debug][vmthread] Adding VM operation: RevokeBias
[1.524s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.526s][debug][vmthread] Adding VM operation: RevokeBias
[1.528s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.529s][debug][vmthread] Adding VM operation: RevokeBias
[1.530s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.532s][debug][vmthread] Adding VM operation: RevokeBias
[1.533s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.534s][debug][vmthread] Adding VM operation: RevokeBias
[1.536s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.537s][debug][vmthread] Adding VM operation: RevokeBias
[1.539s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.540s][debug][vmthread] Adding VM operation: RevokeBias
[1.542s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.543s][debug][vmthread] Adding VM operation: RevokeBias
[1.545s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.546s][debug][vmthread] Adding VM operation: RevokeBias
[1.547s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.549s][debug][vmthread] Adding VM operation: RevokeBias
[1.551s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.552s][debug][vmthread] Adding VM operation: RevokeBias
[1.554s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.555s][debug][vmthread] Adding VM operation: RevokeBias
[1.556s][debug][vmthread] Evaluating safepoint VM operation: RevokeBias
[1.559s][debug][vmthread] Adding VM operation: HandshakeAllThreads



*[1.560s][debug][vmthread] Adding VM operation:
RevokeBias[1.561s][debug][vmthread] Evaluating non-safepoint VM operation:
HandshakeAllThreads[1.563s][debug][handshake] Threads signaled, begin
processing blocked threads by VMThtread*

And it always stops like that and gdb shows similar state as I originally
posted.

Now I have tried to analyze the code in handshakes.cpp (I think this
version applied to me -
https://github.com/openjdk/jdk/blob/jdk-12%2B12/src/hotspot/share/runtime/handshake.cpp)
and here is my reasoning about why this hanging in active loop happens:

1. VM Thread executes VM_HandshakeAllThreads::doit() (
https://github.com/openjdk/jdk/blob/jdk-12%2B12/src/hotspot/share/runtime/handshake.cpp#L178
).

2. It iterates through all JavaThread instances from the jtiwh collection
(what exactly is this?) and SHOULD end up calling
HandshakeState::process_by_vmthread
(
https://github.com/openjdk/jdk/blob/jdk-12%2B12/src/hotspot/share/runtime/handshake.cpp#L361)
which eventually should call
HandshakeThreadsOperation::do_handshake(JavaThread*
thread) for each JavaThread and increment the _done semaphore BUT only if
the process_by_vmthread() calls _operation->do_handshake(target), right?
But there are at least 3 IFs which may cause this method to return and the
critical 4th IF (
https://github.com/openjdk/jdk/blob/jdk-12%2B12/src/hotspot/share/runtime/handshake.cpp#L379-L389)
which only executes its body if vmthread_can_process_handshake returns
true. What could make these first 3 IF be true and make
process_by_vmthread to return BEFORE the last if? When would last IF be
false?

3. VM_HandshakeAllThreads::doit() loops by calling poll_for_completed_thread()
which NEVER completes.

Correct me where I made any mistake in my thinking.

Thanks in advance for your support,
Waldek






On Thu, Aug 8, 2019 at 6:53 AM Robbin Ehn <robbin.ehn at oracle.com> wrote:

> Hi Waldek,
>
>
> > #0  0x0000100000c86370 in sem_trywait at plt ()
> > #1  0x0000100001702bf2 in PosixSemaphore::trywait() ()
> > #2  0x000010000121aab4 in VM_HandshakeAllThreads::doit() ()
>
> VMThread is trying to figure out which threads have not executed their
> handshake
> operation and possible execute it for them (e.g. JavaThread in native).
>
> If you attach gdb and step around in VM_HandshakeAllThreads::doit while
> looping
> there, you can figure out why we never finish.
>
> > When I explicitly enable thread local handshakes on Java 11 it works as
> > well:
>
> In 11 it is only used by ZGC, but in 12 it is used for stack-scanning
> after
> nmethods.
>
> Sweeper thread:
>
> #12 0x0000100001219a48 in Handshake::execute(ThreadClosure*) ()
> #13 0x00001000018b4a0c in NMethodSweeper::possibly_sweep() ()
>
> > One more datapoint - I am able to run a simple Hello World java app on
> Java
> > 12 on OSv with thread-local handshakes on so it looks like this problem
> > appears on more complicated apps.
>
> If you never get to needing to sweep nmethod, you will have never executed
> a
> handshake. (but you will execute safepoints using the handshake poll)
>
> If you can easily reprod, take a slowdebug and when the process hang,
> attach gdb
> switch to VMThread and step around, you will see a count which decrease
> once for
> every thread which have executed it's handshake. To figure out if a thread
> have
> executed it's handshake, VMThread will take a per thread semaphore
> (decrease
> it), which serialize access to the per thread handshake operation, and
> then look
> if the operation is completed, return the semaphore (increase it), and
> look at
> next thread.
>
> /Robbin
>
> >
> > *Lastly, the exact same app works fine on Java 12 on Linux.*
> >
> > So given all that could you please point me to what the problem might be?
> > What has changed in the implementation of thread local handshakes between
> > Java 11 and 12 that may have caused this issue (I see many changes made
> to
> >
> https://github.com/openjdk/jdk/blob/0fe0312f416add1536a45ecfb292c887ef7e02bd/src/hotspot/share/runtime/handshake.cpp
> > but
> > I am not even sure which commit matches the version of Java 12 or Java
> 11 I
> > am using)? I am thinking this has to do with some subtle differences
> > between relevant ABI implementation between OSv and Linux. Signals
> related?
> >
> > Thanks for your help in advance,
> >
> > Waldek
> >
> > Thread dump of all Java threads (in other email that was to big)
> >
>


More information about the hotspot-dev mailing list