JDK-8343893 : Test jdk/jfr/event/runtime/TestNativeMemoryUsageEvents.java failed: heap should have grown and NMT should show that: expected 0 > 0
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 24
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2024-11-10
  • Updated: 2024-11-28
  • Resolved: 2024-11-22
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 24
24 b26Fixed
Related Reports
Relates :  
JDK-8318098 - Update jfr tests with corresponding requires flags
Relates :  
JDK-8343953 - Test jdk/jfr/threading/TestDeepVirtualStackTrace.java fails with Parallel/Serial GC
Sub Tasks
JDK-8344051 :  
Problemlist jdk/jfr/event/runtime/TestNativeMemoryUsageEvents.java with ZGC until JDK-8343893 is fixed - Resolved
Description
Test: jdk/jfr/event/runtime/TestNativeMemoryUsageEvents.java

----------System.out:(13/869)----------
[0.040s][info][gc] Using The Z Garbage Collector
[1.109s][info][gc] GC(0) Major Collection (Warmup)
[1.217s][info][gc] GC(0) Major Collection (Warmup) 14M(11%)->8M(6%) 0.107s
[1.385s][info][gc] GC(1) Major Collection (Warmup)
[1.506s][info][gc] GC(1) Major Collection (Warmup) 26M(20%)->82M(64%) 0.121s
[1.510s][info][gc] GC(2) Major Collection (Warmup)
[1.610s][info][gc] GC(3) Minor Collection (Allocation Rate)
[1.871s][info][gc] GC(3) Minor Collection (Allocation Rate) 80M(62%)->82M(64%) 0.260s
[1.878s][info][gc] GC(4) Minor Collection (Allocation Rate)
[1.937s][info][gc] GC(4) Minor Collection (Allocation Rate) 82M(64%)->86M(67%) 0.060s
[1.949s][info][gc] GC(5) Minor Collection (Allocation Rate)
[2.050s][info][gc] GC(5) Minor Collection (Allocation Rate) 86M(67%)->82M(64%) 0.101s
[2.050s][info][gc] GC(2) Major Collection (Warmup) 82M(64%)->82M(64%) 0.540s
----------System.err:(14/1012)----------
java.lang.RuntimeException: heap should have grown and NMT should show that: expected 0 > 0
	at jdk.test.lib.Asserts.fail(Asserts.java:691)
	at jdk.test.lib.Asserts.assertGreaterThan(Asserts.java:400)
	at jdk.jfr.event.runtime.TestNativeMemoryUsageEvents.verifyHeapGrowth(TestNativeMemoryUsageEvents.java:155)
	at jdk.jfr.event.runtime.TestNativeMemoryUsageEvents.main(TestNativeMemoryUsageEvents.java:188)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
	at java.base/java.lang.Thread.run(Thread.java:1576)

Failed in tier8 on three platforms: linux-x64, linux-aarch64, windows-x64
Comments
Changeset: 2ea0364b Branch: master Author: Johan Sjölen <jsjolen@openjdk.org> Date: 2024-11-22 08:55:27 +0000 URL: https://git.openjdk.org/jdk/commit/2ea0364b6e3f10977f7b607d239c29ee616a8f7c
22-11-2024
A pull request was submitted for review. Branch: master URL: https://git.openjdk.org/jdk/pull/22204 Date: 2024-11-18 11:44:41 +0000
18-11-2024
So this was caused by JDK-8341280 , which not only added the UseCOH flag but also the set of GC flags, hence we started running these tests with different GCs compared to usual..
13-11-2024
Leonid's evaluation of the problem is correct. We have not added any JFR integration for the new MemoryFileTracker. I'm evaluating what needs to be done for this issue right now.
12-11-2024
The usage event looks like: jdk.NativeMemoryUsage { startTime = 19:15:07.214 (2024-11-08) type = "Java Heap" reserved = 16.1 GB committed = 0.0 MB } while NTM memory report has: Native Memory Tracking: Total: reserved=36038064519, committed=1758534023 malloc: 121268615 #153665, peak=120511943 #144555 mmap: reserved=35916795904, committed=1637265408 - Java Heap (reserved=17246978048, committed=1493172224) (mmap: reserved=17246978048, committed=1493172224, at peak) ..... The native memory report use: void MemBaseline::baseline_summary() { MallocMemorySummary::snapshot(&_malloc_memory_snapshot); VirtualMemorySummary::snapshot(&_virtual_memory_snapshot); { MemoryFileTracker::Instance::Locker lock; MemoryFileTracker::Instance::summary_snapshot(&_virtual_memory_snapshot); } _metaspace_stats = MetaspaceUtils::get_combined_statistics(); } and JFR inly virtual memory void NMTUsage::update_vm_usage() { const VirtualMemorySnapshot* vms = VirtualMemorySummary::as_snapshot(); // Reset total to allow recalculation. _vm_total.committed = 0; _vm_total.reserved = 0; for (int i = 0; i < mt_number_of_tags; i++) { MemTag mem_tag = NMTUtil::index_to_tag(i); const VirtualMemory* vm = vms->by_type(mem_tag); _vm_by_type[i].reserved = vm->reserved(); _vm_by_type[i].committed = vm->committed(); _vm_total.reserved += vm->reserved(); _vm_total.committed += vm->committed(); } } so it is needed to etiher update ZGC JFR reporting to track memory commited by MemoryFileTracker or to updated test to exepct that cmmited memory is zero.
11-11-2024
It is not lilliput problem. The test doesn't work with all GCs. It checks committed memory but for ZGC it doesn't add memory allocated by MemoryFileTracker.
11-11-2024
I will file a seperate bug, for tracking purposes, for the jdk/jfr/threading/TestDeepVirtualStackTrace.java failures.
11-11-2024
jdk/jfr/threading/TestDeepVirtualStackTrace.java also seems to fail with -XX:+UseCompactObjectHeaders and "java.lang.RuntimeException: No event found in virtual thread: expected false, was true".
11-11-2024
This happens with -XX:+UseCompactObjectHeaders. Roman has agreed to take a look at it.
11-11-2024
Moving to Runtime to investigate if there has been changes to NMT.
11-11-2024