JDK-8295274 : HelidonAppTest.java fails "assert(event->should_commit()) failed: invariant" from compiled frame"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jfr
  • Affected Version: 20
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2022-10-13
  • Updated: 2023-11-29
  • Resolved: 2022-10-14
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 20
17.0.11Fixed 20 b20Fixed
Related Reports
Relates :  
JDK-8288663 - JFR: Disabling the JfrThreadSampler commits only a partially disabled state
Relates :  
JDK-8287832 - jdk/jfr/event/runtime/TestActiveSettingEvent.java failed with "Expected two batches of Active Setting events"
Description
The following test failed in the JDK20 CI:

applications/helidonapp/HelidonAppTest.java

Here's a snippet from the log file:

[2022-10-13T05:39:07.637887500Z] Gathering output for process 47884
[2022-10-13T05:39:07.940001500Z] Waiting for completion for process 47884
[2022-10-13T05:39:07.940276Z] Waiting for completion finished for process 47884
Output and diagnostic info for process 47884 was saved into 'pid-47884-output.log'
[stress.process.out] #
[stress.process.out] # A fatal error has been detected by the Java Runtime Environment:
[stress.process.out] #
[stress.process.out] #  Internal Error (c:\\sb\\prod\\1665585502\\workspace\\open\\src\\hotspot\\share\\prims\\unsafe.cpp:756), pid=41348, tid=32984
[stress.process.out] #  assert(event->should_commit()) failed: invariant
[stress.process.out] #
[stress.process.out] # JRE version: Java(TM) SE Runtime Environment (20.0+19) (fastdebug build 20-ea+19-1363)
[stress.process.out] # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 20-ea+19-1363, mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, windows-amd64)
[stress.process.out] # Core dump will be written. Default location: C:\\sb\\prod\\1665638747\\testoutput\\test-support\\jtreg_closed_test_hotspot_jtreg_applications_helidonapp_HelidonAppTest_java\\scratch\\0\\hs_err_pid41348.mdmp
[stress.process.out] #
[stress.process.out] # JFR recording file will be written. Location: C:\\sb\\prod\\1665638747\\testoutput\\test-support\\jtreg_closed_test_hotspot_jtreg_applications_helidonapp_HelidonAppTest_java\\scratch\\0\\hs_err_pid41348.jfr
[stress.process.out] #
[stress.process.out] Unsupported internal testing APIs have been used.
[stress.process.out] 
[stress.process.out] # An error report file with more information is saved as:
[stress.process.out] # C:\\sb\\prod\\1665638747\\testoutput\\test-support\\jtreg_closed_test_hotspot_jtreg_applications_helidonapp_HelidonAppTest_java\\scratch\\0\\hs_err_pid41348.log
[stress.process.out] [610.514s][warning][os] Loading hsdis library failed
[stress.process.out] #
[stress.process.out] # If you would like to submit a bug report, please visit:
[stress.process.out] #   https://bugreport.java.com/bugreport/crash.jsp
[stress.process.out] #
[stress.process.out] [thread 27004 also had an error]


Here's the stack trace from the crashing thread:

---------------  T H R E A D  ---------------

Current thread (0x000002177eab8f40):  JavaThread "helidon-19" daemon [_thread_in_vm, id=32984, stack(0x000000fd53100000,0x000000fd53200000)]

Stack: [0x000000fd53100000,0x000000fd53200000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0xc0b641]  os::win32::platform_print_native_stack+0xf1  (os_windows_x86.cpp:236)
V  [jvm.dll+0xe6e18e]  VMError::report+0x10be  (vmError.cpp:841)
V  [jvm.dll+0xe6fc84]  VMError::report_and_die+0x644  (vmError.cpp:1700)
V  [jvm.dll+0xe703c4]  VMError::report_and_die+0x64  (vmError.cpp:1481)
V  [jvm.dll+0x57fb27]  report_vm_error+0xb7  (debug.cpp:285)
V  [jvm.dll+0xe264c5]  post_thread_park_event+0xb5  (unsafe.cpp:756)
V  [jvm.dll+0xe19f78]  Unsafe_Park+0x348  (unsafe.cpp:781)
C  0x0000021708139c53

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
J 9900  jdk.internal.misc.Unsafe.park(ZJ)V java.base@20-ea (0 bytes) @ 0x0000021708139bb8 [0x0000021708139b40+0x0000000000000078]
J 13328 c2 java.util.concurrent.CompletableFuture.timedGet(J)Ljava/lang/Object; java.base@20-ea (212 bytes) @ 0x0000021708df4588 [0x0000021708df4460+0x0000000000000128]
J 13330 c2 java.util.concurrent.CompletableFuture.get(JLjava/util/concurrent/TimeUnit;)Ljava/lang/Object; java.base@20-ea (31 bytes) @ 0x0000021708df81d4 [0x0000021708df8160+0x0000000000000074]
J 13197 c2 io.helidon.security.integration.jersey.SecurityFilterCommon.processAuthorization(Lio/helidon/security/integration/jersey/SecurityFilterCommon$FilterContext;Lio/helidon/security/SecurityClientBuilder;)V (335 bytes) @ 0x0000021708c8951c [0x0000021708c89480+0x000000000000009c]
J 11992 c2 io.helidon.security.integration.jersey.SecurityFilter.processSecurity(Ljavax/ws/rs/container/ContainerRequestContext;Lio/helidon/security/integration/jersey/SecurityFilterCommon$FilterContext;Lio/helidon/security/integration/common/SecurityTracing;Lio/helidon/security/SecurityContext;)V (78 bytes) @ 0x0000021708504e20 [0x0000021708503c20+0x0000000000001200]
J 12290 c2 io.helidon.security.integration.jersey.SecurityFilterCommon.doFilter(Ljavax/ws/rs/container/ContainerRequestContext;Lio/helidon/security/SecurityContext;)V (383 bytes) @ 0x000002170890f79c [0x000002170890c5c0+0x00000000000031dc]
J 12320 c2 io.helidon.security.integration.jersey.SecurityFilter.filter(Ljavax/ws/rs/container/ContainerRequestContext;)V (31 bytes) @ 0x00000217087f7bcc [0x00000217087f7b40+0x000000000000008c]
J 12880 c2 org.glassfish.jersey.server.ContainerFilteringStage.apply(Lorg/glassfish/jersey/server/internal/process/RequestProcessingContext;)Lorg/glassfish/jersey/process/internal/Stage$Continuation; (431 bytes) @ 0x0000021708923a8c [0x0000021708922520+0x000000000000156c]
J 10719 c2 org.glassfish.jersey.server.ContainerFilteringStage.apply(Ljava/lang/Object;)Lorg/glassfish/jersey/process/internal/Stage$Continuation; (9 bytes) @ 0x00000217083b4f0c [0x00000217083b4ec0+0x000000000000004c]
J 12094 c2 org.glassfish.jersey.process.internal.RequestScope.runInScope(Lorg/glassfish/jersey/process/internal/RequestContext;Ljava/lang/Runnable;)V (49 bytes) @ 0x000002170851c8bc [0x000002170851b320+0x000000000000159c]
J 11941 c2 org.glassfish.jersey.server.ServerRuntime.process(Lorg/glassfish/jersey/server/ContainerRequest;)V (185 bytes) @ 0x00000217085bb500 [0x00000217085ba800+0x0000000000000d00]
J 13085 c2 io.helidon.webserver.jersey.JerseySupport$JerseyHandler.lambda$doAccept$4(Lio/helidon/webserver/ServerRequest;Ljava/util/Optional;Lorg/glassfish/jersey/server/ContainerRequest;Lio/helidon/webserver/ServerResponse;Ljava/util/concurrent/CompletableFuture;)V (113 bytes) @ 0x0000021708b90b44 [0x0000021708b90720+0x0000000000000424]
J 13113 c2 io.helidon.webserver.jersey.JerseySupport$JerseyHandler$$Lambda$1934+0x0000000801587348.run()V (28 bytes) @ 0x0000021708baffa0 [0x0000021708bafe20+0x0000000000000180]
J 10502 c2 io.helidon.common.context.Contexts.runInContext(Lio/helidon/common/context/Context;Ljava/lang/Runnable;)V (25 bytes) @ 0x00000217081c2b68 [0x00000217081c2840+0x0000000000000328]
J 13238% c2 java.util.concurrent.ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V java.base@20-ea (187 bytes) @ 0x0000021708d70f48 [0x0000021708d70b40+0x0000000000000408]
j  java.util.concurrent.ThreadPoolExecutor$Worker.run()V+5 java.base@20-ea
j  java.lang.Thread.run()V+13 java.base@20-ea
v  ~StubRoutines::call_stub 0x000002170753107d
Comments
Fix Request (17u): This a follow-up to related https://bugs.openjdk.org/browse/JDK-8288663?focusedId=14629608&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14629608 The code is the same in 17 so it looks right to remove asserts there as well. Original patch is applied cleanly. Testing: tier1, tier2, jdk_jfr, gc/stress/jfr on (linux-aarch64 fastdebug), pre-commit checks.
28-11-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/1992 Date: 2023-11-28 20:26:32 +0000
28-11-2023
Here's the stack track for the crashing thread in the jdk-20+20-1388-tier8 sighting: applications/kitchensink/Kitchensink8H.java --------------- T H R E A D --------------- Current thread (0x000002b935c67460): JavaThread "pool-1-thread-2" [_thread_in_vm, id=44700, stack(0x000000eb56400000,0x000000eb56500000)] Stack: [0x000000eb56400000,0x000000eb56500000] Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [jvm.dll+0xc0b6d1] os::win32::platform_print_native_stack+0xf1 (os_windows_x86.cpp:236) V [jvm.dll+0xe6e21e] VMError::report+0x10be (vmError.cpp:841) V [jvm.dll+0xe6fd14] VMError::report_and_die+0x644 (vmError.cpp:1700) V [jvm.dll+0xe70454] VMError::report_and_die+0x64 (vmError.cpp:1481) V [jvm.dll+0x57fb77] report_vm_error+0xb7 (debug.cpp:285) V [jvm.dll+0xe26555] post_thread_park_event+0xb5 (unsafe.cpp:756) V [jvm.dll+0xe1a008] Unsafe_Park+0x348 (unsafe.cpp:781) C 0x000002b916e2cd53 Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) J 20617 jdk.internal.misc.Unsafe.park(ZJ)V java.base@20-ea (0 bytes) @ 0x000002b916e2ccb8 [0x000002b916e2cc40+0x0000000000000078] J 54553 c1 java.util.concurrent.locks.LockSupport.parkNanos(Ljava/lang/Object;J)V java.base@20-ea (56 bytes) @ 0x000002b90de35544 [0x000002b90de352a0+0x00000000000002a4] J 20822 c1 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(J)J java.base@20-ea (207 bytes) @ 0x000002b90f8d00a4 [0x000002b90f8cf8c0+0x00000000000007e4] J 30067 c2 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take()Ljava/util/concurrent/RunnableScheduledFuture; java.base@20-ea (203 bytes) @ 0x000002b916f56694 [0x000002b916f564c0+0x00000000000001d4] J 30537 c2 java.util.concurrent.ThreadPoolExecutor.getTask()Ljava/lang/Runnable; java.base@20-ea (177 bytes) @ 0x000002b916e941ac [0x000002b916e940e0+0x00000000000000cc] j java.util.concurrent.ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V+26 java.base@20-ea j java.util.concurrent.ThreadPoolExecutor$Worker.run()V+5 java.base@20-ea j java.lang.Thread.run()V+13 java.base@20-ea v ~StubRoutines::call_stub 0x000002b9150d107d
16-10-2022
Here's a log file snippet for the jdk-20+20-1384-tier8 sighting: applications/kafkastress/KafkaStressTest.java [2022-10-15 05:05:01,999] INFO [GroupCoordinator 1001]: Stabilized group perf-consumer-87875 generation 1 (__consumer_offsets-0) (kafka.coordinator.group.GroupCoordinator) [2022-10-15 05:05:02,024] INFO [GroupCoordinator 1001]: Assignment received from leader for group perf-consumer-87875 for generation 1 (kafka.coordinator.group.GroupCoordinator) [2022-10-15 05:05:03,544] INFO [GroupCoordinator 1001]: Member[group.instance.id None, member.id consumer-perf-consumer-87875-1-156e58b2-2c8a-464e-bcc3-61a0e3b49b55] in group perf-consumer-87875 has left, removing it from the group (kafka.coordinator.group.GroupCoordinator) [2022-10-15 05:05:03,544] INFO [GroupCoordinator 1001]: Preparing to rebalance group perf-consumer-87875 in state PreparingRebalance with old generation 1 (__consumer_offsets-0) (reason: removing member consumer-perf-consumer-87875-1-156e58b2-2c8a-464e-bcc3-61a0e3b49b55 on LeaveGroup) (kafka.coordinator.group.GroupCoordinator) [2022-10-15 05:05:03,544] INFO [GroupCoordinator 1001]: Group perf-consumer-87875 with generation 2 is now empty (__consumer_offsets-0) (kafka.coordinator.group.GroupCoordinator) # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/opt/mach5/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S94981/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2eda829a-f85f-45b4-b01c-4a699a3b5266/runs/1e00aff6-1da9-4f23-815e-a776be954226/workspace/open/src/hotspot/share/prims/unsafe.cpp:756), pid=989084, tid=989308 # assert(event->should_commit()) failed: invariant # # JRE version: Java(TM) SE Runtime Environment (20.0+20) (fastdebug build 20-ea+20-1384) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 20-ea+20-1384, mixed mode, sharing, tiered, compressed class ptrs, z gc, linux-amd64) # Problematic frame: # V [libjvm.so+0x1ab207f] post_thread_park_event(EventThreadPark*, oop, long, long)+0x15f # # Core dump will be written. Default location: Core dumps may be processed with "/opt/core.sh %p" (or dumping to /opt/mach5/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S94950/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/22d0de81-e81e-4809-86a8-94626a8d13b4/runs/b807e1dd-cfe1-4038-9f58-c590c51f1625/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kafkastress_KafkaStressTest_java/scratch/0/core.989084) # # JFR recording file will be written. Location: /opt/mach5/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S94950/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/22d0de81-e81e-4809-86a8-94626a8d13b4/runs/b807e1dd-cfe1-4038-9f58-c590c51f1625/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kafkastress_KafkaStressTest_java/scratch/0/hs_err_pid989084.jfr # Unsupported internal testing APIs have been used. # An error report file with more information is saved as: # /opt/mach5/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S94950/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/22d0de81-e81e-4809-86a8-94626a8d13b4/runs/b807e1dd-cfe1-4038-9f58-c590c51f1625/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kafkastress_KafkaStressTest_java/scratch/0/hs_err_pid989084.log [607.483s][warning][os] Loading hsdis library failed [thread 989154 also had an error] [thread 989156 also had an error] # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # ----------System.err:(132/47890)---------- Here's the crashing thread's stack: --------------- T H R E A D --------------- Current thread (0x00007f853d8a7a70): JavaThread "data-plane-kafka-request-handler-7" daemon [_thread_in_vm, id=989308, stack(0x00007f847fcfd000,0x00007f847fdfe000)] Stack: [0x00007f847fcfd000,0x00007f847fdfe000], sp=0x00007f847fdfc700, free space=1021k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0x1ab207f] post_thread_park_event(EventThreadPark*, oop, long, long)+0x15f (unsafe.cpp:756) V [libjvm.so+0x1ab287a] Unsafe_Park+0x2da (unsafe.cpp:778) J 3732 jdk.internal.misc.Unsafe.park(ZJ)V java.base@20-ea (0 bytes) @ 0x00007f87c8b26621 [0x00007f87c8b26540+0x00000000000000e1] J 6438 c2 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(J)J java.base@20-ea (207 bytes) @ 0x00007f87c8bbbfa4 [0x00007f87c8bbbba0+0x0000000000000404] J 8974 c2 java.util.concurrent.ArrayBlockingQueue.poll(JLjava/util/concurrent/TimeUnit;)Ljava/lang/Object; java.base@20-ea (83 bytes) @ 0x00007f87c8dbc1f4 [0x00007f87c8dbc0a0+0x0000000000000154] J 7536% c2 kafka.server.KafkaRequestHandler.run()V (223 bytes) @ 0x00007f87c90cbc84 [0x00007f87c90cbb60+0x0000000000000124] j java.lang.Thread.run()V+13 java.base@20-ea v ~StubRoutines::call_stub 0x00007f87c84f8d1a V [libjvm.so+0x102b870] JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x500 (javaCalls.cpp:417) V [libjvm.so+0x102c080] JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, JavaThread*)+0x430 (javaCalls.cpp:331) V [libjvm.so+0x102c4f1] JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, JavaThread*)+0x71 (javaCalls.cpp:193) V [libjvm.so+0x11ad8eb] thread_entry(JavaThread*, JavaThread*)+0x12b (jvm.cpp:2876) V [libjvm.so+0x1061da6] JavaThread::thread_main_inner()+0x206 (javaThread.cpp:699) V [libjvm.so+0x1a54f90] Thread::call_run()+0x100 (thread.cpp:224) V [libjvm.so+0x16f1443] thread_native_entry(Thread*)+0x103 (os_linux.cpp:710) Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) J 3732 jdk.internal.misc.Unsafe.park(ZJ)V java.base@20-ea (0 bytes) @ 0x00007f87c8b265ae [0x00007f87c8b26540+0x000000000000006e] J 6438 c2 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(J)J java.base@20-ea (207 bytes) @ 0x00007f87c8bbbfa4 [0x00007f87c8bbbba0+0x0000000000000404] J 8974 c2 java.util.concurrent.ArrayBlockingQueue.poll(JLjava/util/concurrent/TimeUnit;)Ljava/lang/Object; java.base@20-ea (83 bytes) @ 0x00007f87c8dbc1f4 [0x00007f87c8dbc0a0+0x0000000000000154] J 7536% c2 kafka.server.KafkaRequestHandler.run()V (223 bytes) @ 0x00007f87c90cbc84 [0x00007f87c90cbb60+0x0000000000000124] j java.lang.Thread.run()V+13 java.base@20-ea v ~StubRoutines::call_stub 0x00007f87c84f8d1a
15-10-2022
The fix for this bug is integrated in jdk-20+20-1395.
14-10-2022
Changeset: 21e4f06a Author: Markus Grönlund <mgronlun@openjdk.org> Date: 2022-10-14 12:34:42 +0000 URL: https://git.openjdk.org/jdk/commit/21e4f06ada24098dad4e71b0f9c13afeff87c24b
14-10-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/10700 Date: 2022-10-13 14:38:59 +0000
13-10-2022
This does not seem to be directly related to compiler. As the failing event is a EventThreadPark pointer from JFR, I'll move it to JFR for now for further investigation.
13-10-2022