NMT: Weird merging of regions

Thu Jan 25 15:31:55 UTC 2018

Hi Coleen and Zhengyu,

Thanks for the feedback.

The accounting part of the patch is wrong, because the size of the next 
node needs to be subtracted. I fixed this, simplified the code, and 
added a test:

http://cr.openjdk.java.net/~stefank/zgc/zNMTMerging/webrev.02

With this patch all tests test/hotspot/jtreg/runtime/NMT passes.

Thanks,
StefanK

On 2018-01-24 17:40, coleen.phillimore at oracle.com wrote:
> 
> Yeah, I don't remember why we checked for null.   Probably just to 
> simplify the code path.
> 
> The patch looks good.  There should be a test in the test system to 
> verify it (see the bug that Zhengyu pointed to).
> 
> Coleen
> 
> On 1/24/18 10:43 AM, Zhengyu Gu wrote:
>> Hi Stefan,
>>
>> It looks like a bug that subsequent small regions were not merged, 
>> they all have the same stacks. This part of code was last touched by 
>> JDK-8138705 (https://bugs.openjdk.java.net/browse/JDK-8138705), not 
>> sure if it is the cause.
>>
>> Your patch looks good to me.
>>
>> Thanks,
>>
>> -Zhengyu
>>
>> On 01/24/2018 10:17 AM, Stefan Karlsson wrote:
>>> Hi Zhengyu (all),
>>>
>>> I was looking at the NMT output from one of our stress tests and saw 
>>> something unexpected. It looks like the first number commits of small 
>>> ZPages get merged into one region, until we allocate a medium ZPage 
>>> which ends up at the end of the virtual address space. After the 
>>> medium ZPage has been allocated non of the subsequent small ZPages 
>>> get merged.
>>>
>>> I traced the committing of memory:
>>>
>>> [0.079s][info][gc     ] nmt_commit   0x0000040000000000 514048K
>>> [2.523s][info][gc     ] nmt_commit   0x000004001f600000 2048K
>>> [2.528s][info][gc     ] nmt_commit   0x000004001f800000 2048K
>>> [2.533s][info][gc     ] nmt_commit   0x000004001fa00000 2048K
>>> [2.535s][info][gc     ] nmt_commit   0x000004001fc00000 2048K
>>> [2.537s][info][gc     ] nmt_commit   0x000004001fe00000 2048K
>>> [2.538s][info][gc     ] nmt_commit   0x0000040020000000 2048K
>>> [2.543s][info][gc     ] nmt_commit   0x0000040020200000 2048K
>>> [2.547s][info][gc     ] nmt_commit   0x0000040020400000 2048K
>>> ...
>>> [3.714s][info][gc       ] nmt_commit   0x000004003c200000 2048K
>>> [3.715s][info][gc       ] nmt_commit   0x000004003c400000 2048K
>>> [3.731s][info][gc       ] nmt_commit   0x000007fffe000000 32768K
>>> [3.737s][info][gc       ] nmt_commit   0x000007fffc000000 32768K
>>> [3.737s][info][gc       ] nmt_commit   0x000004003c600000 2048K
>>> [3.741s][info][gc       ] nmt_commit   0x000004003c800000 2048K
>>>
>>> The output from NMT is:
>>>
>>> [0x0000040000000000 - 0x000004001f600000] committed 514048KB from
>>>      [0x00002b9e6209618b] 
>>> ZPreMappedMemory::ZPreMappedMemory(ZVirtualMemoryManager&, 
>>> ZPhysicalMemoryManager&, unsigned long)+0xfb
>>>      [0x00002b9e6208e277] ZPageAllocator::ZPageAllocator(unsigned 
>>> long, unsigned long, unsigned long)+0x67
>>>      [0x00002b9e620706fc] ZHeap::ZHeap()+0xac
>>>      [0x00002b9e6206c2c9] 
>>> ZCollectedHeap::ZCollectedHeap(ZCollectorPolicy*)+0x49
>>>
>>> [0x000004001f600000 - 0x000004003c600000] committed 475136KB from
>>>      [0x00002b9e620907bb] ZPageAllocator::alloc_page(unsigned char, 
>>> unsigned long, ZAllocationFlags)+0x9b
>>>      [0x00002b9e620712e7] ZHeap::alloc_page(unsigned char, unsigned 
>>> long, ZAllocationFlags)+0x17
>>>      [0x00002b9e6207faa4] 
>>> ZObjectAllocator::alloc_object_in_shared_page(ZPage**, unsigned char, 
>>> unsigned long, unsigned long, ZAllocationFlags)+0x114
>>>      [0x00002b9e62081853] ZObjectAllocator::alloc_object(unsigned 
>>> long)+0x103
>>>
>>> [0x000004003c600000 - 0x000004003c800000] committed 2048KB from
>>>      [0x00002b9e620907bb] ZPageAllocator::alloc_page(unsigned char, 
>>> unsigned long, ZAllocationFlags)+0x9b
>>>      [0x00002b9e620712e7] ZHeap::alloc_page(unsigned char, unsigned 
>>> long, ZAllocationFlags)+0x17
>>>      [0x00002b9e6207faa4] 
>>> ZObjectAllocator::alloc_object_in_shared_page(ZPage**, unsigned char, 
>>> unsigned long, unsigned long, ZAllocationFlags)+0x114
>>>      [0x00002b9e62081853] ZObjectAllocator::alloc_object(unsigned 
>>> long)+0x103
>>>
>>> [0x000004003c800000 - 0x000004003ca00000] committed 2048KB from
>>>      [0x00002b9e620907bb] ZPageAllocator::alloc_page(unsigned char, 
>>> unsigned long, ZAllocationFlags)+0x9b
>>>      [0x00002b9e620712e7] ZHeap::alloc_page(unsigned char, unsigned 
>>> long, ZAllocationFlags)+0x17
>>>      [0x00002b9e6207faa4] 
>>> ZObjectAllocator::alloc_object_in_shared_page(ZPage**, unsigned char, 
>>> unsigned long, unsigned long, ZAllocationFlags)+0x114
>>>      [0x00002b9e62081853] ZObjectAllocator::alloc_object(unsigned 
>>> long)+0x103
>>>
>>>
>>> As can be seen all pages between:
>>> [2.523s][info][gc     ] nmt_commit   0x000004001f600000 2048K
>>>
>>> and:
>>> [3.715s][info][gc       ] nmt_commit   0x000004003c400000 2048K
>>>
>>> are merged into:
>>> [0x000004001f600000 - 0x000004003c600000] committed 475136KB from
>>>
>>> However the small page commits after the medium page commits all get 
>>> separate entries.
>>>
>>> I looked at the code in add_committed_region and this seems to be 
>>> intentionally:
>>>        // special case to expand prior region if there is no next region
>>>
>>> but I don't understand the _reason_ why we don't merge the added 
>>> region with adjacent next regions.
>>>
>>> Zhengyu, do you know/remember the motivation behind this?
>>>
>>>
>>> I created a patch to try to merge with the next region:
>>>   http://cr.openjdk.java.net/~stefank/zgc/zNMTMerging/webrev.01/
>>>
>>> This yields NMT output like the following:
>>>
>>> [0x0000040000000000 - 0x000004001f600000] committed 514048KB from
>>>      [0x00002b26cda232db] 
>>> ZPreMappedMemory::ZPreMappedMemory(ZVirtualMemoryManager&, 
>>> ZPhysicalMemoryManager&, unsigned long)+0xfb
>>>      [0x00002b26cda1b3c7] ZPageAllocator::ZPageAllocator(unsigned 
>>> long, unsigned long, unsigned long)+0x67
>>>      [0x00002b26cd9fd84c] ZHeap::ZHeap()+0xac
>>>      [0x00002b26cd9f9419] 
>>> ZCollectedHeap::ZCollectedHeap(ZCollectorPolicy*)+0x49
>>>
>>> [0x000004001f600000 - 0x0000040380800000] committed 14174208KB from
>>>      [0x00002b26cda1d90b] ZPageAllocator::alloc_page(unsigned char, 
>>> unsigned long, ZAllocationFlags)+0x9b
>>>      [0x00002b26cd9fe437] ZHeap::alloc_page(unsigned char, unsigned 
>>> long, ZAllocationFlags)+0x17
>>>      [0x00002b26cda0cbf4] 
>>> ZObjectAllocator::alloc_object_in_shared_page(ZPage**, unsigned char, 
>>> unsigned long, unsigned long, ZAllocationFlags)+0x114
>>>      [0x00002b26cda0e9a3] ZObjectAllocator::alloc_object(unsigned 
>>> long)+0x103
>>>
>>> [0x000007ffce000000 - 0x0000080000000000] committed 819200KB from
>>>      [0x00002b26cda1d90b] ZPageAllocator::alloc_page(unsigned char, 
>>> unsigned long, ZAllocationFlags)+0x9b
>>>      [0x00002b26cd9fe437] ZHeap::alloc_page(unsigned char, unsigned 
>>> long, ZAllocationFlags)+0x17
>>>      [0x00002b26cda0cbf4] 
>>> ZObjectAllocator::alloc_object_in_shared_page(ZPage**, unsigned char, 
>>> unsigned long, unsigned long, ZAllocationFlags)+0x114
>>>      [0x00002b26cda0e935] ZObjectAllocator::alloc_object(unsigned 
>>> long)+0x95
>>>
>>> StefanK
> 