Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Add support for ZGC logging #216

Merged
merged 34 commits into from
Jun 10, 2019
Merged

Conversation

yanqilee
Copy link
Contributor

Added ZGC GC log in unified JVM logging format to GCViewer. Currently parsing all 3 STW pause events as well as all 7 concurrency events. These info are listed in [gc,phases] so we had to include that for parsing in ZGC. Memory info are displayed separately, the pre and post used heap sizes are only displayed every GC cycle, not at every pause. For total heap, we parsed the capacity block in [gc,heap]. Currently we are only parsing the capacity block, but there are information in the [gc,heap] section that could be useful in future improvements.

I had to add a line in the pom file on javadoc plugin because travis build is failing, it has recently started running JDK 11.0.2 (only that version fails, 11.0.1 works fine)
Also did some refactoring around the classes I have touched.

@codecov-io
Copy link

codecov-io commented Jan 22, 2019

Codecov Report

Merging #216 into develop will increase coverage by 0.23%.
The diff coverage is 92.67%.

Impacted file tree graph

@@              Coverage Diff              @@
##             develop     #216      +/-   ##
=============================================
+ Coverage      69.94%   70.18%   +0.23%     
- Complexity      1479     1512      +33     
=============================================
  Files            145      145              
  Lines           8396     8500     +104     
  Branches        1374     1385      +11     
=============================================
+ Hits            5873     5966      +93     
- Misses          1948     1953       +5     
- Partials         575      581       +6
Impacted Files Coverage Δ Complexity Δ
...a/com/tagtraum/perf/gcviewer/model/GCEventUJL.java 77.77% <100%> (+17.77%) 6 <2> (+2) ⬆️
...om/tagtraum/perf/gcviewer/imp/DataReaderTools.java 88.88% <100%> (ø) 15 <0> (ø) ⬇️
.../tagtraum/perf/gcviewer/model/AbstractGCEvent.java 85.11% <100%> (+1.02%) 74 <5> (+5) ⬆️
...perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java 80.73% <85.29%> (+0.26%) 62 <14> (+15) ⬆️
...tagtraum/perf/gcviewer/view/ModelDetailsPanel.java 94.59% <85.71%> (-0.35%) 5 <0> (+1)
...java/com/tagtraum/perf/gcviewer/model/GCModel.java 86.58% <96.34%> (+0.72%) 139 <21> (+9) ⬆️
...va/com/tagtraum/perf/gcviewer/view/GCDocument.java 33.97% <0%> (-0.97%) 23% <0%> (ø)
...agtraum/perf/gcviewer/model/ConcurrentGCEvent.java 48.71% <0%> (+5.12%) 9% <0%> (+1%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 99ceac8...4793b3d. Read the comment docs.

Copy link
Contributor

@Marysunithajoseph Marysunithajoseph left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will do one more sweep to check and see if we've added something ZGC specific

Copy link
Contributor

@Marysunithajoseph Marysunithajoseph left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM!

@yanqilee
Copy link
Contributor Author

Tried a couple things on a different branch, seems like the code need a major refactor to pass the Better Code Hub check.

@chewiebug please look at the PR when you have a chance and let me know of any concerns. Thanks!

Copy link
Owner

@chewiebug chewiebug left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In general: Thank you very much for the pull request! I looks quite good already! Don't bother too much about the failing "Better Code Hub" check. I am not sure, if those checks are really a good match for GCViewer. I like the concept, but it might be too much for a grown code base like GCViewer to introduce at this stage.

I'll currently set the status to "request changes". My main concern is to understand to right model. For that, please see my comment / questions in the issue. After these questions have good answers, the necessary changes in the code will be more clear.



/** Pattern - for ZGC phases - that are to be included for parsing */
private static final Pattern PATTERN_INCLUDE_STRINGS_PHASE = Pattern.compile("\\[(gc,phases[ ]*)][ ]GC\\(([0-9]+)\\)[ ](?<type>[-a-zA-Z1 ()]+)(([ ]([0-9]{1}.*))|$)");
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could this pattern not be made part of the INCLUDE_STRINGS and later, the "gc,phases" lines could be treated as AbstractGCEvent.GcPattern.GC_PAUSE? Looking at the included sample log, I am not sure, if this needs a new regex.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See my comments below on parsing gc,phases.
It is a solution to the problem but personally I don't like having something this ZGC specific in there. Any suggestions to improve this?

@@ -140,7 +174,7 @@ public GCModel read() throws IOException {
getLogger().info("Reading Oracle / OpenJDK unified jvm logging format...");

try {
// some information shared accross several lines of parsing...
// some information shared across several lines of parsing...
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks :-)!

@@ -185,46 +218,84 @@ private ParseContext parseEvent(ParseContext context) {
AbstractGCEvent<?> returnEvent = event;
switch (tags) {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

looks nice to have this switch shortened and the code moved to separate methods!

@@ -401,6 +513,17 @@ private boolean lineContainsParseableEvent(ParseContext context) {
return false;
}

private boolean isParseablePhaseEvent(String line) {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are there also "gc,phases" events, that are not parseable?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So what was happening is that [gc,phases] events were not included at all previously, when I added [gc,phases] to INCLUDE_STRINGS, it broke many existing test cases because there are [gc,phases] lines in the test files that were ignored and the test cases asserts 0 warnings. When those lines got included, the assertions failed. So this is a solution to only include ZGC [gc,phases] to not break the build and/or affect existing functionalities.

@@ -38,6 +38,10 @@
private DoubleDataMapModel concurrentGcEventModel;

private DoubleDataMapTable vmOperationTable;

/** GC Causes Model and table */
private DoubleDataMapModel gcCausesModel;
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please see my comment in the issue. I don't understand the concept of the "causes", yet and am not sure, if this is the right way to go.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have commented on the issue, will likely scrap causes section all together, please let me know what you think.

@@ -24,6 +24,10 @@
private int preUsed;
/** Used after GC in KB */
private int postUsed;
/** Percentage used before GC */
private int preUsedPercent;
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is it really worthwhile to store this information? Can't it be calculated, if needed?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are right, I don't think it's worthwhile to have this, I will remove this.

Matcher parenMatcher = parenthesesPattern.matcher(lookupTypeName);
if (parenMatcher.find()) {
gcType = AbstractGCEvent.Type.lookup(parenMatcher.replaceFirst(""));
// try to parse it again with the parents removed
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is "parents" an established abbrevation for "parenthesis"? If not, I'd prefer the renaming to go to "parenthesisMatcher" to avoid confusion.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch! I think we got confused too while renaming this, will fix this.

remove(gcCausesTable);
}
else {
gcCausesModel.setModel(model.getGcEventCauses(), totalPause, false);
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since, currently, there is no pause time in the causes, this line might cause the weird numbers. But first, let's clarify on the right model (see my comment in the issue).

@@ -327,6 +327,7 @@
<links>
<link>http://docs.oracle.com/javase/8/docs/api/</link>
</links>
<source>${jdk.source.version}</source>
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, this fixes the build failure on the develop branch - thank you very much!

@yanqilee
Copy link
Contributor Author

yanqilee commented Mar 4, 2019

Hi @chewiebug,

I have made the suggested changes, please have a look.
Attached are the screenshots for the various panels after parsing ZGC log.

image
image
image

@chewiebug
Copy link
Owner

chewiebug commented Mar 5, 2019 via email

@yanqilee
Copy link
Contributor Author

yanqilee commented Mar 5, 2019

Thanks @chewiebug!

Looking forward to your comments.

@chewiebug
Copy link
Owner

chewiebug commented Mar 18, 2019 via email

@chewiebug chewiebug merged commit 4793b3d into chewiebug:develop Jun 10, 2019
chewiebug added a commit that referenced this pull request Jun 10, 2019
chewiebug added a commit that referenced this pull request Jun 10, 2019
@chewiebug
Copy link
Owner

Hi @yanqilee

I have finally merged your pull request after adding support for parsing phase events for the other gc algorithms. Thanks again for your contribution! By the way: I have added your name to the list of contributors (see in the "AboutDialog": Help -> About GCViewer).

Best regards,
Jörg

@yanqilee
Copy link
Contributor Author

Woohoo! Awesome! Thanks @chewiebug!
Please do also add @Marysunithajoseph to the list of contributors as she helped with the development of this feature.

Cheers,
Yanqi

@chewiebug
Copy link
Owner

chewiebug commented Jun 11, 2019 via email

@Marysunithajoseph
Copy link
Contributor

@chewiebug @yanqilee Thank you, it was great to have worked on this!

sparrowzoo pushed a commit to sparrowzoo/GCViewer that referenced this pull request Dec 28, 2020
sparrowzoo pushed a commit to sparrowzoo/GCViewer that referenced this pull request Dec 28, 2020
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants