8262386: resourcehogs/serviceability/sa/TestHeapDumpForLargeArray.java timed out

[linzang]

---

Progress

• Change must not contain extraneous whitespace
• Commit message must refer to an issue
• Change must be properly reviewed

Issue

• JDK-8262386: resourcehogs/serviceability/sa/TestHeapDumpForLargeArray.java timed out

Reviewers

• Chris Plummer (@plummercj - Reviewer) ⚠️ Review applies to c80a10e
• Serguei Spitsyn (@sspitsyn - Reviewer) ⚠️ Review applies to 621b27d

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/2803/head:pull/2803
$ git checkout pull/2803

Update a local copy of the PR:
$ git checkout pull/2803
$ git pull https://git.openjdk.java.net/jdk pull/2803/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 2803

View PR using the GUI difftool:
$ git pr show -t 2803

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/2803.diff

[bridgekeeper]

👋 Welcome back lzang! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

[openjdk]

@linzang The following label will be automatically applied to this pull request:

• serviceability

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

[mlbridge]

Webrevs

• 15: Full - Incremental (9b614aff)
• 14: Full - Incremental (621b27dc)
• 13: Full - Incremental (a87793c3)
• 12: Full - Incremental (dd665c5e)
• 11: Full - Incremental (c80a10e0)
• 10: Full - Incremental (01e1a107)
• 09: Full - Incremental (6fde07bd)
• 08: Full - Incremental (67f6d985)
• 07: Full - Incremental (70dbbfea)
• 06: Full - Incremental (a173251)
• 05: Full - Incremental (bb5827d)
• 04: Full - Incremental (7eb475e)
• 03: Full - Incremental (6019b1f)
• 02: Full - Incremental (8dde2fd)
• 01: Full - Incremental (70e43dd)
• 00: Full (1fe8c0c)

[plummercj]

The fix is fairly big and could use some explaining. Can you provide a bit more detail on what the bug is? In the CR you mention it is due to the combination of a very large array and the segmented heap dump support, but don't really explain what the actual bug is. You can add this detail to the CR rather than here. Also can explain your solution, especially this new writeThrough mode? Thanks.

[linzang]

Hi Chris,

Thanks for your review, I found there is a potential risk for huge object dumping with this PR, I would work out an update and then add the explaination in the CR.
Thanks!

BRs,
Lin

[plummercj]

Thanks for the explanation in the CR. That helps a lot. I didn't have time to get through the review today, but will do so tomorrow.

[linzang]

Hi Chris,
Thanks a lot, I am still wip to reduce the memory consumption. So I think you could help review after my next update :)

BRs,
Lin

[linzang]

Update a new patch that reduce the memory consumption issue.
As mentioned in the CR, there is internal buffer used for segmented heap dump. The dumped object data firstly write into this buffer and then flush() when the size is known. when the internal buffer is full, the current implementation do:

• new a larger buffer, copy data from old buffer into the new one, and then use it as the internal buffer.

This could cause large memory consumption because the old buffer data are copied, and also the old buffer can not be "free" until next GC.

For example, if the internel buffer's length is 1MB, when it is full, a new 2MB buffer is allocated so there is actually 3MB memory taken (old buffer + new buffer). And in this case, for the ~4GB large array, it keeps generating new buffers and do copying, which takes both CPU and memory intensively and cause the timeout issue.

This patch optimize it by creating a array list of byte[]. when old buffer is full, it saved into the list and the new one is created and used as the internal buffer. In this case, the above example takes 2MB（1MB for old， saved in the list; and 1MB for the new buffer)

Together with the "write through" mode introduced in this PR, by which all arrays are write through to underlying stream and hence no extra buffer requried. The PR could help fix the LargeArray issue and also save memory.

Thanks!
Lin

[linzang]

As discussed in CR https://bugs.openjdk.java.net/browse/JDK-8262386, the byte[] list is much more like an optimization. Revert it in the PR and I will create a separate CR and PR for it.

Thanks,
Lin

[plummercj]

It seems to me this is the key part of the fix, and all other changes and driven by this change. What I don't understand is why enabling writeThrough is done here in calculateArrayMaxLength(), especially since this same code might be execute more than once for the same segment (thus "enabling" writeThrough when it is already enabled). What is the actual trigger for wanting writeThrough mode? Is it really just seeing an array for the first time in a segment?

[linzang]

Dear Chris,

What I don't understand is why enabling writeThrough is done here in calculateArrayMaxLength()

This is the place where the array size could be calculated by the writer before the array element data are written. So there is no need to cache the array in the internal buffer of segmentedOutputStream.

especially since this same code might be execute more than once for the same segment (thus "enabling" writeThrough when it is already enabled).

IMO, it is not possible to execute write-through multiple times. in fillSegmentSizeAndEnableWriteThrough() there is a flush that will write all buffered data in to underlying output stream first and then start write-through mode.
And from the implementation in

jdk/src/jdk.hotspot.agent/share/classes/sun/jvm/hotspot/utilities/AbstractHeapGraphWriter.java

Line 62 in c484d89

writeHeapRecordPrologue();

the method writeHeapRecordEpilogue() would be called for every object iterated. And in this method, the exitSegmentMode() will be called which will disable write-through mode.

Briefly, the segment could contain multiple objects. But the array object would be treated as a new standalone segment, which is written to the underlying output stream directly by write-through mode.

What is the actual trigger for wanting writeThrough mode? Is it really just seeing an array for the first time in a segment?

The root cause for requiring writeThrough mode is to avoid caching data in the internal buffer of SegmentedOutputStream, which would cause memory consumption and also performance issues, which is the also the root cause of this bug.

Moreover, the reason that need to "cache data" in internal buffer before data written to file is that current implementation of SA heap dumper need to fill the size slot in segment header only after the segment data are written. Which is hard to do after introducing gzipped heap dump because the header and the data are compressed when written to file and not easy to be modified.

However, the current implementation of dumping array object first calculates the array size, so the size of segment data is known when creating segment header. And this fix uses that info to avoid cache array data.

[sspitsyn]

Hi Lin,

One concern I have is the naming used in the fix.
First, the term write-through you use is unusual and confusing.
Would it better to say 'direct or unbuffered output' instead?

 612         // Now the total size of data to dump is known and can be filled to segment header.
 613         // Enable write-through mode to avoid internal buffer copies.
 614         if (useSegmentedHeapDump) {
 615             long longBytes = length * typeSize + headerSize;
 616             int bytesToWrite = (int) (longBytes);
 617             hprofBufferedOut.fillSegmentSizeAndEnableWriteThrough(bytesToWrite);
 618         }

Why 'longBytes' ? The scope of this local variable is very short, and it is clear that its type is long.
Why not something like 'size' or 'totalSize' ?
There is no need in parentheses around the 'longBytes' at L616.
Also, there is no need to for one more local variable 'bytesToWrite'.
Something like below is more clear:
int size = (int)(length * typeSize + headerSize);
I agree with Chris, it is confusing why the decision about write-trough mode is made in this method.
The method fillSegmentSizeAndEnableWriteThrough() is called for any array if useSegmentedHeapDump == true,
so any segmented output for arrays is direct (in write-through mode).
Is this new dimension really needs to be introduced?

Thanks,
Serguei

[sspitsyn]

One more question.

1367         public synchronized void write(int b) throws IOException {
1368            if (segmentMode && !writeThrough) {
1369                if (segmentWritten == 0) {
1370                    // At the begining of the segment.
1371                    writeSegmentHeader();
1372                } else if (segmentWritten == segmentBuffer.length) {
1373                    // Internal buffer is full, extend a larger one.
1374                    int newSize = segmentBuffer.length + SEGMENT_BUFFER_INC_SIZE;
1375                    byte newBuf[] = new byte[newSize];
1376                    System.arraycopy(segmentBuffer, 0, newBuf, 0, segmentWritten);
1377                    segmentBuffer = newBuf;
1378                }
1379                segmentBuffer[segmentWritten++] = (byte)b;
1380                return;
1381            }
1382            super.write(b);
1383         }

Does the check for "!writeThrough" at L1368 means there is no need to write the segment header (as at L1371)?

[linzang]

Dear Serguei,
Thanks for review! I will refine it based on your comments.

I agree with Chris, it is confusing why the decision about write-trough mode is made in this method

The "write-through" mode requires filling the segment size in segment header before object contents are scanned and written, And it is only in method calculateArrayMaxLength() the array size could be known and filled, and therefore the write-through mode could be enabled.
(please be aware that current implementation of dumping non-array object does not calculate the object size first, which is
the reason why internal buffer is required when compressed heap dump was introduced.)

The method fillSegmentSizeAndEnableWriteThrough() is called for any array if useSegmentedHeapDump == true,
so any segmented output for arrays is direct (in write-through mode).
Is this new dimension really needs to be introduced?

IMO, it is better to dump all array object in write-through mode, because it could avoid memory consumption and performance issue when dumping large array. And the original implementation of object dump works like write-through, so this fix looks like sort of retrieve back to the original behavior.

On the other side, the specific issue described at JDK-8262386 could also be fixed if enable write-through mode only when array size is larger than maxBytes calculated in calculateArrayMaxLength(), because the test created an 4GB integer array. But I suggest to write-through all array objects as this could help avoid similar issue that may happen when dump large array whose size is less than 4GB.

Does the check for "!writeThrough" at L1368 means there is no need to write the segment header (as at L1371)?

Yes, The writeSegmentHeader(size) is invoked in fillSegmentSizeAndEnableWriteThrough(), so there is no need to call it here.

Thanks!
Lin

[plummercj]

IMO, it is better to dump all array object in write-through mode, because it could avoid memory consumption and performance issue when dumping large array. And the original implementation of object dump works like write-through, so this fix looks like sort of retrieve back to the original behavior.

I guess I don't understand why you would want write-through for small arrays but not large objects. I also have to admit I don't fully grasp the purpose of "segment mode". I see the docs say:

 301  * A heap dump can optionally be generated as a sequence of heap dump
 302  * segments. This sequence is terminated by an end record. The additional
 303  * tags allowed by format "JAVA PROFILE 1.0.2" are:
 304  *
 305  * HPROF_HEAP_DUMP_SEGMENT  denote a heap dump segment
 306  *
 307  *               [heap dump sub-records]*
 308  *               The same sub-record types allowed by HPROF_HEAP_DUMP
 309  *
 310  * HPROF_HEAP_DUMP_END      denotes the end of a heap dump

But all this seems to be doing is grouping the HPROF_HEAP_DUMP records into an array rather than having them interspersed with other types of records. How does this help, and why would this mode not always be enabled?

Also I'm not so sure the above documentation is fully accurate. It looks like both HPROF_HEAP_DUMP_SEGMENT and HPROF_HEAP_DUMP_END are followed by a 4-byte size and 4-byte timestamp, although the timestamp seems to always be 0, and the size for END is also always 0.

[linzang]

Dear Chris，

I guess I don't understand why you would want write-through for small arrays but not large objects.

I think it is because that the current implementation does not have code which could calculate the object size before scan it. but it has the logic for calculate array length (calculateArrayMaxLength()) ahead of scaning. ( BTW, I am planing to add the logic for object, and then rewrite the whole heap dump impl to use writeThrough also for compressed dump, I think that should be in a separate PR)

But all this seems to be doing is grouping the HPROF_HEAP_DUMP records into an array rather than having them interspersed with other types of records. How does this help, and why would this mode not always be enabled?

I think the original pupose of SEGMENT heap dump is to handle the case for large heap. In the hprof format spec, the size slot of the heap dump is 32bit, which means it has limitation of dump 4GB used heap. so use segmental dump could help resolve the problem. And IMO the reason for not always enable it is because every segment has a header and tail, which may introduce extra memory, althogh it is not much.

It looks like both HPROF_HEAP_DUMP_SEGMENT and HPROF_HEAP_DUMP_END are followed by a 4-byte size and 4-byte timestamp, although the timestamp seems to always be 0, and the size for END is also always 0.

My understand from code is that 4-byte size and 4-byte timestamp only exist after HPROF_HEAP_DUMP_SEGMENT, and the HPROF_HEAP_DUMP_END actually is the end of the segment. So I think the specification is not accurate.

Thanks,
Lin

[plummercj]

I guess I don't understand why you would want write-through for small arrays but not large objects.

I think it is because that the current implementation does not have code which could calculate the object size before scan it. but it has the logic for calculate array length (calculateArrayMaxLength()) ahead of scaning. ( BTW, I am planing to add the logic for object, and then rewrite the whole heap dump impl to use writeThrough also for compressed dump, I think that should be in a separate PR)

Can't you just call Oop.getObjectSize()?

But all this seems to be doing is grouping the HPROF_HEAP_DUMP records into an array rather than having them interspersed with other types of records. How does this help, and why would this mode not always be enabled?

I think the original pupose of SEGMENT heap dump is to handle the case for large heap. In the hprof format spec, the size slot of the heap dump is 32bit, which means it has limitation of dump 4GB used heap. so use segmental dump could help resolve the problem. And IMO the reason for not always enable it is because every segment has a header and tail, which may introduce extra memory, althogh it is not much.

Ok. So HPROF_HEAP_DUMP is just a record, and records have a 32-bit size limit. I assume that previously only one such record was allowed. So HPROF_HEAP_DUMP_SEGMENT was created, and the only difference between it and HPROF_HEAP_DUMP is that you can have more than one HPROF_HEAP_DUMP_SEGMENT. Am I understanding it correctly?

[linzang]

Dear Chris,

Can't you just call Oop.getObjectSize()?

Yes, I can use it, then I think there is no need to use segmental heap dump when heap used bytes is not large than 4G. so there may be lots of code change. do you think it is ok to include change in this bug fix? or I just keep the segmental heap dump codes and use the write through mode for object dump in this fix.

Ok. So HPROF_HEAP_DUMP is just a record, and records have a 32-bit size limit. I assume that previously only one such record was allowed. So HPROF_HEAP_DUMP_SEGMENT was created, and the only difference between it and HPROF_HEAP_DUMP is that you can have more than one HPROF_HEAP_DUMP_SEGMENT. Am I understanding it correctly?

Yes, I think so.

Thanks,
Lin

[linzang]

Dear @plummercj,
I am planing to rewrite the whole implementation with Oop.getObjectSize(), by which most of the object dump code could be write to underlying outputstream directly. And then there is no need to use segmental dump for gziped heap dump. And hence this issue could be fixed at all.
Do you think it is OK to include the re-write change in this PR?

BRs,
Lin

[plummercj]

If your rewrite has the side affect of fixing this issue, what I would suggest is a new CR and PR that just address the rewrite, especially since this PR has a lot of history that I think you are saying will pretty much become obsolete, and therefore is just noise to anyone wanting to review your changes. In the new PR you can note that the changes will also address 8262386, and you can include an /issue 8262386 comment so it will be closed out with new PR.

[linzang]

/integrate

[openjdk]

@linzang
Your change (at version a87793c) is now ready to be sponsored by a Committer.

[linzang]

Dear All,
May I ask your help to review this bug fix? IMHO it is better if JDK17 could have it. Thanks!
BRs,
Lin

[linzang]

Dear All,
Please note that the issue could also be fixed by a new PR #4666. IMHO, this one could be closed when the #4666 is ready for pushing.
Thanks!

Lin

[bridgekeeper]

@linzang This pull request has been inactive for more than 4 weeks and will be automatically closed if another 4 weeks passes without any activity. To avoid this, simply add a new comment to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

[sspitsyn]

It is not clear why the condition !unbufferedMode is additionally checked here and several places below. The SegmentedOutputStream constructor always sets false to theunbufferedMode field at L1344. Is it possible that segmentMode can be also unbuffered?

[linzang]

The unbufferedMode is set to true at L1498, and it is use when writing array data. The purpose is to write the data directly to the file instead of buffering them first, it can avoid memory copy and also avoid timeout when dumping large array (because the buffer must contains the whole segment before it is written to file, to avoid data pollution for compressed dump, and if the buffer is not enough, a memory copy is conducted)

[sspitsyn]

Okay, thanks.

[linzang]

Dear Serguei,
Thanks a lot for your review and comments! I have updated the PR with your suggestions, and done some basic tests on my side. (tier1, and a test for dump heap with clhsdb).

Thanks!
Lin

[sspitsyn]

Lin,
The fix looks good to me.
Thank you for your patience!
Serguei

[linzang]

Hi Serguei (@sspitsyn ),
Really thanks for your help!

Hi Chris (@plummercj ),
Would you like to review the latest change again? There are not too much changes since your approval, but I think it is better if you could help take a look.

@plummercj @sspitsyn , I will tag this PR with /integrate, and may need your help to sponsor it when it is ready. Thanks!

BRs,
Lin

[linzang]

/integrate

[openjdk]

@linzang
Your change (at version 9b614af) is now ready to be sponsored by a Committer.

[sspitsyn]

/sponsor

[openjdk]

Going to push as commit 46684a4.
Since your change was applied there have been 10 commits pushed to the master branch:

• c925c7f: 8273020: LibraryCallKit::sharpen_unsafe_type does not handle narrow oop array
• 76baace: 8273045: Fix misc javadoc bugs in the java.security and javax.net.ssl code
• b16a04e: 8271186: Add UL option to replace newline char
• d732c30: 8272863: Replace usages of Collections.sort with List.sort call in public java modules
• fe7d708: 8272473: Parsing epoch seconds at a DST transition with a non-UTC parser is wrong
• 845e1ce: 8272983: G1 Add marking details to eager reclaim logging
• c420530: 8272481: [macos] javax/swing/JFrame/NSTexturedJFrame/NSTexturedJFrame.java fails
• e43a907: 8271315: Redo: Nimbus JTree renderer properties persist across L&F changes
• 11c9fd8: 8272975: ParallelGC: add documentation to heap memory layout
• b94fd32: 8272859: Javadoc external links should only have feature version number in URL

Your commit was automatically rebased without conflicts.

[openjdk]

@sspitsyn @linzang Pushed as commit 46684a4.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.