JDK-8273639 : tests fail with "assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 18
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: windows
  • CPU: x86_64
  • Submitted: 2021-09-12
  • Updated: 2021-09-20
  • Resolved: 2021-09-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 18
18 b15Fixed
Related Reports
Relates :  
JDK-8273482 - Remove "foreground work" concept from WorkGang
Relates :  
JDK-8273733 - Remove HandleMark
Description
The following test failed in the JDK18 CI:

serviceability/dcmd/gc/HeapDumpAllTest.java

Here's a snippet from the log file:

----------stdout:(18/1117)*----------
# To suppress the following error report, specify this argument
# after -XX: or in .hotspotrc:  SuppressErrorAt=\\handles.cpp:35
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (t:\\workspace\\open\\src\\hotspot\\share\\runtime\\handles.cpp:35), pid=3540, tid=25336
#  assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark
#
# JRE version: Java(TM) SE Runtime Environment (18.0+15) (fastdebug build 18-ea+15-794)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+15-794, compiled mode, tiered, compressed oops, compressed class ptrs, g1 gc, windows-amd64)
# Core dump will be written. Default location: T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\5\\hs_err_pid3540.mdmp
#
# An error report file with more information is saved as:
# T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\5\\hs_err_pid3540.log
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#
result: Error. Agent communication error: java.net.SocketException: Connection reset; check console log for any additional details


Here's the crashing thread's stack:

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

Current thread (0x000001a491005d00):  GCTaskThread "GC Thread#2" [stack: 0x0000003d8c300000,0x0000003d8c400000] [id=25336] _threads_hazard_ptr=0x000001a48f54e810, _nested_threads_hazard_ptr_cnt=0

Stack: [0x0000003d8c300000,0x0000003d8c400000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0xadc411]  os::platform_print_native_stack+0xf1  (os_windows_x86.cpp:235)
V  [jvm.dll+0xcf9675]  VMError::report+0x1005  (vmError.cpp:742)
V  [jvm.dll+0xcfb01e]  VMError::report_and_die+0x7fe  (vmError.cpp:1552)
V  [jvm.dll+0xcfb7a4]  VMError::report_and_die+0x64  (vmError.cpp:1333)
V  [jvm.dll+0x4ce027]  report_vm_error+0xb7  (debug.cpp:282)
V  [jvm.dll+0x6594c0]  HandleArea::allocate_handle+0x40  (handles.cpp:35)
V  [jvm.dll+0x4cfeb2]  ConstantOopReadValue::ConstantOopReadValue+0x162  (debugInfo.cpp:267)
V  [jvm.dll+0x4d05d8]  ScopeValue::read_from+0xe8  (debugInfo.cpp:108)
V  [jvm.dll+0x4d07ee]  ObjectValue::read_object+0x1e  (debugInfo.cpp:152)
V  [jvm.dll+0x4d0b6a]  DebugInfoReadStream::read_object_value+0x1aa  (debugInfo.cpp:80)
V  [jvm.dll+0x4d0663]  ScopeValue::read_from+0x173  (debugInfo.cpp:111)
V  [jvm.dll+0xb87d1d]  ScopeDesc::ScopeDesc+0x13d  (scopeDesc.cpp:39)
V  [jvm.dll+0xcebba0]  compiledVFrame::compiledVFrame+0xa0  (vframe_hp.cpp:293)
V  [jvm.dll+0xce7c23]  vframe::new_vframe+0x173  (vframe.cpp:86)
V  [jvm.dll+0xce906e]  vframe::sender+0x1be  (vframe.cpp:112)
V  [jvm.dll+0xced8a5]  compiledVFrame::sender+0xd5  (vframe_hp.cpp:388)
V  [jvm.dll+0xc8f693]  ThreadStackTrace::dump_stack_at_safepoint+0x153  (threadService.cpp:669)
V  [jvm.dll+0x66380f]  VM_HeapDumper::dump_stack_traces+0x23f  (heapDumper.cpp:1868)
V  [jvm.dll+0x6650c6]  VM_HeapDumper::work+0x226  (heapDumper.cpp:1815)
V  [jvm.dll+0xd3f28a]  GangWorker::loop+0x8a  (workgroup.cpp:240)
V  [jvm.dll+0xd3f32d]  GangWorker::run+0x1d  (workgroup.cpp:207)
V  [jvm.dll+0xc7c164]  Thread::call_run+0x1b4  (thread.cpp:365)
V  [jvm.dll+0xadadce]  thread_native_entry+0xae  (os_windows.cpp:549)
C  [ucrtbase.dll+0x1fb80]
C  [KERNEL32.DLL+0x84d4]
C  [ntdll.dll+0x51781]
Comments
Changeset: f5272899 Author: Per Liden <pliden@openjdk.org> Date: 2021-09-14 08:36:39 +0000 URL: https://git.openjdk.java.net/jdk/commit/f52728993dc8f61a537b899ed0c47d83ca594738
14-09-2021
Looks like a missing HandleMark. This is a unintended side-effect of my fix for JDK-8273482. With that fix, calls to ThreadStackTrace::dump_stack_at_safepoint() can now be made from Worker threads. Previously it was always done from the VMThread, which always puts a HandleMark on the stack before evaluating the VM operation. The reason this wasn't noticed when testing JDK-8273482 is that you needs to be a little bit unlucky, and take the stacktrace when there's certain types op frames on the stack. Assigning this to myself.
13-09-2021
The following tests failed the same assert in the JDK18 CI: serviceability/dcmd/gc/HeapDumpCompressedTest.java#id1 serviceability/dcmd/gc/HeapDumpCompressedTest.java#id2 serviceability/dcmd/gc/HeapDumpCompressedTest.java#id3 Here's a snippet from one of the HeapDumpCompressedTest.java#id1 log files: ---------------- stderr ---------------- ---------------------------------------- Running DCMD 'GC.heap_dump -gz=1 T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\0\\jcmd.gc.heap_dump.1631391589436.hprof.gz' through 'PidJcmdExecutor' Executing command '[c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-18+15-786\\windows-x64-debug.jdk\\jdk-18\\fastdebug\\bin\\jcmd.exe, 14176, GC.heap_dump -gz=1 T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\0\\jcmd.gc.heap_dump.1631391589436.hprof.gz]' [2021-09-11T20:20:13.443763100Z] Gathering output for process 34576 # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=\\handles.cpp:35 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (t:\\workspace\\open\\src\\hotspot\\share\\runtime\\handles.cpp:35), pid=14176, tid=20108 # assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark # # JRE version: Java(TM) SE Runtime Environment (18.0+15) (fastdebug build 18-ea+15-786) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+15-786, compiled mode, sharing, tiered, compressed oops, compressed class ptrs, parallel gc, windows-amd64) # Core dump will be written. Default location: T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\0\\hs_err_pid14176.mdmp # # An error report file with more information is saved as: # T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\0\\hs_err_pid14176.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # ----------System.err:(0/0)---------- ----------rerun:(53/6416)*---------- Here's a snippet from one of the HeapDumpCompressedTest.java#id2 log files: ---------------- stderr ---------------- ---------------------------------------- Running DCMD 'GC.heap_dump -gz=1 T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\1\\jcmd.gc.heap_dump.1631391511832.hprof.gz' through 'PidJcmdExecutor' Executing command '[c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-18+15-786\\windows-x64-debug.jdk\\jdk-18\\fastdebug\\bin\\jcmd.exe, 20340, GC.heap_dump -gz=1 T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\1\\jcmd.gc.heap_dump.1631391511832.hprof.gz]' [2021-09-11T20:18:38.666715400Z] Gathering output for process 32372 # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=\\handles.cpp:35 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (t:\\workspace\\open\\src\\hotspot\\share\\runtime\\handles.cpp:35), pid=20340, tid=58424 # assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark # # JRE version: Java(TM) SE Runtime Environment (18.0+15) (fastdebug build 18-ea+15-786) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+15-786, compiled mode, sharing, compressed oops, compressed class ptrs, g1 gc, windows-amd64) # Core dump will be written. Default location: T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\1\\hs_err_pid20340.mdmp # # An error report file with more information is saved as: # T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\scratch\\1\\hs_err_pid20340.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # ----------System.err:(0/0)---------- ----------rerun:(53/6410)*---------- Here's a snippet from one of the HeapDumpCompressedTest.java#id3 log files: ---------------- stderr ---------------- ---------------------------------------- Running DCMD 'GC.heap_dump -gz=1 /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/1/jcmd.gc.heap_dump.1631389520528.hprof.gz' through 'PidJcmdExecutor' Executing command '[/opt/mach5/mesos/work_dir/jib-master/install/jdk-18+15-786/linux-x64-debug.jdk/jdk-18/fastdebug/bin/jcmd, 27907, GC.heap_dump -gz=1 /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/1/jcmd.gc.heap_dump.1631389520528.hprof.gz]' [2021-09-11T19:45:25.830172574Z] Gathering output for process 28093 # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=/handles.cpp:35 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13815/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/07d36d5b-fee2-45e0-a832-229be203cb25/runs/538c354b-ab44-471b-9fc8-90402e8494c7/workspace/open/src/hotspot/share/runtime/handles.cpp:35), pid=27907, tid=27921 # assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark # # JRE version: Java(TM) SE Runtime Environment (18.0+15) (fastdebug build 18-ea+15-786) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+15-786, compiled mode, sharing, compressed class ptrs, z gc, linux-amd64) # Problematic frame: # V [libjvm.so+0xd66b74] HandleArea::allocate_handle(oop)+0x214 # # 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/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/1/core.27907) # # An error report file with more information is saved as: # /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/1/hs_err_pid27907.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # ----------System.err:(0/0)---------- ----------rerun:(48/7741)*----------
12-09-2021
The following test failed the same assert in the JDK18 CI: serviceability/dcmd/gc/HeapDumpTest.java Here's a snippet from the log file: ----------stdout:(21/1866)---------- # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=/handles.cpp:35 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13815/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/07d36d5b-fee2-45e0-a832-229be203cb25/runs/538c354b-ab44-471b-9fc8-90402e8494c7/workspace/open/src/hotspot/share/runtime/handles.cpp:35), pid=28440, tid=30705 # assert(_handle_mark_nesting > 1) failed: memory leak: allocating handle outside HandleMark # # JRE version: Java(TM) SE Runtime Environment (18.0+15) (fastdebug build 18-ea+15-786) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+15-786, compiled mode, compressed oops, compressed class ptrs, g1 gc, linux-amd64) # Problematic frame: # V [libjvm.so+0xd66b74] HandleArea::allocate_handle(oop)+0x214 # # 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/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/3/core.28440) # # An error report file with more information is saved as: # /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13974/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e269cef-d4f7-434d-ba13-83d25173f189/runs/56a8b3ca-f8d0-48fc-827d-b817e27840e7/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_serviceability/scratch/3/hs_err_pid28440.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # result: Error. Agent communication error: java.io.EOFException; check console log for any additional details Here's the crashing thread's stack: --------------- T H R E A D --------------- Current thread (0x00007fc614008f80): GCTaskThread "GC Thread#8" [stack: 0x00007fc61c6f1000,0x00007fc61c7f1000] [id=30705] _threads_hazard_ptr=0x00007fc5d82a3300, _nested_threads_hazard_ptr_cnt=0 Stack: [0x00007fc61c6f1000,0x00007fc61c7f1000], sp=0x00007fc61c7ec0a0, free space=1004k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0xd66b74] HandleArea::allocate_handle(oop)+0x214 V [libjvm.so+0xa7a414] ConstantOopReadValue::ConstantOopReadValue(DebugInfoReadStream*)+0x94 V [libjvm.so+0xa7aef0] ScopeValue::read_from(DebugInfoReadStream*)+0x1e0 V [libjvm.so+0xa7a79f] ObjectValue::read_object(DebugInfoReadStream*)+0x1f V [libjvm.so+0xa7ac50] DebugInfoReadStream::read_object_value(bool)+0x350 V [libjvm.so+0x16efe43] ScopeDesc::decode_object_values(int)+0x193 V [libjvm.so+0x16efef4] ScopeDesc::ScopeDesc(CompiledMethod const*, PcDesc*, bool)+0x44 V [libjvm.so+0xa25e6a] CompiledMethod::scope_desc_at(unsigned char*)+0xda V [libjvm.so+0x1963b1a] compiledVFrame::compiledVFrame(frame const*, RegisterMap const*, JavaThread*, CompiledMethod*)+0x6a V [libjvm.so+0x1958a38] vframe::new_vframe(frame const*, RegisterMap const*, JavaThread*) [clone .part.0]+0x68 V [libjvm.so+0x1959038] vframe::sender() const+0x128 V [libjvm.so+0x1963910] compiledVFrame::sender() const+0x50 V [libjvm.so+0x18b21f6] ThreadStackTrace::dump_stack_at_safepoint(int)+0xc6 V [libjvm.so+0xd83b8d] VM_HeapDumper::dump_stack_traces()+0x1ed V [libjvm.so+0xd84028] VM_HeapDumper::work(unsigned int) [clone .part.0]+0xc8 V [libjvm.so+0x19f32d5] GangWorker::run_task(WorkData)+0x85 V [libjvm.so+0x19f3414] GangWorker::loop()+0x44 V [libjvm.so+0x19f346a] V [libjvm.so+0x1898cb0] Thread::call_run()+0x100 V [libjvm.so+0x15768b4] thread_native_entry(Thread*)+0x104
12-09-2021