JDK-8256729 : [windows] runtime/cds/SharedBaseAddress.java: assert on split_reserved_memory
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 16
  • Priority: P3
  • Status: Resolved
  • Resolution: Duplicate
  • Submitted: 2020-11-20
  • Updated: 2022-09-14
  • Resolved: 2021-01-08
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
17Resolved
Related Reports
Duplicate :  
JDK-8255917 - runtime/cds/SharedBaseAddress.java failed "assert(reserved_rgn != 0LL) failed: No reserved region"
Relates :  
JDK-8256864 - [windows] Improve tracing for mapping errors
Relates :  
JDK-8253649 - Potential bug in os::split_reserved_memory on windows
Description
When trying to split a memory reservation this assertion is hit:
#  Internal Error (t:/workspace/open/src/hotspot/os/windows/os_windows.cpp:3221), pid=673620, tid=1168692
#  assert(false) failed: os::split_reserved_memory failed for [[0x000001e30f000000-0x000001e350000000))
#

This happens when running the test:
runtime/cds/SharedBaseAddress.java

Stacktrace:
Current thread (0x000001e36a1b95f0):  JavaThread "Unknown thread" [_thread_in_vm, id=1168692, stack(0x0000004248300000,0x0000004248400000)]

Stack: [0x0000004248300000,0x0000004248400000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0xadf471]  os::platform_print_native_stack+0xf1  (os_windows_x86.cpp:236)
V  [jvm.dll+0xd06067]  VMError::report+0xfb7  (vmError.cpp:731)
V  [jvm.dll+0xd0798e]  VMError::report_and_die+0x7de  (vmError.cpp:1537)
V  [jvm.dll+0xd080a4]  VMError::report_and_die+0x64  (vmError.cpp:1328)
V  [jvm.dll+0x4ba787]  report_vm_error+0x117  (debug.cpp:267)
V  [jvm.dll+0xadd84c]  os::split_reserved_memory+0x1fc  (os_windows.cpp:3220)
V  [jvm.dll+0xd0187e]  ReservedSpace::first_part+0x6e  (virtualspace.cpp:260)
V  [jvm.dll+0xa557b6]  MetaspaceShared::reserve_address_space_for_archives+0x4b6  (metaspaceShared.cpp:1636)
V  [jvm.dll+0xa534d1]  MetaspaceShared::map_archives+0x141  (metaspaceShared.cpp:1367)
V  [jvm.dll+0xa52b40]  MetaspaceShared::initialize_runtime_shared_and_meta_spaces+0x1b0  (metaspaceShared.cpp:1282)
V  [jvm.dll+0xa4be17]  Metaspace::global_initialize+0x57  (metaspace.cpp:684)
V  [jvm.dll+0xcbcae9]  universe_init+0x149  (universe.cpp:745)
V  [jvm.dll+0x669081]  init_globals+0x31  (init.cpp:119)
V  [jvm.dll+0xc8c866]  Threads::create_vm+0x626  (thread.cpp:3567)
V  [jvm.dll+0x746232]  JNI_CreateJavaVM_inner+0xb2  (jni.cpp:3765)
V  [jvm.dll+0x7491ff]  JNI_CreateJavaVM+0x1f  (jni.cpp:3848)
C  [jli.dll+0x53ef]  JavaMain+0x113  (java.c:416)
C  [ucrtbase.dll+0x21ffa]
C  [KERNEL32.DLL+0x17974]
C  [ntdll.dll+0x6a271]
Comments
This should be a dup of 8255917.
08-01-2021
Related to JDK-8256213 "Remove os::split_reserved_memory"
03-12-2020
[~stuefe] " And this coding is real old. Why does it start failing now. Who could allocate there? There should be no concurrent allocation ongoing at this point." os::split_reserved_memory() had been around for a long time, but we've been using it to split only the default CDS region at 0x800000000. We starting splitting the region at OS-picked addresses only recently since JDK-8231610 (Nov 2019).
30-11-2020
[~stuefe] How easy is it from you for reproduce the failure? Did you save the MDMP file? If so, you can see the memory mappings using WinDBG: https://stackoverflow.com/questions/22722345/windbg-memory-map/22732961
30-11-2020
JDK-8256864 "[windows] Improve tracing for mapping errors" , needed for further analysis, needs reviews.
25-11-2020
ILW = HLM = P3
24-11-2020
Eventually sure, but I'd like to understand what happens. We can pull the plug on os::split_reserved_memory() at any time. I have one final PR open to improve error handling and actually print the whole mapping of the failed split: https://github.com/openjdk/jdk/pull/1390 What makes me nervous is that this release-and-re-reserve technique is used in other places too. So we should rewrite those too. And this coding is real old. Why does it start failing now. Who could allocate there? There should be no concurrent allocation ongoing at this point.
23-11-2020
Let's just get rid of os::split_reserved_memory() -- JDK-8256213.
23-11-2020
So what happens: - we reserve memory for CDS + metaspace combined at [0x0000016a0f000000-0x0000016a50000000) - os::split_resreved_memory: -> we release the whole region. Which works -> we reallocate the first region (CDS), rather small: [0x0000016a0f000000-0x0000016a10000000) -> we attempt to reserve the second region (Class space): [0x0000016a10000000-0x0000016a50000000) which fails with 487 Now I wonder whether NMT itself is the problem here. os::split_reserved_region() does: 1) call os::release_memory(whole region) 2) call os::reserve_memory(part1) 3) call os::reserve_memory(part2) -> fails I find it very unlikely that someone concurrently grabbed address space. Especially since this is during VM initialization where we are still single threaded. But os::release_memory() does: VirtualFree(), then calls into NMT to unregister the region. And os::reserve_memory() does call VirtualAlloc(), then registers that region with NMT. If NMT itself allocates memory (maybe C-Heap) in (2) which then would by placed, by the Operating System, inside the supposed class space region, then this would explain the allocation failure at (3). Especially since we are here in the "allocate CDS/CCS anywhere" path where the original location for CDS/CCS has been chosen by the Operating System. One obvious solution would be to re-implement os::split_reserved_memory() with VirtualAlloc() and VirtualFree(), bypassing NMT and UL.
22-11-2020
ok, 487 also occurs when the range to reserve is in use. Damn those incomplete MSDN API specs.
22-11-2020
"[0.115s][info ][os ] VirtualAlloc(0x0000016a10000000, 1073741824, 2000, 4) failed (487)." Weird. 487 = ERROR_INVALID_ADDRESS According to MSDN https://docs.microsoft.com/en-us/windows/win32/api/memoryapi/nf-memoryapi-virtualalloc , VirtualAlloc returns 487 in two cases: 1) When using a non-NULL wish address in conjunction with MEM_COMMIT. This is not the case here. Call is done with MEM_RESERVE(0x2000) 2) "If the (wish) address in within an enclave that you initialized, then the allocation operation fails with the ERROR_INVALID_ADDRESS error." Enclaves are Microsoft's interface to Intel Software Guard Extensions (https://software.intel.com/content/www/us/en/develop/topics/software-guard-extensions.html). Does the VM run under some form of intrusion prevention or similar?
21-11-2020
Bumping from P4 to P3 since this failure mode is showing up fairly frequently in Tier3.
21-11-2020
Here's a snippet from the log file for the jdk-16+26-1701-tier3 sighting: ----------System.err:(119/9165)*---------- stdout: [[0.006s][debug][os] Initial active processor count set to 16 [0.008s][debug][nmt] Add reserved region 'Unknown' (0x0000016a75100000, 8192) [0.008s][debug][nmt] Add committed region 'Unknown'(0x0000016a75100000, 8192) Succeeded [0.008s][info ][os ] SafePoint Polling address, bad (protected) page:0x0000016a75100000, good (unprotected) page:0x0000016a75101000 [0.012s][debug][nmt] Add reserved region 'Internal' (0x0000016a75110000, 65536) [0.012s][debug][nmt] Add committed region 'Unknown'(0x0000016a75110000, 65536) Succeeded [0.012s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1200000, 1048576) [0.012s][debug][nmt] Add committed region 'Unknown'(0x00000043e1200000, 16384) Succeeded [0.014s][info ][os ] attempting shared library load of c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-16+26-1701\\windows-x64-debug.jdk\\jdk-16\\fastdebug\\bin\\java.dll [0.015s][info ][os ] shared library load of c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-16+26-1701\\windows-x64-debug.jdk\\jdk-16\\fastdebug\\bin\\java.dll was successful [0.016s][debug][nmt] Add reserved region 'Unknown' (0x0000016a00000000, 251658240) [0.016s][debug][nmt] Add committed region 'Unknown'(0x0000016a00000000, 2555904) Succeeded [0.016s][debug][nmt] Add reserved region 'Unknown' (0x0000016a75360000, 65536) [0.016s][debug][nmt] Add committed region 'Unknown'(0x0000016a75360000, 20480) Succeeded [0.018s][debug][nmt] Add committed region 'Unknown'(0x0000016a00750000, 2555904) Succeeded [0.018s][debug][nmt] Add reserved region 'Unknown' (0x0000016a75720000, 983040) [0.018s][debug][nmt] Add committed region 'Unknown'(0x0000016a75720000, 20480) Succeeded [0.019s][debug][nmt] Add committed region 'Unknown'(0x0000016a07ba0000, 2555904) Succeeded [0.020s][debug][nmt] Add reserved region 'Unknown' (0x0000016a75810000, 983040) [0.020s][debug][nmt] Add committed region 'Unknown'(0x0000016a75810000, 20480) Succeeded [0.023s][info ][os ] attempting shared library load of KernelBase [0.023s][info ][os ] shared library load of KernelBase was successful [0.024s][info ][os ] attempting shared library load of KernelBase [0.024s][info ][os ] shared library load of KernelBase was successful [0.024s][info ][os ] attempting shared library load of KernelBase [0.024s][info ][os ] shared library load of KernelBase was successful [0.024s][info ][os ] attempting shared library load of KernelBase [0.024s][info ][os ] shared library load of KernelBase was successful [0.024s][info ][os ] attempting shared library load of KernelBase [0.024s][info ][os ] shared library load of KernelBase was successful [0.025s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1300000, 1048576) [0.025s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1400000, 1048576) [0.025s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1500000, 1048576) [0.025s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1700000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1600000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1800000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1a00000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1b00000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1900000, 1048576) [0.026s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1c00000, 1048576) [0.027s][debug][nmt] Add reserved region 'Unknown' (0x0000040000000000, 32984006656) [0.027s][debug][nmt] Add reserved region 'Unknown' (0x0000080000000000, 32984006656) [0.027s][debug][nmt] Add reserved region 'Unknown' (0x0000100000000000, 32984006656) [0.027s][debug][nmt] Add reserved region 'Unknown' (0x0000016a75370000, 65536) [0.027s][debug][nmt] Add committed region 'Unknown'(0x0000016a75370000, 65536) Succeeded [0.028s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1d00000, 1048576) [0.029s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1e00000, 1048576) [0.096s][debug][nmt] Add committed region 'Unknown'(0x0000040000000000, 1073741824) Succeeded [0.097s][debug][nmt] Add reserved region 'Unknown' (0x0000016a7d620000, 16777216) [0.097s][debug][nmt] Add committed region 'Unknown'(0x0000016a7d620000, 16777216) Succeeded [0.097s][debug][nmt] Add reserved region 'Unknown' (0x0000016a7e620000, 16777216) [0.097s][debug][nmt] Add committed region 'Unknown'(0x0000016a7e620000, 16777216) Succeeded [0.097s][debug][nmt] Add reserved region 'Unknown' (0x0000016a7f620000, 8589934592) [0.097s][debug][nmt] Add committed region 'Unknown'(0x0000016a7f620000, 33554432) Succeeded [0.111s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e1f00000, 1048576) [0.111s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2000000, 1048576) [0.111s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2100000, 1048576) [0.112s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2200000, 1048576) [0.112s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2300000, 1048576) [0.112s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2400000, 1048576) [0.112s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2500000, 1048576) [0.112s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2600000, 1048576) [0.113s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2700000, 1048576) [0.113s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2800000, 1048576) [0.113s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2900000, 1048576) [0.114s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2a00000, 1048576) [0.114s][debug][nmt] Add reserved region 'Thread Stack' (0x00000043e2b00000, 1048576) [0.114s][info ][cds] trying to map SharedBaseAddress1g.jsa [0.114s][info ][cds] Opened archive SharedBaseAddress1g.jsa. [0.114s][info ][cds] Archive was created with UseCompressedOops = 0, UseCompressedClassPointers = 1 [0.114s][info ][cds] full module graph: disabled because archive was created without full module graph [0.114s][info ][os ] VirtualAlloc(0x0000000040000000, 1090519040, 2000, 4) failed (487). [0.114s][debug][os ] Attempt to reserve memory at 0x0000000040000000 for 1090519040 bytes failed, errno 487 [0.114s][debug][cds] Failed to reserve spaces (use_requested_addr=1) [0.114s][info ][cds] Try to map archive(s) at an alternative address [0.114s][debug][nmt] Add reserved region 'Unknown' (0x0000016a0f000000, 1090519040) [0.115s][debug][nmt] Remove uncommitted region 'Unknown' (0x0000016a0f000000, 1090519040) Succeeded [0.115s][debug][nmt] Removed region 'Unknown' (0x0000016a0f000000, 1090519040) from _resvered_regions Succeeded [0.115s][debug][nmt] Add reserved region 'Unknown' (0x0000016a0f000000, 16777216) [0.115s][info ][os ] VirtualAlloc(0x0000016a10000000, 1073741824, 2000, 4) failed (487). [0.115s][debug][os ] Attempt to reserve memory at 0x0000016a10000000 for 1073741824 bytes failed, errno 487 [0.115s][warning][os ] os::split_reserved_memory failed for [[0x0000016a0f000000-0x0000016a50000000)) # To suppress the following error report, specify this argument # after -XX: or in .hotspotrc: SuppressErrorAt=t:/workspace/open/src/hotspot/os/windows/os_windows.cpp:3221 # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (t:/workspace/open/src/hotspot/os/windows/os_windows.cpp:3221), pid=823332, tid=812824 # assert(false) failed: os::split_reserved_memory failed for [[0x0000016a0f000000-0x0000016a50000000)) # # JRE version: (16.0+26) (fastdebug build ) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 16-ea+26-1701, mixed mode, sharing, tiered, z gc, windows-amd64) # Core dump will be written. Default location: T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_runtime\\scratch\\7\\hs_err_pid823332.mdmp # # An error report file with more information is saved as: # T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_runtime\\scratch\\7\\hs_err_pid823332.log # # ]; stderr: [] exitValue = 1 Here's the crashing stack from the jdk-16+26-1701-tier3 sighting: --------------- T H R E A D --------------- Current thread (0x0000016a75f6ba20): JavaThread "Unknown thread" [_thread_in_vm, id=812824, stack(0x00000043e1200000,0x00000043e1300000)] Stack: [0x00000043e1200000,0x00000043e1300000] Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [jvm.dll+0xadf111] os::platform_print_native_stack+0xf1 (os_windows_x86.cpp:236) V [jvm.dll+0xd05897] VMError::report+0xfb7 (vmError.cpp:731) V [jvm.dll+0xd071be] VMError::report_and_die+0x7de (vmError.cpp:1537) V [jvm.dll+0xd078d4] VMError::report_and_die+0x64 (vmError.cpp:1328) V [jvm.dll+0x4ba6d7] report_vm_error+0x117 (debug.cpp:267) V [jvm.dll+0xadd65c] os::split_reserved_memory+0x1fc (os_windows.cpp:3220) V [jvm.dll+0xd010ae] ReservedSpace::first_part+0x6e (virtualspace.cpp:260) V [jvm.dll+0xa55616] MetaspaceShared::reserve_address_space_for_archives+0x4b6 (metaspaceShared.cpp:1636) V [jvm.dll+0xa53331] MetaspaceShared::map_archives+0x141 (metaspaceShared.cpp:1367) V [jvm.dll+0xa529a0] MetaspaceShared::initialize_runtime_shared_and_meta_spaces+0x1b0 (metaspaceShared.cpp:1282) V [jvm.dll+0xa4bc47] Metaspace::global_initialize+0x57 (metaspace.cpp:684) V [jvm.dll+0xcbc699] universe_init+0x149 (universe.cpp:745) V [jvm.dll+0x668eb1] init_globals+0x31 (init.cpp:119) V [jvm.dll+0xc8c416] Threads::create_vm+0x626 (thread.cpp:3567) V [jvm.dll+0x746062] JNI_CreateJavaVM_inner+0xb2 (jni.cpp:3765) V [jvm.dll+0x74902f] JNI_CreateJavaVM+0x1f (jni.cpp:3848) C [jli.dll+0x53ef] JavaMain+0x113 (java.c:416) C [ucrtbase.dll+0x21ffa] C [KERNEL32.DLL+0x17974] C [ntdll.dll+0x6a271]
21-11-2020
Attached the log file and the hs_err_pid file from the jdk-16+26-1699-tier3 sighting: test-support_jtreg_open_test_hotspot_jtreg_hotspot_runtime_runtime_cds_SharedBaseAddress.log test-support_jtreg_open_test_hotspot_jtreg_hotspot_runtime_runtime_cds_SharedBaseAddress_hs_err_pid1009860.log
21-11-2020
Quite sure this is a duplicate to JDK-8255917. We added asserts to split_memory to catch those errors earlier. The test is ran with Xlog:os=debug, so the VM should have printed helpful information to stdout/err. Could you please attach the jtr files, and if possible the hs-err file?
21-11-2020