8300742: jstat's CGCT is 5 percent higher than the pause time in -Xlog:gc.

[yukikimmura]

Could anyone review the fix please?
I explain the fix below.
I tested hotspot/gc with rhel and windows x86_64, and no errors found.
I added a test to confirm the fix. There is no risk.

GC time in the gclog is calculated in the GCTraceTime constructor,
and jstat's CGCT is calculated in the TraceCollectorStats constructor.

In my investigation, the cost of the GCTraceTime constructor is larger than that of TraceCollectorStats.
CGCT includes the executing time of GCTraceTime.
Since CGCT is the accmulated time, as the number of CMSGC increases, the difference with the gclog increases.

Only CMSGC, execution order of GCTraceTime and TraceCollectorStats is different from other GCs.

concurrentMarkSweepGeneration.cpp
TraceCollectorStats
GCTraceTime

g1CollectedHeap.cpp / vm_operations_g1.cpp / psParallelCompact.cpp / genCollectedHeap.cpp
GCTraceTime
TraceCollectorStats

I modified the order of two constructors in concurrentMarkSweepGeneration.cpp.
The following is the result. The difference between two timers bcomes small.
The difference of time a GC should be small, because CGCT is the accmulated time.
The order of two timers should be same for all GCs.
Naturally, the GC time in the gclog will increase slightly which is several micro secs in Xmx512m, 2.5GHz CPU.

Windows 2016 / x64

befor modification
jstat CGT 6011
jstat CGCT 8593.0 ms
gclog invocations 6011
gclog time 8136.4 ms

jstat/loggc=1.056 (the difference is 5.6%)

after modification
jstat CGT 6104
jstat CGCT 7503.0 ms
gclog invocations 6104
gclog time 7603.5 ms

jstat/loggc=0.987 (the difference is 1.3%)

RHEL 7 / x64

befor modification
jstat CGT 4576
jstat CGCT 5010.0ms
gclog invocations 4576
gclog time 4871.4 ms

jstat/loggc=1.028 (the difference is 2.8%)

after modification
jstat CG 4297
jstat CGCT 3408.0ms
gclog invocations 4297
gclog time 3416.95 ms

jstat/loggc=0.997 (the difference is 0.3%)

---

Progress

• Change must be properly reviewed (1 review required, with at least 1 Reviewer)
• Change must not contain extraneous whitespace
• Commit message must refer to an issue

Issue

• JDK-8300742: jstat's CGCT is 5 percent higher than the pause time in -Xlog:gc.

Reviewers

• Richard Reingruber (@reinrich - Reviewer) ⚠️ Review applies to c1f78569

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk11u-dev pull/1676/head:pull/1676
$ git checkout pull/1676

Update a local copy of the PR:
$ git checkout pull/1676
$ git pull https://git.openjdk.org/jdk11u-dev pull/1676/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 1676

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

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk11u-dev/pull/1676.diff

[bridgekeeper]

👋 Welcome back yukikimmura! 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.

[mlbridge]

Webrevs

• 02: Full - Incremental (3e450760)
• 01: Full - Incremental (c1f78569)
• 00: Full (3311e6a4)

[reinrich]

Hi Kimura,

cms changes seem ok.
I'm not sure though if the test is necessary (and worth the CO2). What are the runtimes you are seeing?

Thanks, Richard.

[yukikimmura]

Hello Richard,
Thank you for your review.

The test is to make sure the difference of elapsed time between the two timers. It might be a flaky test.
I think it should not be included in the jtreg test set, once the effect of the fix has been confirmed.
I removed the test from the commit.

Thanks,
Kimura Yukihiro

[reinrich]

Looks good to me.

Thanks, Richard.

[openjdk]

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

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

8300742: jstat's CGCT is 5 percent higher than the pause time in -Xlog:gc.

Reviewed-by: rrich

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 2 new commits pushed to the master branch:

• fc4b9de: 8218431: Improved platform checking in makefiles
• 6ffd006: 8241806: The sun/awt/shell/FileSystemViewMemoryLeak.java is unstable

Please see this link for an up-to-date comparison between the source branch of this pull request and the master branch.
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 (@reinrich) 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).

[reinrich]

Hi @yukikimmura ,
I think you can now add the jdk11u-fix-request label to the JBS item https://bugs.openjdk.org/browse/JDK-8300742.

[yukikimmura]

Hello Richard,
Thank you for your advice.
I added the jdk11u-fix-request label to the JBS.

Thanks,
Kimura Yukihiro

[reinrich]

You're welcome. This would be a general guide: https://wiki.openjdk.org/display/JDKUpdates/How+to+contribute+or+backport+a+fix
Its only partially applicable to your fix though since it isn't a backport.

[yukikimmura]

/integrate

[openjdk]

@yukikimmura
Your change (at version 3e45076) is now ready to be sponsored by a Committer.

[reinrich]

/sponsor

[openjdk]

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

• fc4b9de: 8218431: Improved platform checking in makefiles
• 6ffd006: 8241806: The sun/awt/shell/FileSystemViewMemoryLeak.java is unstable

Your commit was automatically rebased without conflicts.

[openjdk]

@reinrich @yukikimmura Pushed as commit ebac392.

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