April 2023 - zgc-dev - openjdk.org

RFR: 8306656: Fix age table logging
by Erik Helin 02 Jan '24

02 Jan '24

Hey all, please review this patch that updates the age table logging. The logging now looks like: [1.946s][info][gc,reloc ] GC(22) y: Age Table: [1.946s][info][gc,reloc ] GC(22) y: Live Small Medium Large [1.946s][info][gc,reloc ] GC(22) y: Eden 0M -> 0M 300 -> 300 0 -> 0 0 -> 0 [1.946s][info][gc,reloc ] GC(22) y: Survivor 1 0M -> 0M 2 -> 2 0 -> 0 0 -> 0 [1.946s][info][gc,reloc ] GC(22) y: Survivor 2 0M -> 0M 1 -> 0 0 -> 0 0 -> 0 [1.946s][info][gc,reloc ] GC(22) y: Survivor 3 0M -> 0M 1 -> 1 0 -> 0 0 -> 0 [1.946s][info][gc,reloc ] GC(22) y: Survivor 4 0M -> 0M 0 -> 1 0 -> 0 0 -> 0 The first column is the size of the live objects with the given age and how that has changed since the previous collection. The remaining columns are the number of pages of the given age and how those have changed from the previous collection to the current one (so the format is `<previous> -> <current>`). This makes it easy to spot a change in behavior in objects' lifetimes from one collection to another: if objects have similar lifetimes compared to the previous collection then the distribution of pages should be similar between the current collection and the previous collection. _Note_: I would like to make the table adapt to live sizes smaller than one megabyte, but that should probably be done for the logging as a whole, not just for the age table. I also cleaned up some minor stuff as I went along. Testing: - [x] Tier 1-3 (macOS-aarch64, Windows-x64, Linux-x64, Linux-aarch64) - [x] Local testing on macOS-aarch64 Thanks, Erik ------------- Commit messages: - Rework age table logging Changes: https://git.openjdk.org/zgc/pull/19/files Webrev: https://webrevs.openjdk.org/?repo=zgc&pr=19&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8306656 Stats: 200 lines in 10 files changed: 104 ins; 52 del; 44 mod Patch: https://git.openjdk.org/zgc/pull/19.diff Fetch: git fetch https://git.openjdk.org/zgc.git pull/19/head:pull/19 PR: https://git.openjdk.org/zgc/pull/19

3 4

Large number of VMAs for large ZGC heap
by Thomas Stüfe 26 Apr '23

26 Apr '23

Hi ZGC experts, I see a strangeness with one of our customers running JDK 17 with ZGC, THP enabled (always), and a large heap of 4.6TB. The number of VMAs exceeds 20 million. I try to understand whether that is normal or pathological. Looking at maps, I see millions of adjacent VMAs that point into the heap to different offsets: ``` 15fc5f600000-15fc5f800000 rw-s 24630400000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 15fc5f800000-15fc5fa00000 rw-s 2504e600000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 15fc5fa00000-15fc5fc00000 rw-s 25330000000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 15fc5fc00000-15fc5fe00000 rw-s 26324200000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 15fc5fe00000-15fc60000000 rw-s 26f03a00000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) ``` The different offsets prevent these mappings from being folded. The number of mappings surpasses what would be needed to map the heap. Almost all are 2MB mappings: Total number of mappings: 18634289 Number of 2MB mappings: 18529201 Per color: 6211420 / 6211429 / 6211439 The total address space covered by these 2MB mappings is 38TB. Taking into account the triple-mapping, we still map about 12TB per color. That far exceeds the necessary room for a 4.6TB heap. Examining the mappings, I see that many offsets into the heap are mapped to multiple points, even discounting the triple mapping. For example, offset 105fe800000 is mapped six times per color, for a total of 12 times: 13438de00000-13438e000000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 15bf79400000-15bf79600000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 165022800000-165022a00000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 16fdad200000-16fdad400000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 17b1b9600000-17b1b9800000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 1d9860000000-1d9860200000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 23438de00000-23438e000000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 25bf79400000-25bf79600000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 265022800000-265022a00000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 26fdad200000-26fdad400000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 27b1b9600000-27b1b9800000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 2d9860000000-2d9860200000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 43438de00000-43438e000000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 45bf79400000-45bf79600000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 465022800000-465022a00000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 46fdad200000-46fdad400000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 47b1b9600000-47b1b9800000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) 4d9860000000-4d9860200000 rw-s 105fe800000 00:0f 373323680 /memfd:java_heap.hugetlb (deleted) The ZGC Page table contains close to a million ZGC pages and looks okay for a heap of that size: Small: 739175 Medium: 10160 Large: 65495 ------- 814830 My question: is such a high number of mappings for ZGC normal? Thank you for your time, Cheers, Thomas

2 3

on heap overhead of ZGC
by Alen Vrečko 23 Apr '23

23 Apr '23

Hello everyone. I did my best to search the web for any prior discussion on this. Haven't found anything useful. I am trying to understand why there is a noticeable difference between the size of all objects on the heap and the heap used (after full GC). The heap used size can be 10%+ more than the size of of all live objects. Let's say I want to fill 1 GiB heap with 4MiB byte[] objects. Naively I'd imagine I can store 1 GiB / 4MiB = 256 such byte[] on the heap. (I made a simple program that just allocates byte[], stores it in a list, does GC and waits (so I can do jcmd or similar), nothing else) With EpsilonGC -> 255x 4MiB byte[] allocations, after this the app crashes with out of memory With SerialGC -> 246x With ParallelGC -> 233x With G1GC -> 204x With ZGC -> 170x For example in the ZGC case, where I have 170x of 4MiB byte[] on the heap. GC.heap_info: ZHeap used 1022M, capacity 1024M, max capacity 1024M Metaspace used 407K, committed 576K, reserved 1114112K class space used 24K, committed 128K, reserved 1048576K GC.class_histogram: Total 15118 713971800 (~714M) In this case does it mean ZGC is wasting 1022M - 714M = 308M for doing its "thing"? This is like 1022/714= 43% overhead? This example might be convoluted and atypical of any production environment. I am seeing the difference between live set and heap used in production at around 12.5% for 3 servers looked at. Is there any other way to estimate the overhead apart from looking at the difference between the live set and heap used? Does ZGC have any internal statistic of the overhead? I'd prefer not to assume 12.5% is the number to use and then get surprised that in some case it might be 25%? Do you have any recommendations regarding ZGC overhead when estimating heap space? Thank you Alen

2 2