JDK-8262897 : [macos_aarch64] TimedAcquireLeak failure
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 17
  • Priority: P4
  • Status: Resolved
  • Resolution: Duplicate
  • OS: os_x
  • CPU: aarch64
  • Submitted: 2021-03-02
  • Updated: 2021-06-29
  • Resolved: 2021-06-28
Related Reports
Duplicate :  
JDK-8262896 - [macos_aarch64] Crash in jni_fast_GetLongField
Relates :  
JDK-8155727 - java/util/concurrent/locks/Lock/TimedAcquireLeak.java timeouts.
Relates :  
JDK-8262896 - [macos_aarch64] Crash in jni_fast_GetLongField
Sub Tasks
JDK-8265111 :  
ProblemList java/util/concurrent/locks/Lock/TimedAcquireLeak.java on macosx-aarch64 - Resolved
JDK-8269534 :  
Remove java/util/concurrent/locks/Lock/TimedAcquireLeak.java from ProblemList.txt - Resolved
Description
Testing https://github.com/openjdk/jdk/pull/2200 reveals this failure in java/util/concurrent/locks/Lock/TimedAcquireLeak.java: 

java.lang.Exception: Stack trace
	at java.base/java.lang.Thread.dumpStack(Thread.java:1377)
	at TimedAcquireLeak.fail(TimedAcquireLeak.java:333)
	at TimedAcquireLeak.fail(TimedAcquireLeak.java:334)
	at TimedAcquireLeak.equal(TimedAcquireLeak.java:340)
	at TimedAcquireLeak.outputOf(TimedAcquireLeak.java:108)
	at TimedAcquireLeak.commandOutputOf(TimedAcquireLeak.java:115)
	at TimedAcquireLeak.realMain(TimedAcquireLeak.java:220)
	at TimedAcquireLeak.main(TimedAcquireLeak.java:342)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
	at java.base/java.lang.Thread.run(Thread.java:831)
java.lang.Exception: Stack trace
	at java.base/java.lang.Thread.dumpStack(Thread.java:1377)
	at TimedAcquireLeak.fail(TimedAcquireLeak.java:333)
	at TimedAcquireLeak.fail(TimedAcquireLeak.java:334)
	at TimedAcquireLeak.equal(TimedAcquireLeak.java:340)
	at TimedAcquireLeak.outputOf(TimedAcquireLeak.java:109)
	at TimedAcquireLeak.commandOutputOf(TimedAcquireLeak.java:115)
	at TimedAcquireLeak.realMain(TimedAcquireLeak.java:220)
	at TimedAcquireLeak.main(TimedAcquireLeak.java:342)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
	at java.base/java.lang.Thread.run(Thread.java:831)
java.lang.AssertionError: Some tests failed
	at TimedAcquireLeak.main(TimedAcquireLeak.java:344)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
	at java.base/java.lang.Thread.run(Thread.java:831)
Comments
[~dcubed] Sorry, I was expecting to look at this, but other priorities ate me :( The former java backtrace did not provide a clue this bug relates to JDK-8262896. Thank you for taking care of this.
29-06-2021
[~dholmes] - agreed. Thanks for the suggestion.
28-06-2021
I'd create a subtask to correct the ProblemList, so that this bug is clearly seen to be a duplicate.
28-06-2021
[~gziemski] - I'm going to close this bug as a duplicate of: JDK-8262896 [macos_aarch64] Crash in jni_fast_GetLongField after doing more testing on the JDK18 version (assuming no new failures). Update: Hmmmm... I forgot that I still need to integrate a fix to take the test off the ProblemList so maybe I'll use this bug for that. Not sure yet.
26-06-2021
I did an experiment where I backed out the fix for JDK-8262896: commit 5d16652ef130af4113c9eca0ef6b39fd31a58fdf Author: Daniel D. Daugherty <daniel.daugherty@oracle.com> Date: Fri Jun 25 16:12:46 2021 -0400 Revert "8262896: [macos_aarch64] Crash in jni_fast_GetLongField" This reverts commit 283d64f81531ec3edc156f13278a9a284445b61d. Did a clean rebuild and retested: $ do_java_test java/util/concurrent/locks/Lock/TimedAcquireLeak.java INFO: GNUMAKE=make INFO: GNUMAKE version is: GNU Make 3.81 INFO: JTREG options: INFO: JOBS=4 INFO: TEST_MODE=agentvm INFO: EXTRA_PROBLEM_LISTS=ProblemList-extra.txt INFO: VM_OPTIONS= INFO: test_val=java/util/concurrent/locks/Lock/TimedAcquireLeak.java Test Config: macosx-aarch64-normal-server-release INFO: TIMEOUT_FACTOR=4 Done testing Test Run macosx-aarch64-normal-server-release time: 0.35 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java >> 1 0 1 0 << 1 failure(s) found in log=do_java_test.macosx-aarch64-normal-server-release.log TEST: java/util/concurrent/locks/Lock/TimedAcquireLeak.java LOG: build/macosx-aarch64-normal-server-release/test-support/jtreg_open_test_jdk_java_util_concurrent_locks_Lock_TimedAcquireLeak_java/java/util/concurrent/locks/Lock/TimedAcquireLeak.jtr Saving build/macosx-aarch64-normal-server-release/test-support/jtreg_open_test_jdk_java_util_concurrent_locks_Lock_TimedAcquireLeak_java/java/util/concurrent/locks/Lock/TimedAcquireLeak.jtr as /work/shared/bug_hunt/exp_for_jdk18.git/test_failures.2021-06-25-170352/TimedAcquireLeak.jtr.release Saving build/macosx-aarch64-normal-server-release/test-support/jtreg_open_test_jdk_java_util_concurrent_locks_Lock_TimedAcquireLeak_java/java/util/concurrent/locks/Lock/TimedAcquireLeak/hs_err_pid41927.log as /work/shared/bug_hunt/exp_for_jdk18.git/test_failures.2021-06-25-170352/hs_err_pid41927.log Test Config: macosx-aarch64-normal-server-fastdebug INFO: TIMEOUT_FACTOR=6 Done testing Test Run macosx-aarch64-normal-server-fastdebug time: 0.28 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java 1 1 0 0 Test Config: macosx-aarch64-normal-server-slowdebug INFO: TIMEOUT_FACTOR=12 Done testing Test Run macosx-aarch64-normal-server-slowdebug time: 0.67 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java 1 1 0 0 Total test time: 1.30 minutes. The "release" bits failure shows the same failure mode as the original sighting: # SIGBUS (0xa) at pc=0x000000011144c180, pid=41927, tid=40707 # # JRE version: Java(TM) SE Runtime Environment (18.0) (build 18-internal+0-2021-06-25-2036524.dcubed...) # Java VM: Java HotSpot(TM) 64-Bit Server VM (18-internal+0-2021-06-25-2036524.dcubed..., mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, bsd-aarch64) # Problematic frame: # v ~BufferBlob::jni_fast_GetLongField <snip> --------------- T H R E A D --------------- Current thread (0x0000000154885800): JavaThread "Common-Cleaner" daemon [_thread_in_native, id=40707, stack(0x000000016e1fc000,0x000000016e3ff000)] Stack: [0x000000016e1fc000,0x000000016e3ff000], sp=0x000000016e3fe730, free space=2057k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) v ~BufferBlob::jni_fast_GetLongField V [libjvm.dylib+0x7d63a4] Perf_Detach+0x13c j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@18-internalj jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@18-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@18-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@18-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@18-internal j java.lang.Thread.run()V+11 java.base@18-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@18-internal v ~StubRoutines::call_stub V [libjvm.dylib+0x464278] _ZN9JavaCalls11call_helperEP9JavaValueRK12methodHandleP17JavaCallArgumentsP10JavaThread+0x38c V [libjvm.dylib+0x463294] _ZN9JavaCalls12call_virtualEP9JavaValueP5KlassP6SymbolS5_P17JavaCallArgumentsP10JavaThread+0x11c V [libjvm.dylib+0x463360] _ZN9JavaCalls12call_virtualEP9JavaValue6HandleP5KlassP6SymbolS6_P10JavaThread+0x64 V [libjvm.dylib+0x5156dc] _ZL12thread_entryP10JavaThreadS0_+0xc4 V [libjvm.dylib+0x8f950c] _ZN10JavaThread17thread_main_innerEv+0xa0 V [libjvm.dylib+0x8f7ef8] _ZN6Thread8call_runEv+0x128 V [libjvm.dylib+0x7a3e1c] _ZL19thread_native_entryP6Thread+0x158 C [libsystem_pthread.dylib+0x7878] _pthread_start+0x140 Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@18-internal j jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@18-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@18-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@18-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@18-internal j java.lang.Thread.run()V+11 java.base@18-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@18-internal v ~StubRoutines::call_stub siginfo: si_signo: 10 (SIGBUS), si_code: 1 (BUS_ADRALN), si_addr: 0x000000011144c180
25-06-2021
The failure mode that I see in the two hs_err_pid files looks like: JDK-8262896 [macos_aarch64] Crash in jni_fast_GetLongField which [~akozlov] fixed in JDK17-B18.
25-06-2021
The test is currently passing with JDK18 bits as of: $ git log -r HEAD^! commit 35c4702055ccf11975391df01f62a70e06ecae83 (HEAD -> master, origin/master, origin/HEAD) Author: Patrick Concannon <pconcannon@openjdk.org> Date: Fri Jun 25 16:34:18 2021 +0000 8268967: Update java.security to use switch expressions Reviewed-by: xuelei $ do_java_test java/util/concurrent/locks/Lock/TimedAcquireLeak.java INFO: GNUMAKE=make INFO: GNUMAKE version is: GNU Make 3.81 INFO: JTREG options: INFO: JOBS=4 INFO: TEST_MODE=agentvm INFO: EXTRA_PROBLEM_LISTS=ProblemList-extra.txt INFO: VM_OPTIONS= INFO: test_val=java/util/concurrent/locks/Lock/TimedAcquireLeak.java Test Config: macosx-aarch64-normal-server-release INFO: TIMEOUT_FACTOR=4 Done testing Test Run macosx-aarch64-normal-server-release time: 0.22 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java 1 1 0 0 Test Config: macosx-aarch64-normal-server-fastdebug INFO: TIMEOUT_FACTOR=6 Done testing Test Run macosx-aarch64-normal-server-fastdebug time: 0.25 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java 1 1 0 0 Test Config: macosx-aarch64-normal-server-slowdebug INFO: TIMEOUT_FACTOR=12 Done testing Test Run macosx-aarch64-normal-server-slowdebug time: 0.64 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/java/util/concurrent/locks/Lock/TimedAcquireLeak.java 1 1 0 0 Total test time: 1.10 minutes.
25-06-2021
There are two hs_err_pid files for this failure sighting. Here are snippets from the first: # SIGBUS (0xa) at pc=0x000000010d50c400, pid=27682, tid=41475 # # JRE version: Java(TM) SE Runtime Environment (17.0) (build 17-internal+0-LTS-2021-02-27-1954067.mikael.vidstedt.jdk-macosjib) # Java VM: Java HotSpot(TM) 64-Bit Server VM (17-internal+0-LTS-2021-02-27-1954067.mikael.vidstedt.jdk-macosjib, mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc, bsd-aarch64) # Problematic frame: # v ~BufferBlob::jni_fast_GetLongField <snip> Current thread (0x000000012f85a800): JavaThread "Common-Cleaner" daemon [_thread_in_native, id=41475, stack(0x0000000171a8c000,0x0000000171c8f000)] Stack: [0x0000000171a8c000,0x0000000171c8f000], sp=0x0000000171c8e750, free space=2057k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) v ~BufferBlob::jni_fast_GetLongField V [libjvm.dylib+0x7a6538] Perf_Detach+0x168 j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@17-internal j jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@17-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@17-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@17-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@17-internal j java.lang.Thread.run()V+11 java.base@17-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@17-internal v ~StubRoutines::call_stub V [libjvm.dylib+0x4313a0] _ZN9JavaCalls11call_helperEP9JavaValueRK12methodHandleP17JavaCallArgumentsP6Thread+0x318 V [libjvm.dylib+0x430430] _ZN9JavaCalls12call_virtualEP9JavaValueP5KlassP6SymbolS5_P17JavaCallArgumentsP6Thread+0x11c V [libjvm.dylib+0x4304fc] _ZN9JavaCalls12call_virtualEP9JavaValue6HandleP5KlassP6SymbolS6_P6Thread+0x64 V [libjvm.dylib+0x4e5994] _ZL12thread_entryP10JavaThreadP6Thread+0xc4 V [libjvm.dylib+0x8bbc4c] _ZN10JavaThread17thread_main_innerEv+0xa8 V [libjvm.dylib+0x8ba3e8] _ZN6Thread8call_runEv+0x8c V [libjvm.dylib+0x773b80] _ZL19thread_native_entryP6Thread+0x16c C [libsystem_pthread.dylib+0x706c] _pthread_start+0x140 Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@17-internal j jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@17-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@17-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@17-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@17-internal j java.lang.Thread.run()V+11 java.base@17-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@17-internal v ~StubRoutines::call_stub siginfo: si_signo: 10 (SIGBUS), si_code: 1 (BUS_ADRALN), si_addr: 0x000000010d50c400 And here are snippets from the second: # SIGBUS (0xa) at pc=0x000000010dd0c400, pid=27685, tid=40707 # # JRE version: Java(TM) SE Runtime Environment (17.0) (build 17-internal+0-LTS-2021-02-27-1954067.mikael.vidstedt.jdk-macosjib) # Java VM: Java HotSpot(TM) 64-Bit Server VM (17-internal+0-LTS-2021-02-27-1954067.mikael.vidstedt.jdk-macosjib, mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc, bsd-aarch64) # Problematic frame: # v ~BufferBlob::jni_fast_GetLongField <snip> --------------- T H R E A D --------------- Current thread (0x000000013c064c00): JavaThread "Common-Cleaner" daemon [_thread_in_native, id=40707, stack(0x000000017142c000,0x000000017162f000)] Stack: [0x000000017142c000,0x000000017162f000], sp=0x000000017162e750, free space=2057k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) v ~BufferBlob::jni_fast_GetLongField V [libjvm.dylib+0x7a6538] Perf_Detach+0x168 j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@17-internal j jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@17-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@17-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@17-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@17-internal j java.lang.Thread.run()V+11 java.base@17-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@17-internal v ~StubRoutines::call_stub V [libjvm.dylib+0x4313a0] _ZN9JavaCalls11call_helperEP9JavaValueRK12methodHandleP17JavaCallArgumentsP6Thread+0x318 V [libjvm.dylib+0x430430] _ZN9JavaCalls12call_virtualEP9JavaValueP5KlassP6SymbolS5_P17JavaCallArgumentsP6Thread+0x11c V [libjvm.dylib+0x4304fc] _ZN9JavaCalls12call_virtualEP9JavaValue6HandleP5KlassP6SymbolS6_P6Thread+0x64 V [libjvm.dylib+0x4e5994] _ZL12thread_entryP10JavaThreadP6Thread+0xc4 V [libjvm.dylib+0x8bbc4c] _ZN10JavaThread17thread_main_innerEv+0xa8 V [libjvm.dylib+0x8ba3e8] _ZN6Thread8call_runEv+0x8c V [libjvm.dylib+0x773b80] _ZL19thread_native_entryP6Thread+0x16c C [libsystem_pthread.dylib+0x706c] _pthread_start+0x140 Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) j jdk.internal.perf.Perf.detach(Ljava/nio/ByteBuffer;)V+0 java.base@17-internal j jdk.internal.perf.Perf$CleanerAction.run()V+8 java.base@17-internal j jdk.internal.ref.CleanerImpl$PhantomCleanableRef.performCleanup()V+4 java.base@17-internal j jdk.internal.ref.PhantomCleanable.clean()V+12 java.base@17-internal j jdk.internal.ref.CleanerImpl.run()V+57 java.base@17-internal j java.lang.Thread.run()V+11 java.base@17-internal j jdk.internal.misc.InnocuousThread.run()V+20 java.base@17-internal v ~StubRoutines::call_stub siginfo: si_signo: 10 (SIGBUS), si_code: 1 (BUS_ADRALN), si_addr: 0x000000010dd0c400
25-06-2021
[~akozlov] - Hope you don't mind that I stole back this bug. I've gotten an M1 MacMini and I'm going to use this bug to check out whether I have the dev environment set up properly... wish me luck!
25-06-2021
[~akozlov] - This one should have been assigned to you instead of me so I've taken care of that.
07-04-2021