Bug ID: JDK-8307185 pkcs11 native libraries make JNI calls into java code while holding GC lock

JDK-8307185 : pkcs11 native libraries make JNI calls into java code while holding GC lock

Type: Bug
Component: security-libs
Sub-Component: javax.crypto:pkcs11
Affected Version: 8,11,17,20,21,22

Priority: P2
Status: Closed
Resolution: Fixed

Submitted: 2023-05-01
Updated: 2024-07-26
Resolved: 2023-07-20

Versions (Unresolved/Resolved/Fixed)

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 17	JDK 21	JDK 22	JDK 8
17.0.11-oracleFixed	21Fixed	22 b08Fixed	8u411Fixed

Related Reports

Duplicate :	JDK-8299485 - Test sun/security/pkcs11/Cipher/TestCICOWithGCMAndAAD.java timed out
Duplicate :	JDK-8277359 - sun/security/pkcs11/* test failures with jtreg test timeout
Duplicate :	JDK-8240611 - pkcs11/Cipher/TestKATForGCM.java failed due to timeout
Duplicate :	JDK-8253056 - sun/security/pkcs11/Cipher/TestGCMKeyAndIvCheck.java timed out
Duplicate :	JDK-8275751 - Security tests unexpectedly timed out
Relates :	JDK-8312368 - Improve troubleshooting of GCLocker-induced deadlocks
Relates :	JDK-8299485 - Test sun/security/pkcs11/Cipher/TestCICOWithGCMAndAAD.java timed out
Relates :	JDK-8080462 - Update SunPKCS11 provider with PKCS11 v2.40 support

Description

Test sun/security/pkcs11/Cipher/TestGCMKeyAndIvCheck.java crashed
with
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/opt/mach5/mesos/work_dir/slaves/741e9afd-8c02-45c3-b2e2-9db1450d0832-S79186/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2ef51ca9-bad0-46db-8e19-172f18899f3c/runs/8002a502-cb17-4c3a-ad85-b28c10f2ab4e/workspace/open/src/hotspot/share/gc/shared/gcLocker.cpp:107), pid=6849, tid=6918
#  assert(!JavaThread::current()->in_critical()) failed: Would deadlock
#
# JRE version: Java(TM) SE Runtime Environment (21.0) (fastdebug build 21-internal-LTS-2023-04-28-1933301.leonid.mesnik.jdk-ttf-build)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 21-internal-LTS-2023-04-28-1933301.leonid.mesnik.jdk-ttf-build, mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
# Problematic frame:
# V  [libjvm.so+0xd1553c]  GCLocker::stall_until_clear()+0x1ac
#


Current thread (0x00007f25b0007850):  JavaThread "ForkJoinPool-1-worker-2" daemon [_thread_in_vm, id=6918, stack(0x00007f25f94f4000,0x00007f25f95f5000)]

Stack: [0x00007f25f94f4000,0x00007f25f95f5000],  sp=0x00007f25f95f1ba0,  free space=1014k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0xd1553c]  GCLocker::stall_until_clear()+0x1ac  (gcLocker.cpp:107)
V  [libjvm.so+0xc0ba5b]  G1CollectedHeap::attempt_allocation_slow(unsigned long)+0x13b  (g1CollectedHeap.cpp:484)
V  [libjvm.so+0xc100fe]  G1CollectedHeap::attempt_allocation(unsigned long, unsigned long, unsigned long*)+0x21e  (g1CollectedHeap.cpp:642)
V  [libjvm.so+0x1325707]  MemAllocator::mem_allocate_inside_tlab_slow(MemAllocator::Allocation&) const+0x237  (memAllocator.cpp:324)
V  [libjvm.so+0x1325fbb]  MemAllocator::mem_allocate_slow(MemAllocator::Allocation&) const+0x9b  (memAllocator.cpp:361)
V  [libjvm.so+0x13260eb]  MemAllocator::allocate() const+0xdb  (memAllocator.cpp:379)
V  [libjvm.so+0xe07167]  InstanceKlass::allocate_instance(JavaThread*)+0x87  (collectedHeap.inline.hpp:36)
V  [libjvm.so+0xe409de]  InterpreterRuntime::_new(JavaThread*, ConstantPool*, int)+0x15e  (interpreterRuntime.cpp:243)
j  sun.security.pkcs11.wrapper.PKCS11Exception$RV.<clinit>()V+872 jdk.crypto.cryptoki@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
V  [libjvm.so+0xe55d02]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x462  (javaCalls.cpp:415)
V  [libjvm.so+0xe07d48]  InstanceKlass::call_class_initializer(JavaThread*)+0x258  (instanceKlass.cpp:1553)
V  [libjvm.so+0xe0a6d0]  InstanceKlass::initialize_impl(JavaThread*)+0x640  (instanceKlass.cpp:1139)
V  [libjvm.so+0x11f5ac6]  LinkResolver::resolve_static_call(CallInfo&, LinkInfo const&, bool, JavaThread*)+0x1e6  (linkResolver.cpp:1078)
V  [libjvm.so+0x11f679b]  LinkResolver::resolve_invoke(CallInfo&, Handle, constantPoolHandle const&, int, Bytecodes::Code, JavaThread*)+0x18b  (linkResolver.cpp:1672)
V  [libjvm.so+0xe3f3a6]  InterpreterRuntime::resolve_invoke(JavaThread*, Bytecodes::Code)+0x316  (interpreterRuntime.cpp:834)
V  [libjvm.so+0xe400ee]  InterpreterRuntime::resolve_from_cache(JavaThread*, Bytecodes::Code)+0x7e  (interpreterRuntime.cpp:968)
j  sun.security.pkcs11.wrapper.PKCS11Exception.lookup(J)Ljava/lang/String;+0 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.wrapper.PKCS11Exception.<init>(JLjava/lang/String;)V+11 jdk.crypto.cryptoki@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
V  [libjvm.so+0xe55d02]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x462  (javaCalls.cpp:415)
V  [libjvm.so+0xf61fa9]  jni_invoke_nonstatic(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, JavaThread*) [clone .constprop.0]+0x1d9  (jni.cpp:950)
V  [libjvm.so+0xf62a18]  jni_NewObject+0x208  (jni.cpp:1023)
C  [libj2pkcs11.so+0xc989]  ckAssertReturnValueOK2.part.0+0x89  (p11_util.c:224)
C  [libj2pkcs11.so+0x68ab]  Java_sun_security_pkcs11_wrapper_PKCS11_C_1Decrypt+0xdb  (p11_crypt.c:404)
j  sun.security.pkcs11.wrapper.PKCS11.C_Decrypt(JJ[BIIJ[BII)I+0 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.cancelOperation()V+120 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.reset(Z)V+65 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.ensureInitialized()V+19 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.implDoFinal([BII[BII)I+26 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.engineDoFinal([BII[BI)I+14 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.engineDoFinal([BII)[B+20 jdk.crypto.cryptoki@21-internal
j  javax.crypto.Cipher.doFinal([B)[B+31 java.base@21-internal
j  TestGCMKeyAndIvCheck.test(Ljava/lang/String;Ljava/security/Provider;)V+240
j  TestGCMKeyAndIvCheck.main(Ljava/security/Provider;)V+4
j  PKCS11Test.premain(Ljava/security/Provider;)V+69
j  PKCS11Test.testNSS(LPKCS11Test;)V+16
J 600  jdk.internal.vm.Continuation.enterSpecial(Ljdk/internal/vm/Continuation;ZZ)V java.base@21-internal (0 bytes) @ 0x00007f261079c6d3 [0x00007f261079c560+0x0000000000000173]
j  jdk.internal.vm.Continuation.run()V+152 java.base@21-internal
j  java.lang.VirtualThread.runContinuation()V+76 java.base@21-internal
j  java.lang.VirtualThread$$Lambda+0x000000010014aba8.run()V+4 java.base@21-internal
j  java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec()Z+4 java.base@21-internal
j  java.util.concurrent.ForkJoinTask.doExec()I+10 java.base@21-internal
j  java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Ljava/util/concurrent/ForkJoinTask;Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V+19 java.base@21-internal
J 1241 c2 java.util.concurrent.ForkJoinPool.scan(Ljava/util/concurrent/ForkJoinPool$WorkQueue;II)I java.base@21-internal (263 bytes) @ 0x00007f26107f626c [0x00007f26107f6040+0x000000000000022c]
j  java.util.concurrent.ForkJoinPool.runWorker(Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V+35 java.base@21-internal
j  java.util.concurrent.ForkJoinWorkerThread.run()V+31 java.base@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
V  [libjvm.so+0xe55d02]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x462  (javaCalls.cpp:415)
V  [libjvm.so+0xe562e3]  JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, JavaThread*)+0x283  (javaCalls.cpp:329)
V  [libjvm.so+0xe564f1]  JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, JavaThread*)+0x71  (javaCalls.cpp:191)
V  [libjvm.so+0xfa5666]  thread_entry(JavaThread*, JavaThread*)+0x96  (jvm.cpp:2918)
V  [libjvm.so+0xe87e9e]  JavaThread::thread_main_inner()+0x17e  (javaThread.cpp:717)
V  [libjvm.so+0x1758538]  Thread::call_run()+0xb8  (thread.cpp:215)
V  [libjvm.so+0x145984a]  thread_native_entry(Thread*)+0x11a  (os_linux.cpp:740)
Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  sun.security.pkcs11.wrapper.PKCS11Exception$RV.<clinit>()V+872 jdk.crypto.cryptoki@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
j  sun.security.pkcs11.wrapper.PKCS11Exception.lookup(J)Ljava/lang/String;+0 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.wrapper.PKCS11Exception.<init>(JLjava/lang/String;)V+11 jdk.crypto.cryptoki@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
j  sun.security.pkcs11.wrapper.PKCS11.C_Decrypt(JJ[BIIJ[BII)I+0 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.cancelOperation()V+120 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.reset(Z)V+65 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.ensureInitialized()V+19 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.implDoFinal([BII[BII)I+26 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.engineDoFinal([BII[BI)I+14 jdk.crypto.cryptoki@21-internal
j  sun.security.pkcs11.P11AEADCipher.engineDoFinal([BII)[B+20 jdk.crypto.cryptoki@21-internal
j  javax.crypto.Cipher.doFinal([B)[B+31 java.base@21-internal
j  TestGCMKeyAndIvCheck.test(Ljava/lang/String;Ljava/security/Provider;)V+240
j  TestGCMKeyAndIvCheck.main(Ljava/security/Provider;)V+4
j  PKCS11Test.premain(Ljava/security/Provider;)V+69
j  PKCS11Test.testNSS(LPKCS11Test;)V+16
J 600  jdk.internal.vm.Continuation.enterSpecial(Ljdk/internal/vm/Continuation;ZZ)V java.base@21-internal (0 bytes) @ 0x00007f261079c6d3 [0x00007f261079c560+0x0000000000000173]
j  jdk.internal.vm.Continuation.run()V+152 java.base@21-internal
j  java.lang.VirtualThread.runContinuation()V+76 java.base@21-internal
j  java.lang.VirtualThread$$Lambda+0x000000010014aba8.run()V+4 java.base@21-internal
j  java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec()Z+4 java.base@21-internal
j  java.util.concurrent.ForkJoinTask.doExec()I+10 java.base@21-internal
j  java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Ljava/util/concurrent/ForkJoinTask;Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V+19 java.base@21-internal
J 1241 c2 java.util.concurrent.ForkJoinPool.scan(Ljava/util/concurrent/ForkJoinPool$WorkQueue;II)I java.base@21-internal (263 bytes) @ 0x00007f26107f626c [0x00007f26107f6040+0x000000000000022c]
j  java.util.concurrent.ForkJoinPool.runWorker(Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V+35 java.base@21-internal
j  java.util.concurrent.ForkJoinWorkerThread.run()V+31 java.base@21-internal
v  ~StubRoutines::call_stub 0x00007f26101c5d21
Registers:
RAX=0x00007f262962e000, RBX=0x00007f26289ab044, RCX=0x00007f26283b7e01, RDX=0x00007f26284a5230
RSP=0x00007f25f95f1ba0, RBP=0x00007f25f95f1bb0, RSI=0x000000000000006b, RDI=0x00007f26284a4ff8
R8 =0x0000000000000000, R9 =0x0000000000000000, R10=0x0000000000000000, R11=0x00007f2620048960
R12=0x00007f25b0007850, R13=0x0000000000000100, R14=0x00007f262003f830, R15=0x00007f26289ab044
RIP=0x00007f262777c53c, EFLAGS=0x0000000000010202, CSGSFS=0x002b000000000033, ERR=0x0000000000000006
  TRAPNO=0x000000000000000e

Comments

Fix request [17u] I backport this for parity with 17.0.11-oracle. Risk limited to pkcs. Rather simple change, limited risk. Clean backport. Test passes, but also without the fix. SAP nightly testing passed.
09-01-2024
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/2112 Date: 2024-01-08 14:23:12 +0000
08-01-2024
Fix request approved.
21-07-2023
Fix Request This is a fix for a regression that will cause user applications to deadlock randomly. The issue is well understood, and the fix is low risk. The fix is covered by existing tests that time out intermittently without it.
21-07-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk21/pull/142 Date: 2023-07-21 10:29:43 +0000
21-07-2023
Changeset: 354c6605 Author: Daniel Jeliński <djelinski@openjdk.org> Date: 2023-07-20 16:39:17 +0000 URL: https://git.openjdk.org/jdk/commit/354c6605e32790ca421869636d8bf5456fc51717
20-07-2023
introduced in JDK-8080462
19-07-2023
I've changed the priority back to P2, this is an important bug to fix. See also discussion in JDK-8253056.
19-07-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/14931 Date: 2023-07-19 12:03:14 +0000
19-07-2023
p11_crypt.c is last touched in JDK 17. Lowering to P3 due to the intermittent nature.
06-07-2023
The advice to don't call JNI functions and don't allocate a heap in the critical section is correct. GC locker prevent GC and might cause deadlock. I am not sure if -Xcheck:jni print warnings for JDK libraries.
01-06-2023
Is there a set of rules of calling GetPrimitiveArrayCritical? Is the advice in this discussion legit? https://stackoverflow.com/questions/23258357/whats-the-trade-off-between-using-getprimitivearraycritical-and-getprimitivety Would this be reported with the Java flag -Xcheck:jni?
31-05-2023
It looks like like several JNI functions in p11_crypt.c can exit (in error case) without doing cleanup so they don't ReleasePrimitiveArrayCritical. These should be fixed.
26-05-2023
The code in the https://github.com/openjdk/jdk/blob/89b3c375ac55f960dbeac8a2355e528450e610a1/src/jdk.crypto.cryptoki/share/native/libj2pkcs11/p11_crypt.c#L404 and places like this can cause JVM locks. The pattern like: inBufP = (env)->GetPrimitiveArrayCritical(env, jIn, NULL); ... ckAssertReturnValueOK(env, rv); ^^^^ call Java code here (env)->ReleasePrimitiveArrayCritical(env, jIn, inBufP, JNI_ABORT); is unsafe. It could potentially GC deadlock if Java code allocates an object while the heap is locked. Also, it could cause virtual threads remounting while GC lock is held. Which also can deadlock.
25-05-2023
The more reliable reproducer would be better as a regression test for this bug.
01-05-2023
Although it is in gc component, it is more loom issue.
01-05-2023
The failure is very intermittent. Run: make -- run-test JTREG_VERBOSE=all JTREG_RETAIN=all JTREG_TEST_THREAD_FACTORY=Virtual TEST=sun/security/pkcs11/Cipher/TestGCMKeyAndIvCheck.java to reproduce. Seems the GCLocker should pin VirtualThread to JavaThread so the another gc locking couldn't be executed on it.
01-05-2023