8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total #3087

jyukutyo · 2021-03-19T11:49:39Z

When a heap is used more than about 2.1GB, clhsdb jhisto shows a negative number in the total field.

$ java -Xmx20g Sample

$ jhsdb clhsdb --pid 5773
Attaching to process 5773, please wait...
hsdb> jhisto
...
299:            1       16      jdk.internal.misc.Unsafe
300:            3402    10737610256     byte[]
Total :         15823   -2146661280
Heap traversal took 1.793 seconds.

(Incidentally, the Sample is a program that only allocates many objects.)

Details

This is because in ObjectHistogram class the totalSize variable is int type.

The total size is the total of ObjectHistogramElement#getSize() and getSize() returns long. So I changed int to long in the ObjectHistogram class.

Additionally, I changed the type of the totalCount. This doesn't cause a bug, but ObjectHistogramElement#getCount() also returns long. So it doesn't need to treat it as int, I think. ObjectHistogramElement#compare() also do the same thing, so a class that is a huge size show the bottom of the list.

Tests

The jtreg test was successful.

$ sudo make run-test TEST=serviceability/sa/ClhsdbJhisto.java

$ cat build/linux-x86_64-server-fastdebug/test-results/jtreg_test_hotspot_jtreg_serviceability_sa_ClhsdbJhisto_java/text/summary.txt
serviceability/sa/ClhsdbJhisto.java  Passed. Execution successful

I confirmed the output with the same program.

$ ./jdk/build/linux-x86_64-server-fastdebug/jdk/bin/java -Xmx20g Sample
$ ./jdk/build/linux-x86_64-server-fastdebug/jdk/bin/jhsdb clhsdb --pid 10196
Attaching to process 10196, please wait...
hsdb> jhisto
Object Histogram:

num       #instances    #bytes  Class description
--------------------------------------------------------------------------
1:              3405    13958838400     byte[]
2:              887     109032  java.lang.Class
...
300:            1       16      jdk.internal.misc.Unsafe
Total :         15827   13959470288
Heap traversal took 1.72 seconds.

Progress

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

Issue

JDK-8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total

Reviewers

Chris Plummer (@plummercj - Reviewer) ⚠️ Review applies to 248d49f
Kevin Walls (@kevinjwalls - Committer) ⚠️ Review applies to a9447ca
@mgkwill (no known github.com user name / role) ⚠️ Review applies to 248d49f
Yasumasa Suenaga (@YaSuenag - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 3087

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

Using diff file

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

bridgekeeper · 2021-03-19T11:50:01Z

👋 Welcome back ksakata! 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 · 2021-03-19T11:51:51Z

@jyukutyo The following labels will be automatically applied to this pull request:

hotspot-gc
serviceability

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

mlbridge · 2021-03-19T12:11:52Z

Webrevs

plummercj

I see another cast-to-int related bug, and it's visible in your jhisto output (both before and after):

304: 1 16 jdk.internal.perf.Perf
305: 1 16 java.util.jar.JavaUtilJarAccessImpl
306: 254 2863336944 int[]
Total : 22803 -1430650672

The large int[] array should be at the top of the list, not the bottom. The issue is in ObjectHistogramElement.java:

  public int compare(ObjectHistogramElement other) {
    return (int) (other.size - size);
  }

So this will result in the returned value having the wrong sign if the difference between other.size and size is too large. In ObjectHistogram.java, just above the code you fixed, we have:

  public List<ObjectHistogramElement> getElements() {
    List<ObjectHistogramElement> list = new ArrayList<>();
    list.addAll(map.values());
    Collections.sort(list, new Comparator<>() {
      public int compare(ObjectHistogramElement o1, ObjectHistogramElement o2) {
        return o1.compare(o2);
      }
    });
    return list;
  }

So it looks like this is calling the buggy compare() method. I think the fix is to have compare() return -1, 0, or 1 depending on the long value of (other.size - size), rather than just trying to return (other.size - size).

jyukutyo · 2021-03-23T14:06:39Z

@plummercj That is right! I fixed that bug and pasted the latest output of jhisto to the body. Of course I re-ran the jtreg test.

plummercj

The copyright needs updating in ObjectHistogramElement.java. Otherwise the changes look good.

openjdk · 2021-03-23T21:08:28Z

@jyukutyo This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total

Reviewed-by: cjplummer, kevinw, ysuenaga

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 289 new commits pushed to the master branch:

de495df: 8264413: Data is written to file header even if its CRC32 was calculated
52d8a22: 8264054: Bad XMM performance on java.lang.MathBench.sqrtDouble
16acfaf: 8012229: [lcms] Improve performance of color conversion for images with alpha channel
cb70ab0: 8263235: sanity/client/SwingSet/src/ColorChooserDemoTest.java failed throwing java.lang.NoClassDefFoundError
e2ec997: 8263551: Provide shared lock-free FIFO queue implementation
dec3447: 8264346: nullptr_t undefined in global namespace for clang+libstdc++
0fa3572: 8264489: Add more logging to LargeCopyWithMark.java
f43d14a: 8264396: Use the blessed modifier order in jdk.internal.jvmstat
6225ae6: 8264466: Cut-paste error in InterfaceCalls JMH
40c3249: 8264149: BreakpointInfo::set allocates metaspace object in VM thread
... and 279 more: https://git.openjdk.java.net/jdk/compare/8afec70c283ee549795996031e3a53a3212bf35a...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

As you do not have Committer status in this project an existing Committer must agree to sponsor your change. Possible candidates are the reviewers of this PR (@plummercj, @kevinjwalls, @YaSuenag) but any other Committer may sponsor as well.

➡️ To flag this PR as ready for integration with the above commit message, type /integrate in a new comment. (Afterwards, your sponsor types /sponsor in a new comment to perform the integration).

jyukutyo · 2021-03-26T13:57:00Z

I just updated the copyright.

jyukutyo · 2021-03-26T13:57:30Z

/integrate

openjdk · 2021-03-26T13:58:03Z

@jyukutyo
Your change (at version 4d3b6f8) is now ready to be sponsored by a Committer.

jyukutyo · 2021-04-01T02:30:50Z

Could someone sponsor this pull request? It is ready.

YaSuenag

Looks good. I will sponsor you.

YaSuenag · 2021-04-01T04:09:28Z

/sponsor

openjdk · 2021-04-01T04:10:38Z

@YaSuenag @jyukutyo Since your change was applied there have been 289 commits pushed to the master branch:

de495df: 8264413: Data is written to file header even if its CRC32 was calculated
52d8a22: 8264054: Bad XMM performance on java.lang.MathBench.sqrtDouble
16acfaf: 8012229: [lcms] Improve performance of color conversion for images with alpha channel
cb70ab0: 8263235: sanity/client/SwingSet/src/ColorChooserDemoTest.java failed throwing java.lang.NoClassDefFoundError
e2ec997: 8263551: Provide shared lock-free FIFO queue implementation
dec3447: 8264346: nullptr_t undefined in global namespace for clang+libstdc++
0fa3572: 8264489: Add more logging to LargeCopyWithMark.java
f43d14a: 8264396: Use the blessed modifier order in jdk.internal.jvmstat
6225ae6: 8264466: Cut-paste error in InterfaceCalls JMH
40c3249: 8264149: BreakpointInfo::set allocates metaspace object in VM thread
... and 279 more: https://git.openjdk.java.net/jdk/compare/8afec70c283ee549795996031e3a53a3212bf35a...master

Your commit was automatically rebased without conflicts.

Pushed as commit 39f0b27.

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

jyukutyo added 2 commits March 15, 2021 18:22

Output proper total size when using huge heap

e413b61

Use long instead of int

a9447ca

openjdk bot added serviceability serviceability-dev@openjdk.org hotspot-gc hotspot-gc-dev@openjdk.org labels Mar 19, 2021

jyukutyo marked this pull request as ready for review March 19, 2021 12:07

openjdk bot added the rfr Pull request is ready for review label Mar 19, 2021

plummercj reviewed Mar 19, 2021

View reviewed changes

kevinjwalls approved these changes Mar 22, 2021

View reviewed changes

Fix the sort bug for huge bytes in jhisto

248d49f

plummercj approved these changes Mar 23, 2021

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Mar 23, 2021

mgkwill approved these changes Mar 24, 2021

View reviewed changes

Update copyright

4d3b6f8

openjdk bot added the sponsor Pull request is ready to be sponsored label Mar 26, 2021

YaSuenag approved these changes Apr 1, 2021

View reviewed changes

openjdk bot closed this Apr 1, 2021

openjdk bot added integrated Pull request has been integrated and removed sponsor Pull request is ready to be sponsored ready Pull request is ready to be integrated rfr Pull request is ready for review labels Apr 1, 2021

jyukutyo deleted the JDK-8176026_jhisto_negative_total branch June 15, 2022 09:27

8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total #3087

8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total #3087

jyukutyo commented Mar 19, 2021 •

edited by openjdk bot

bridgekeeper bot commented Mar 19, 2021

openjdk bot commented Mar 19, 2021

mlbridge bot commented Mar 19, 2021 •

edited

plummercj left a comment •

edited

jyukutyo commented Mar 23, 2021

plummercj left a comment

openjdk bot commented Mar 23, 2021 •

edited

jyukutyo commented Mar 26, 2021

jyukutyo commented Mar 26, 2021

openjdk bot commented Mar 26, 2021

jyukutyo commented Apr 1, 2021

YaSuenag left a comment

YaSuenag commented Apr 1, 2021

openjdk bot commented Apr 1, 2021

8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total #3087

8176026: SA: Huge heap sizes cause a negative value to be displayed in the jhisto heap total #3087

Conversation

jyukutyo commented Mar 19, 2021 • edited by openjdk bot

Details

Tests

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Mar 19, 2021

openjdk bot commented Mar 19, 2021

mlbridge bot commented Mar 19, 2021 • edited

Webrevs

plummercj left a comment • edited

Choose a reason for hiding this comment

jyukutyo commented Mar 23, 2021

plummercj left a comment

Choose a reason for hiding this comment

openjdk bot commented Mar 23, 2021 • edited

jyukutyo commented Mar 26, 2021

jyukutyo commented Mar 26, 2021

openjdk bot commented Mar 26, 2021

jyukutyo commented Apr 1, 2021

YaSuenag left a comment

Choose a reason for hiding this comment

YaSuenag commented Apr 1, 2021

openjdk bot commented Apr 1, 2021

jyukutyo commented Mar 19, 2021 •

edited by openjdk bot

mlbridge bot commented Mar 19, 2021 •

edited

plummercj left a comment •

edited

openjdk bot commented Mar 23, 2021 •

edited