Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

enhance support for zgc and shenandoah #261

Merged
merged 4 commits into from
Dec 13, 2022
+1,749 −409
Merged

enhance support for zgc and shenandoah #261

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
fb3b88e
fix failed parsing for ZGC
Aug 11, 2022
e5c31e1
fix failed parsing for ShenandoahGC
Aug 19, 2022
d54eae8
add percentiles in output csv file
Jul 29, 2022
e76f8a7
add "[gc,init" to LOG_ONLY_STRINGS
Aug 22, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
74 changes: 73 additions & 1 deletion src/main/java/com/tagtraum/perf/gcviewer/exp/impl/SummaryDataWriter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,9 +6,13 @@
import java.io.PrintWriter;
import java.text.NumberFormat;
import java.util.Date;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;

import com.tagtraum.perf.gcviewer.exp.AbstractDataWriter;
import com.tagtraum.perf.gcviewer.math.DoubleData;
import com.tagtraum.perf.gcviewer.math.DoubleDataPercentile;
import com.tagtraum.perf.gcviewer.model.GCModel;
import com.tagtraum.perf.gcviewer.util.FormattedValue;
import com.tagtraum.perf.gcviewer.util.MemoryFormat;
Expand Down Expand Up @@ -69,7 +73,7 @@ public SummaryDataWriter(OutputStream out, Map<String, Object> configuration) {

private void initialiseFormatters() {
pauseFormatter = NumberFormat.getInstance();
pauseFormatter.setMaximumFractionDigits(5);
pauseFormatter.setMaximumFractionDigits(6);

totalTimeFormatter = new TimeFormat();

Expand Down Expand Up @@ -227,6 +231,74 @@ private void exportPauseSummary(PrintWriter out, GCModel model) {
exportValue(out, "fullGCPausePc", percentFormatter.format(model.getFullGCPause().getSum()*100.0/model.getPause().getSum()), "%");
exportValue(out, "gcPause", gcTimeFormatter.format(model.getGCPause().getSum()), "s");
exportValue(out, "gcPausePc", percentFormatter.format(model.getGCPause().getSum()*100.0/model.getPause().getSum()), "%");

// Add extra statistical data: sum, count, min, max, average, standardDeviation, median, 75th percentile, 95, 99, 99.5, 99.9
// All Pause stats
if (pauseDataAvailable) {
exportValue(out, "pauseSum", pauseFormatter.format(model.getPause().getSum()), "s");
// exportValue(out, "pauseCount", "" + model.getPause().getN(), "-");
exportValue(out, "pauseMin", pauseFormatter.format(model.getPause().getMin()), "s");
exportValue(out, "pauseMax", pauseFormatter.format(model.getPause().getMax()), "s");
exportValue(out, "pauseAverage", pauseFormatter.format(model.getPause().average()), "s");
exportValue(out, "pauseStandardDeviation", pauseFormatter.format(model.getPause().standardDeviation()), "s");
exportValue(out, "pauseMedian", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(50)), "s");
exportValue(out, "pausePercentile75th", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(50)), "s");
exportValue(out, "pausePercentile95th", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(75)), "s");
exportValue(out, "pausePercentile99th", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(95)), "s");
exportValue(out, "pausePercentile99.5th", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(99)), "s");
exportValue(out, "pausePercentile99.9th", pauseFormatter.format(((DoubleDataPercentile)model.getPause()).getPercentile(99.9)), "s");
}
// GC Pause stats
if (gcDataAvailable) {
exportValue(out, "gcPauseSum", pauseFormatter.format(model.getGCPause().getSum()), "s");
// exportValue(out, "gcPauseCount", "" + model.getGCPause().getN(), "-");
exportValue(out, "gcPauseMin", pauseFormatter.format(model.getGCPause().getMin()), "s");
exportValue(out, "gcPauseMax", pauseFormatter.format(model.getGCPause().getMax()), "s");
exportValue(out, "gcPauseAverage", pauseFormatter.format(model.getGCPause().average()), "s");
exportValue(out, "gcPauseStandardDeviation", pauseFormatter.format(model.getGCPause().standardDeviation()), "s");
exportValue(out, "gcPauseMedian", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(50)), "s");
exportValue(out, "gcPausePercentile75th", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(50)), "s");
exportValue(out, "gcPausePercentile95th", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(75)), "s");
exportValue(out, "gcPausePercentile99th", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(95)), "s");
exportValue(out, "gcPausePercentile99.5th", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(99)), "s");
exportValue(out, "gcPausePercentile99.9th", pauseFormatter.format(((DoubleDataPercentile)model.getGCPause()).getPercentile(99.9)), "s");
}
// Full GC Pause stats
if (fullGCDataAvailable) {
exportValue(out, "fullGCPauseSum", pauseFormatter.format(model.getFullGCPause().getSum()), "s");
// exportValue(out, "fullGCPauseCount", "" + model.getFullGCPause().getN(), "-");
exportValue(out, "fullGCPauseMin", pauseFormatter.format(model.getFullGCPause().getMin()), "s");
exportValue(out, "fullGCPauseMax", pauseFormatter.format(model.getFullGCPause().getMax()), "s");
exportValue(out, "fullGCPauseAverage", pauseFormatter.format(model.getFullGCPause().average()), "s");
exportValue(out, "fullGCPauseStandardDeviation", pauseFormatter.format(model.getFullGCPause().standardDeviation()), "s");
exportValue(out, "fullGCPauseMedian", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(50)), "s");
exportValue(out, "fullGCPausePercentile75th", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(50)), "s");
exportValue(out, "fullGCPausePercentile95th", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(75)), "s");
exportValue(out, "fullGCPausePercentile99th", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(95)), "s");
exportValue(out, "fullGCPausePercentile99.5th", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(99)), "s");
exportValue(out, "fullGCPausePercentile99.9th", pauseFormatter.format(((DoubleDataPercentile)model.getFullGCPause()).getPercentile(99.9)), "s");
}
// ZGC stats: [gc,phases]
if (model.size() > 1 && model.getGcEventPhases().size() > 0) {
DoubleData gcPhases = new DoubleDataPercentile();
for (Entry<String, DoubleData> entry : model.getGcEventPhases().entrySet()) {
List<Double> phaseList = ((DoubleDataPercentile)entry.getValue()).getDoubleData();
for (Double d : phaseList)
gcPhases.add(d);
}
exportValue(out, "gcPhaseSum", pauseFormatter.format(gcPhases.getSum()), "s");
exportValue(out, "gcPhaseCount", "" + gcPhases.getN(), "-");
exportValue(out, "gcPhaseMin", pauseFormatter.format(gcPhases.getMin()), "s");
exportValue(out, "gcPhaseMax", pauseFormatter.format(gcPhases.getMax()), "s");
exportValue(out, "gcPhaseAverage", pauseFormatter.format(gcPhases.average()), "s");
exportValue(out, "gcPhaseStandardDeviation", pauseFormatter.format(gcPhases.standardDeviation()), "s");
exportValue(out, "gcPhaseMedian", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(50)), "s");
exportValue(out, "gcPhasePercentile75th", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(50)), "s");
exportValue(out, "gcPhasePercentile95th", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(75)), "s");
exportValue(out, "gcPhasePercentile99th", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(95)), "s");
exportValue(out, "gcPhasePercentile99.5th", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(99)), "s");
exportValue(out, "gcPhasePercentile99.9th", pauseFormatter.format(((DoubleDataPercentile)gcPhases).getPercentile(99.9)), "s");
}
}

private boolean isSignificant(final double average, final double standardDeviation) {
Expand Down
37 changes: 33 additions & 4 deletions src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,7 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
EXCLUDE_STRINGS_LINE_START.add("/proc/meminfo"); // apple vms seem to print this out in the beginning of the logs
EXCLUDE_STRINGS_LINE_START.add("Uncommitted"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Cancelling concurrent GC"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Cancelling GC"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Capacity"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
EXCLUDE_STRINGS_LINE_START.add("Periodic GC triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
EXCLUDE_STRINGS_LINE_START.add("Immediate Garbage"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
Expand All @@ -126,7 +127,6 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
EXCLUDE_STRINGS_LINE_START.add("Concurrent marking triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
EXCLUDE_STRINGS_LINE_START.add("Adjusting free threshold"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Predicted cset threshold"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Trigger"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Free"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Evacuation Reserve"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add("Pacer for "); // -XX:+UseShenandoahGC
Expand All @@ -135,6 +135,9 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
EXCLUDE_STRINGS_LINE_START.add(" Adaptive CSet Selection"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add(" Collectable Garbage"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add(" Immediate Garbage"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add(" Good progress for"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add(" Failed to"); // -XX:+UseShenandoahGC
EXCLUDE_STRINGS_LINE_START.add(" Cancelling GC"); // -XX:+UseShenandoahGC

EXCLUDE_STRINGS_LINE_CONTAIN.add(LOGFILE_ROLLING_BEGIN);
EXCLUDE_STRINGS_LINE_CONTAIN.add(LOGFILE_ROLLING_END);
Expand All @@ -155,6 +158,8 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
LOG_INFORMATION_STRINGS.add("Reference processing"); // -XX:+UseShenandoahGC
LOG_INFORMATION_STRINGS.add("Heuristics ergonomically sets"); // -XX:+UseShenandoahGC
LOG_INFORMATION_STRINGS.add("Initialize Shenandoah heap"); // -XX:+UseShenandoahGC
LOG_INFORMATION_STRINGS.add("Shenandoah GC mode"); // -XX:+UseShenandoahGC
LOG_INFORMATION_STRINGS.add("Soft Max Heap Size"); // -XX:+UseShenandoahGC
}

private static final String EVENT_YG_OCCUPANCY = "YG occupancy";
Expand Down Expand Up @@ -253,6 +258,8 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
private static final String SHENANDOAH_DETAILS_FINAL_MARK_SPLIT_START = "Total";

private static final String SHENANDOAH_INTRODUCTION_TO_GC_STATISTICS = "Shenandoah Heap";
private static final String SHENANDOAH_GC_CYCLE_DETAILS_START = "All times are wall-clock times";
private static final String SHENANDOAH_GC_CYCLE_START = "Trigger: ";

// -XX:+PrintReferenceGC
private static final String PRINT_REFERENCE_GC_INDICATOR = "Reference";
Expand Down Expand Up @@ -309,9 +316,17 @@ else if (startsWith(line, LOG_INFORMATION_STRINGS, false)) {
continue;
} else if (line.startsWith(SHENANDOAH_INTRODUCTION_TO_GC_STATISTICS)) {
// Assumption: As soon as the shenandoah gc statistics block starts, the vm is shutting down
skipAndLogToEndOfFile(in);
skipAndLogToEndOfFile(in, line);
continue;
} else if (line.startsWith(SHENANDOAH_GC_CYCLE_START)) {
// skip the start string of the first gc cycle
continue;
} else if (line.startsWith(SHENANDOAH_GC_CYCLE_DETAILS_START)) {
// ignore details of each gc cycle
skipGcCycleDetails(in);
continue;
}

if (line.indexOf(CMS_ABORT_PRECLEAN) >= 0) {
// line contains like " CMS: abort preclean due to time "
// -> remove the text
Expand Down Expand Up @@ -485,13 +500,27 @@ else if (beginningOfLine.size() > 0) {
}
}

private void skipAndLogToEndOfFile(LineNumberReader in) throws IOException {
String line;
private void skipAndLogToEndOfFile(LineNumberReader in, String line) throws IOException {
getLogger().info(line);
while ((line = in.readLine()) != null) {
getLogger().info(line);
}
}

private void skipGcCycleDetails(LineNumberReader in) throws IOException {
String line;
while ((line = in.readLine()) != null) {
// parse the events for the next GC cycle
if (line.startsWith(SHENANDOAH_GC_CYCLE_START)) {
break;
}
// the vm is shutting down
if (line.startsWith(SHENANDOAH_INTRODUCTION_TO_GC_STATISTICS)) {
skipAndLogToEndOfFile(in, line);
}
}
}

private boolean isPrintHeapAtGcStarting(String line) {
return line.startsWith(HEAP) // jdk 6 and before
|| line.indexOf(HEAP_SIZING_BEFORE) >= 0 // jdk 7 and after
Expand Down
2 changes: 1 addition & 1 deletion src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderTools.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -69,7 +69,7 @@ public ExtendedType parseType(String typeString) throws UnknownGcTypeException {
}

/**
* Same as @{link {@link #parseType(String)}}, but returns <code>null</code> instead of exception, if no type could
* Same as {@link #parseType(String)}, but returns <code>null</code> instead of exception, if no type could
* be found.
*
* @param typeName string representation of the gc event
Expand Down
Loading