From 2662651414011ff7cbc332b84fad15797808b5d2 Mon Sep 17 00:00:00 2001 From: mmillson Date: Thu, 13 Dec 2018 17:13:37 -0500 Subject: [PATCH] Initial unified G1 details parsing + bug fixes. --- .../java/org/eclipselabs/garbagecat/Main.java | 5 +- .../garbagecat/domain/TimesData.java | 25 +- .../domain/jdk/CmsConcurrentEvent.java | 1 - .../domain/jdk/unified/FooterHeapEvent.java | 122 ++++++++ .../domain/jdk/unified/HeapAddressEvent.java | 94 ++++++ .../jdk/unified/HeapRegionSizeEvent.java | 94 ++++++ .../jdk/unified/UnifiedG1CleanupEvent.java | 224 +++++++++++++ .../jdk/unified/UnifiedG1ConcurrentEvent.java | 129 +++++--- .../jdk/unified/UnifiedG1YoungPauseEvent.java | 248 +++++++++++++++ .../jdk/unified/UnifiedRemarkEvent.java | 81 ++++- .../domain/jdk/unified/UnifiedYoungEvent.java | 26 +- .../unified/UnifiedG1PreprocessAction.java | 295 ++++++++++++++++++ .../garbagecat/service/GcManager.java | 58 ++-- .../garbagecat/util/jdk/JdkRegEx.java | 4 +- .../garbagecat/util/jdk/JdkUtil.java | 91 ++++-- src/test/data/.gitignore | 3 + src/test/data/dataset155.txt | 13 + src/test/data/dataset156.txt | 4 + src/test/data/dataset157.txt | 3 + .../jdk/unified/TestCmsInitialMarkEvent.java | 43 ++- .../jdk/unified/TestFooterHeapEvent.java | 92 ++++++ .../jdk/unified/TestHeapAddressEvent.java | 69 ++++ .../jdk/unified/TestHeapRegionSizeEvent.java | 65 ++++ .../TestUnifiedCmsConcurrentEvent.java | 49 ++- .../unified/TestUnifiedG1CleanupEvent.java | 97 ++++++ .../unified/TestUnifiedG1ConcurrentEvent.java | 148 +++++++-- .../unified/TestUnifiedG1YoungPauseEvent.java | 144 +++++++++ .../jdk/unified/TestUnifiedOldEvent.java | 34 +- .../jdk/unified/TestUnifiedRemarkEvent.java | 49 ++- .../jdk/unified/TestUnifiedYoungEvent.java | 72 ++--- .../domain/jdk/unified/TestUsingCmsEvent.java | 34 +- .../domain/jdk/unified/TestUsingG1Event.java | 34 +- .../jdk/unified/TestUsingParallelEvent.java | 34 +- .../jdk/unified/TestUsingSerialEvent.java | 34 +- .../TestUnifiedG1PreprocessAction.java | 263 ++++++++++++++++ .../garbagecat/util/jdk/TestJdkMath.java | 8 + .../garbagecat/util/jdk/TestJdkRegEx.java | 23 +- src/test/scripts/garbage-maker-jdk11.sh | 20 +- src/test/scripts/garbage-maker-jdk8.sh | 26 +- 39 files changed, 2576 insertions(+), 282 deletions(-) create mode 100644 src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/FooterHeapEvent.java create mode 100644 src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapAddressEvent.java create mode 100644 src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapRegionSizeEvent.java create mode 100644 src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1CleanupEvent.java create mode 100644 src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1YoungPauseEvent.java create mode 100644 src/main/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/UnifiedG1PreprocessAction.java create mode 100644 src/test/data/dataset155.txt create mode 100644 src/test/data/dataset156.txt create mode 100644 src/test/data/dataset157.txt create mode 100644 src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestFooterHeapEvent.java create mode 100644 src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapAddressEvent.java create mode 100644 src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapRegionSizeEvent.java create mode 100644 src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1CleanupEvent.java create mode 100644 src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1YoungPauseEvent.java create mode 100644 src/test/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/TestUnifiedG1PreprocessAction.java diff --git a/src/main/java/org/eclipselabs/garbagecat/Main.java b/src/main/java/org/eclipselabs/garbagecat/Main.java index 31ca49a8..e3a012ac 100644 --- a/src/main/java/org/eclipselabs/garbagecat/Main.java +++ b/src/main/java/org/eclipselabs/garbagecat/Main.java @@ -354,8 +354,9 @@ public static void createReport(JvmRun jvmRun, String reportFileName, boolean ve } } bufferedWriter.write(Constants.LINE_SEPARATOR); - // Inverted parallelism. Only report if we have Serial/Parallel/CMS/G1 events. - if (jvmRun.getCollectorFamilies() != null && jvmRun.getCollectorFamilies().size() > 0) { + // Inverted parallelism. Only report if we have Serial/Parallel/CMS/G1 events with times data. + if (jvmRun.getCollectorFamilies() != null && jvmRun.getCollectorFamilies().size() > 0 + && jvmRun.getParallelCount() > 0) { bufferedWriter.write("# Parallel Events: " + jvmRun.getParallelCount() + Constants.LINE_SEPARATOR); bufferedWriter.write("# Inverted Parallelism: " + jvmRun.getInvertedParallelismCount() + Constants.LINE_SEPARATOR); diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/TimesData.java b/src/main/java/org/eclipselabs/garbagecat/domain/TimesData.java index ad5c6bda..8abf38d3 100644 --- a/src/main/java/org/eclipselabs/garbagecat/domain/TimesData.java +++ b/src/main/java/org/eclipselabs/garbagecat/domain/TimesData.java @@ -18,9 +18,21 @@ *

Example Logging

* *

+ * JDK8 and prior: + *

+ * + * 
  * [Times: user=0.31 sys=0.00, real=0.04 secs]
+ *
+ * + *

+ * JDK9+: *

* + * 
+ * User=0.00s Sys=0.00s Real=0.00s
+ *
+ * * @author Mike Millson * */ @@ -29,9 +41,20 @@ public interface TimesData { /** * Regular expression for times data block. */ - String REGEX = "( \\[Times: user=(\\d{1,5}[\\.\\,]\\d{2}) sys=\\d{1,5}[\\.\\,]\\d{2}, " + public static final String REGEX = "( \\[Times: user=(\\d{1,5}[\\.\\,]\\d{2}) sys=\\d{1,5}[\\.\\,]\\d{2}, " + "real=(\\d{1,5}[\\.\\,]\\d{2}) secs\\])"; + /** + * Regular expression for times data block JDK9+. + */ + public static final String REGEX_JDK9 = "( User=(\\d{1,5}[\\.\\,]\\d{2})s Sys=\\d{1,5}[\\.\\,]\\d{2}s " + + "Real=(\\d{1,5}[\\.\\,]\\d{2})s)"; + + /** + * Use for logging events that do not include times data. + */ + public static final int NO_DATA = -Integer.MIN_VALUE; + /** * @return The time of all threads added together in centiseconds. */ diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/CmsConcurrentEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/CmsConcurrentEvent.java index dd425dae..71c77573 100644 --- a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/CmsConcurrentEvent.java +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/CmsConcurrentEvent.java @@ -109,5 +109,4 @@ public long getTimestamp() { public static final boolean match(String logLine) { return pattern.matcher(logLine).matches(); } - } diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/FooterHeapEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/FooterHeapEvent.java new file mode 100644 index 00000000..ee1ababf --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/FooterHeapEvent.java @@ -0,0 +1,122 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import org.eclipselabs.garbagecat.domain.LogEvent; +import org.eclipselabs.garbagecat.domain.ThrowAwayEvent; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * FOOTER_HEAP + *

+ * + *

+ * Heap information printed at the end of gc logging with unified detailed logging + * (-Xlog:gc*:file=<file>). + *

+ * + *

Example Logging

+ * + * 
+ * [25.016s][info][gc,heap,exit  ] Heap
+ * [25.016s][info][gc,heap,exit  ]  garbage-first heap   total 59392K, used 38015K [0x00000000fc000000, 0x0000000100000000)
+ * [25.016s][info][gc,heap,exit  ]   region size 1024K, 13 young (13312K), 1 survivors (1024K)
+ * [25.016s][info][gc,heap,exit  ]  Metaspace       used 11079K, capacity 11287K, committed 11520K, reserved 1060864K
+ * [25.016s][info][gc,heap,exit  ]   class space    used 909K, capacity 995K, committed 1024K, reserved 1048576K
+ *
+ * + * @author Mike Millson + * + */ +public class FooterHeapEvent implements UnifiedLogging, LogEvent, ThrowAwayEvent { + + /** + * Regular expression for heap line. + */ + private static final String REGEX_HEAP = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,heap,exit \\] Heap$"; + + /** + * Regular expression for garbage-first line. + */ + private static final String REGEX_GARBAGE_FIRST = "^\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc,heap,exit \\] garbage-first heap total " + JdkRegEx.SIZE + ", used " + + JdkRegEx.SIZE + " \\[" + JdkRegEx.ADDRESS + ", " + JdkRegEx.ADDRESS + "\\)$"; + + /** + * Regular expression for region line. + */ + private static final String REGEX_REGION = "^\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc,heap,exit \\] region size " + JdkRegEx.SIZE + ", \\d{1,2} young \\(" + + JdkRegEx.SIZE + "\\), \\d{1} survivors \\(" + JdkRegEx.SIZE + "\\)$"; + + /** + * Regular expression for metaspace line. + */ + private static final String REGEX_METASPACE = "^\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc,heap,exit \\] Metaspace used " + JdkRegEx.SIZE + ", capacity " + + JdkRegEx.SIZE + ", committed " + JdkRegEx.SIZE + ", reserved " + JdkRegEx.SIZE + "$"; + + /** + * Regular expression for class line. + */ + private static final String REGEX_CLASS = "^\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc,heap,exit \\] class space used " + JdkRegEx.SIZE + ", capacity " + + JdkRegEx.SIZE + ", committed " + JdkRegEx.SIZE + ", reserved " + JdkRegEx.SIZE + "$"; + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * The time when the GC event started in milliseconds after JVM startup. + */ + private long timestamp; + + /** + * Create event from log entry. + * + * @param logEntry + * The log entry for the event. + */ + public FooterHeapEvent(String logEntry) { + this.logEntry = logEntry; + this.timestamp = 0L; + } + + public String getLogEntry() { + return logEntry; + } + + public String getName() { + return JdkUtil.LogEventType.FOOTER_HEAP.toString(); + } + + public long getTimestamp() { + return timestamp; + } + + /** + * Determine if the logLine matches the logging pattern(s) for this event. + * + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + return (logLine.matches(REGEX_HEAP) || logLine.matches(REGEX_GARBAGE_FIRST) || logLine.matches(REGEX_REGION) + || logLine.matches(REGEX_METASPACE) || logLine.matches(REGEX_CLASS)); + } +} diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapAddressEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapAddressEvent.java new file mode 100644 index 00000000..df48ad70 --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapAddressEvent.java @@ -0,0 +1,94 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.regex.Pattern; + +import org.eclipselabs.garbagecat.domain.LogEvent; +import org.eclipselabs.garbagecat.domain.ThrowAwayEvent; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * HEAP_ADDRESS + *

+ * + *

+ * Heap address information printed at the beginning gc logging with unified detailed logging + * (-Xlog:gc*:file=<file>). + *

+ * + *

Example Logging

+ * + * 
+ * [0.004s][info][gc,heap,coops] Heap address: 0x00000000fc000000, size: 64 MB, Compressed Oops mode: 32-bit
+ *
+ * + * @author Mike Millson + * + */ +public class HeapAddressEvent implements UnifiedLogging, LogEvent, ThrowAwayEvent { + + /** + * Regular expressions defining the logging. + */ + private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,heap,coops\\] Heap address: " + + JdkRegEx.ADDRESS + ", size: \\d{1,8} MB, Compressed Oops mode: 32-bit$"; + + private static final Pattern pattern = Pattern.compile(REGEX); + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * The time when the GC event started in milliseconds after JVM startup. + */ + private long timestamp; + + /** + * Create event from log entry. + * + * @param logEntry + * The log entry for the event. + */ + public HeapAddressEvent(String logEntry) { + this.logEntry = logEntry; + this.timestamp = 0L; + } + + public String getLogEntry() { + return logEntry; + } + + public String getName() { + return JdkUtil.LogEventType.HEAP_ADDRESS.toString(); + } + + public long getTimestamp() { + return timestamp; + } + + /** + * Determine if the logLine matches the logging pattern(s) for this event. + * + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + return pattern.matcher(logLine).matches(); + } +} diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapRegionSizeEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapRegionSizeEvent.java new file mode 100644 index 00000000..6a4b674c --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/HeapRegionSizeEvent.java @@ -0,0 +1,94 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.regex.Pattern; + +import org.eclipselabs.garbagecat.domain.LogEvent; +import org.eclipselabs.garbagecat.domain.ThrowAwayEvent; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * HEAP_REGION_SIZE + *

+ * + *

+ * Heap region size information printed at the beginning gc logging with unified detailed logging + * (-Xlog:gc*:file=<file>). + *

+ * + *

Example Logging

+ * + * 
+ * [0.003s][info][gc,heap] Heap region size: 1M
+ *
+ * + * @author Mike Millson + * + */ +public class HeapRegionSizeEvent implements UnifiedLogging, LogEvent, ThrowAwayEvent { + + /** + * Regular expressions defining the logging. + */ + private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,heap\\] Heap region size: " + + JdkRegEx.SIZE + "$"; + + private static final Pattern pattern = Pattern.compile(REGEX); + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * The time when the GC event started in milliseconds after JVM startup. + */ + private long timestamp; + + /** + * Create event from log entry. + * + * @param logEntry + * The log entry for the event. + */ + public HeapRegionSizeEvent(String logEntry) { + this.logEntry = logEntry; + this.timestamp = 0L; + } + + public String getLogEntry() { + return logEntry; + } + + public String getName() { + return JdkUtil.LogEventType.HEAP_REGION_SIZE.toString(); + } + + public long getTimestamp() { + return timestamp; + } + + /** + * Determine if the logLine matches the logging pattern(s) for this event. + * + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + return pattern.matcher(logLine).matches(); + } +} diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1CleanupEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1CleanupEvent.java new file mode 100644 index 00000000..4df02e6f --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1CleanupEvent.java @@ -0,0 +1,224 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.eclipselabs.garbagecat.domain.BlockingEvent; +import org.eclipselabs.garbagecat.domain.CombinedData; +import org.eclipselabs.garbagecat.domain.ParallelEvent; +import org.eclipselabs.garbagecat.domain.TimesData; +import org.eclipselabs.garbagecat.domain.jdk.G1Collector; +import org.eclipselabs.garbagecat.util.jdk.JdkMath; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * G1_CLEANUP + *

+ * + *

+ * {@link org.eclipselabs.garbagecat.domain.jdk.G1CleanupEvent} with unified logging (JDK9+). + *

+ * + *

Example Logging

+ * + *

+ * 1) Logging without details: + *

+ * + * 
+ * [15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms
+ *
+ * + *

+ * 2) Preprocessed from logging with details: + *

+ * + * 
+ * [16.082s][info][gc            ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + * @author Mike Millson + * + */ +public class UnifiedG1CleanupEvent extends G1Collector + implements UnifiedLogging, BlockingEvent, ParallelEvent, CombinedData, TimesData { + + /** + * Regular expressions defining the logging. + */ + private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc\\] " + + JdkRegEx.GC_EVENT_NUMBER + " Pause Cleanup " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + "[ ]*$"; + + /** + * Regular expression defining preprocessed logging. + */ + private static final String REGEX_PREPROCESSED = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc \\] " + + JdkRegEx.GC_EVENT_NUMBER + " Pause Cleanup " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + TimesData.REGEX_JDK9 + "[ ]*$"; + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * The elapsed clock time for the GC event in milliseconds (rounded). + */ + private int duration; + + /** + * The time when the GC event started in milliseconds after JVM startup. + */ + private long timestamp; + + /** + * Combined young + old generation size (kilobytes) at beginning of GC event. + */ + private int combinedBegin; + + /** + * Combined young + old generation size (kilobytes) at end of GC event. + */ + private int combinedEnd; + + /** + * Combined young + old generation allocation (kilobytes). + */ + private int combinedAllocation; + + /** + * The time of all threads added together in centiseconds. + */ + private int timeUser; + + /** + * The wall (clock) time in centiseconds. + */ + private int timeReal; + + /** + * Create event from log entry. + * + * @param logEntry + * The log entry for the event. + */ + public UnifiedG1CleanupEvent(String logEntry) { + this.logEntry = logEntry; + if (logEntry.matches(REGEX)) { + Pattern pattern = Pattern.compile(REGEX); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(2)), matcher.group(4).charAt(0)); + combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(5)), matcher.group(7).charAt(0)); + combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(8)), + matcher.group(10).charAt(0)); + duration = JdkMath.roundMillis(matcher.group(11)).intValue(); + timestamp = endTimestamp - duration; + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } else if (logEntry.matches(REGEX_PREPROCESSED)) { + Pattern pattern = Pattern.compile(REGEX_PREPROCESSED); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(2)), matcher.group(4).charAt(0)); + combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(5)), matcher.group(7).charAt(0)); + combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(8)), + matcher.group(10).charAt(0)); + duration = JdkMath.roundMillis(matcher.group(11)).intValue(); + timestamp = endTimestamp - duration; + if (matcher.group(12) != null) { + timeUser = JdkMath.convertSecsToCentis(matcher.group(13)).intValue(); + timeReal = JdkMath.convertSecsToCentis(matcher.group(14)).intValue(); + } else { + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } + } + } + + /** + * Alternate constructor. Create detail logging event from values. + * + * @param logEntry + * The log entry for the event. + * @param timestamp + * The time when the GC event started in milliseconds after JVM startup. + * @param duration + * The elapsed clock time for the GC event in milliseconds. + */ + public UnifiedG1CleanupEvent(String logEntry, long timestamp, int duration) { + this.logEntry = logEntry; + this.timestamp = timestamp; + this.duration = duration; + } + + public String getName() { + return JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString(); + } + + public String getLogEntry() { + return logEntry; + } + + public int getDuration() { + return duration; + } + + public long getTimestamp() { + return timestamp; + } + + public int getCombinedOccupancyInit() { + return combinedBegin; + } + + public int getCombinedOccupancyEnd() { + return combinedEnd; + } + + public int getCombinedSpace() { + return combinedAllocation; + } + + public int getTimeUser() { + return timeUser; + } + + public int getTimeReal() { + return timeReal; + } + + public int getParallelism() { + return JdkMath.calcParallelism(timeUser, timeReal); + } + + /** + * Determine if the logLine matches the logging pattern(s) for this event. + * + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + return logLine.matches(REGEX) || logLine.matches(REGEX_PREPROCESSED); + } +} diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1ConcurrentEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1ConcurrentEvent.java index 4396d453..27667352 100644 --- a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1ConcurrentEvent.java +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1ConcurrentEvent.java @@ -12,13 +12,9 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.domain.jdk.unified; -import java.util.regex.Matcher; -import java.util.regex.Pattern; - import org.eclipselabs.garbagecat.domain.LogEvent; import org.eclipselabs.garbagecat.domain.ParallelEvent; import org.eclipselabs.garbagecat.domain.jdk.G1Collector; -import org.eclipselabs.garbagecat.util.jdk.JdkMath; import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; import org.eclipselabs.garbagecat.util.jdk.JdkUtil; @@ -38,9 +34,9 @@ * *

Example Logging

* - * 
- * [36.603s][info][gc] GC(1335) Pause Cleanup 38M->38M(56M) 0.102ms
- *
+ *

+ * Standard logging: + *

* * 
  * [36.400s][info][gc] GC(1330) Concurrent Cycle
@@ -50,6 +46,58 @@
  * [36.606s][info][gc] GC(1335) Concurrent Cycle 90.487ms
  *
* + *

+ * Detailed logging: + *

+ * + * 
+ * [16.601s][info][gc           ] GC(1033) Concurrent Cycle
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Clear Claimed Marks
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Clear Claimed Marks 0.019ms
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Scan Root Regions
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Scan Root Regions 0.283ms
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Mark (16.601s)
+ *
+ * + * 
+ * [16.050s][info][gc,marking   ] GC(969) Concurrent Mark (16.017s, 16.050s) 33.614ms
+ *
+ * + * 
+ * [16.601s][info][gc,marking   ] GC(1033) Concurrent Mark From Roots
+ *
+ * + * 
+ * [16.601s][info][gc,task      ] GC(1033) Using 1 workers of 1 for marking
+ *
+ * + * 
+ * [16.053s][info][gc,marking    ] GC(969) Concurrent Rebuild Remembered Sets
+ *
+ * + * 
+ * [16.082s][info][gc,marking    ] GC(969) Concurrent Cleanup for Next Mark
+ *
+ * + * 
+ * [16.082s][info][gc,marking    ] GC(969) Concurrent Cleanup for Next Mark 0.428ms
+ *
+ * * @author Mike Millson * */ @@ -58,55 +106,31 @@ public class UnifiedG1ConcurrentEvent extends G1Collector implements UnifiedLogg /** * Regular expressions defining the logging. */ - private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc\\] " - + JdkRegEx.GC_EVENT_NUMBER + " (Pause Cleanup|Concurrent Cycle)( " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE - + "\\(" + JdkRegEx.SIZE + "\\))?( " + JdkRegEx.DURATION_JDK9 + ")?[ ]*$"; - - private static final Pattern pattern = Pattern.compile(REGEX); - - /** - * The log entry for the event. Can be used for debugging purposes. - */ - private String logEntry; - - /** - * The time when the GC event started in milliseconds after JVM startup. - */ - private long timestamp; - - /** - * Create event from log entry. - * - * @param logEntry - * The log entry for the event. - */ - public UnifiedG1ConcurrentEvent(String logEntry) { - this.logEntry = logEntry; - - if (logEntry.matches(REGEX)) { - Pattern pattern = Pattern.compile(REGEX); - Matcher matcher = pattern.matcher(logEntry); - if (matcher.find()) { - long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); - int duration = 0; - if (matcher.group(14) != null) { - duration = JdkMath.roundMillis(matcher.group(14)).intValue(); - } - timestamp = endTimestamp - duration; - } - } - } + private static final String[] REGEX = { + // gc + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc[ ]{0,12}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Concurrent Cycle( " + JdkRegEx.DURATION_JDK9 + ")?$", + // gc, marking + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,marking[ ]{3,4}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Concurrent (Clear Claimed Marks|Scan Root Regions|Mark|Mark From Roots|Preclean|" + + "Rebuild Remembered Sets|Cleanup for Next Mark)( \\(" + JdkRegEx.TIMESTAMP + "s(, " + + JdkRegEx.TIMESTAMP + "s)?\\))?( " + JdkRegEx.DURATION_JDK9 + ")?$", + // gc, task + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,task \\] " + JdkRegEx.GC_EVENT_NUMBER + + " Using \\d workers of \\d for marking$" + // + }; public String getLogEntry() { - return logEntry; + throw new UnsupportedOperationException("Event does not include log entry information"); } public String getName() { - return JdkUtil.LogEventType.G1_CONCURRENT.toString(); + return JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString(); } public long getTimestamp() { - return timestamp; + throw new UnsupportedOperationException("Event does not include timestamp information"); } /** @@ -117,6 +141,13 @@ public long getTimestamp() { * @return true if the log line matches the event pattern, false otherwise. */ public static final boolean match(String logLine) { - return pattern.matcher(logLine).matches(); + boolean match = false; + for (int i = 0; i < REGEX.length; i++) { + if (logLine.matches(REGEX[i])) { + match = true; + break; + } + } + return match; } } diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1YoungPauseEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1YoungPauseEvent.java new file mode 100644 index 00000000..3e452791 --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedG1YoungPauseEvent.java @@ -0,0 +1,248 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.eclipselabs.garbagecat.domain.BlockingEvent; +import org.eclipselabs.garbagecat.domain.CombinedData; +import org.eclipselabs.garbagecat.domain.ParallelEvent; +import org.eclipselabs.garbagecat.domain.TimesData; +import org.eclipselabs.garbagecat.domain.TriggerData; +import org.eclipselabs.garbagecat.domain.YoungCollection; +import org.eclipselabs.garbagecat.domain.jdk.G1Collector; +import org.eclipselabs.garbagecat.util.jdk.JdkMath; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * UNIFIED_G1_YOUNG_PAUSE + *

+ * + *

+ * {@link org.eclipselabs.garbagecat.domain.jdk.G1YoungPauseEvent} with unified logging (JDK9+). + *

+ * + *

+ * G1 young generation collection. Live objects from Eden and Survivor regions are copied to new regions, either to a + * survivor region or promoted to the old space. + *

+ * + *

Example Logging

+ * + *

+ * Standard format: + *

+ * + * 
+ * [18.406s][info][gc] GC(1012) Pause Young (Normal) (G1 Evacuation Pause) 38M->19M(46M) 1.815ms
+ *
+ * + *

+ * Preprocessed from logging with details: + *

+ * + * 
+ * [0.101s][info][gc           ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 0M->0M(2M) 1.371ms User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + * @author Mike Millson + * + */ +public class UnifiedG1YoungPauseEvent extends G1Collector + implements UnifiedLogging, BlockingEvent, YoungCollection, ParallelEvent, CombinedData, TriggerData, TimesData { + + /** + * Trigger(s) regular expression(s). + */ + private static final String TRIGGER = "(" + JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE + ")"; + + /** + * Regular expression defining standard logging (no details). + */ + private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc\\] " + + JdkRegEx.GC_EVENT_NUMBER + " Pause Young \\((Normal|Concurrent Start)\\) \\(" + TRIGGER + "\\) " + + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + "[ ]*$"; + + /** + * Regular expression defining preprocessed logging. + */ + private static final String REGEX_PREPROCESSED = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc[ ]{11,12}\\] " + + JdkRegEx.GC_EVENT_NUMBER + " Pause Young \\((Normal|Concurrent Start)\\) \\(" + TRIGGER + "\\) " + + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + + TimesData.REGEX_JDK9 + "[ ]*$"; + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * The elapsed clock time for the GC event in milliseconds (rounded). + */ + private int duration; + + /** + * The time when the GC event started in milliseconds after JVM startup. + */ + private long timestamp; + + /** + * Combined young + old generation size (kilobytes) at beginning of GC event. + */ + private int combinedBegin; + + /** + * Combined young + old generation size (kilobytes) at end of GC event. + */ + private int combinedEnd; + + /** + * Combined young + old generation allocation (kilobytes). + */ + private int combinedAllocation; + + /** + * The trigger for the GC event. + */ + private String trigger; + + /** + * The time of all threads added together in centiseconds. + */ + private int timeUser; + + /** + * The wall (clock) time in centiseconds. + */ + private int timeReal; + + /** + * Create event from log entry. + * + * @param logEntry + * The log entry for the event. + */ + public UnifiedG1YoungPauseEvent(String logEntry) { + this.logEntry = logEntry; + if (logEntry.matches(REGEX)) { + Pattern pattern = Pattern.compile(REGEX); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + trigger = matcher.group(3); + combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(4)), matcher.group(6).charAt(0)); + combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(7)), matcher.group(9).charAt(0)); + combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(10)), + matcher.group(12).charAt(0)); + duration = JdkMath.roundMillis(matcher.group(13)).intValue(); + timestamp = endTimestamp - duration; + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } else if (logEntry.matches(REGEX_PREPROCESSED)) { + Pattern pattern = Pattern.compile(REGEX_PREPROCESSED); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + trigger = matcher.group(3); + combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(4)), matcher.group(6).charAt(0)); + combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(7)), matcher.group(9).charAt(0)); + combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(10)), + matcher.group(12).charAt(0)); + duration = JdkMath.roundMillis(matcher.group(13)).intValue(); + timestamp = endTimestamp - duration; + if (matcher.group(14) != null) { + timeUser = JdkMath.convertSecsToCentis(matcher.group(15)).intValue(); + timeReal = JdkMath.convertSecsToCentis(matcher.group(16)).intValue(); + } else { + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } + } + } + + /** + * Alternate constructor. Create detail logging event from values. + * + * @param logEntry + * The log entry for the event. + * @param timestamp + * The time when the GC event started in milliseconds after JVM startup. + * @param duration + * The elapsed clock time for the GC event in milliseconds. + */ + public UnifiedG1YoungPauseEvent(String logEntry, long timestamp, int duration) { + this.logEntry = logEntry; + this.timestamp = timestamp; + this.duration = duration; + } + + public String getName() { + return JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString(); + } + + public String getLogEntry() { + return logEntry; + } + + public int getDuration() { + return duration; + } + + public long getTimestamp() { + return timestamp; + } + + public int getCombinedOccupancyInit() { + return combinedBegin; + } + + public int getCombinedOccupancyEnd() { + return combinedEnd; + } + + public int getCombinedSpace() { + return combinedAllocation; + } + + public String getTrigger() { + return trigger; + } + + public int getTimeUser() { + return timeUser; + } + + public int getTimeReal() { + return timeReal; + } + + public int getParallelism() { + return JdkMath.calcParallelism(timeUser, timeReal); + } + + /** + * Determine if the logLine matches the logging pattern(s) for this event. + * + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + return logLine.matches(REGEX) || logLine.matches(REGEX_PREPROCESSED); + } +} diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedRemarkEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedRemarkEvent.java index bbc01bd3..04489888 100644 --- a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedRemarkEvent.java +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedRemarkEvent.java @@ -17,6 +17,7 @@ import org.eclipselabs.garbagecat.domain.BlockingEvent; import org.eclipselabs.garbagecat.domain.ParallelEvent; +import org.eclipselabs.garbagecat.domain.TimesData; import org.eclipselabs.garbagecat.domain.jdk.UnknownCollector; import org.eclipselabs.garbagecat.util.jdk.JdkMath; import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; @@ -28,24 +29,33 @@ *

* *

- * Remark collection JDK9+ with -Xlog:gc:file=<file> (no details). - *

- * - *

* Collector is one of the following: (1) {@link org.eclipselabs.garbagecat.domain.jdk.CmsRemarkEvent}, (2) * {@link org.eclipselabs.garbagecat.domain.jdk.G1RemarkEvent}. *

* *

Example Logging

* + *

+ * 1) Without detailed logging: + *

+ * * 
  * [4.353s][info][gc] GC(3130) Pause Remark 5M->5M(7M) 1.398ms
  *
* + *

+ * 2) Preprocessed detailed logging: + *

+ * + * 
+ * [16.053s][info][gc            ] GC(969) Pause Remark 29M->29M(46M) 2.328ms User=0.01s Sys=0.00s Real=0.00s
+ *
+ * * @author Mike Millson * */ -public class UnifiedRemarkEvent extends UnknownCollector implements UnifiedLogging, BlockingEvent, ParallelEvent { +public class UnifiedRemarkEvent extends UnknownCollector + implements UnifiedLogging, BlockingEvent, ParallelEvent, TimesData { /** * Regular expressions defining the logging JDK9+. @@ -54,7 +64,12 @@ public class UnifiedRemarkEvent extends UnknownCollector implements UnifiedLoggi + JdkRegEx.GC_EVENT_NUMBER + " Pause Remark " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + "[ ]*$"; - private static final Pattern pattern = Pattern.compile(REGEX); + /** + * Regular expression defining preprocessed logging. + */ + private static final String REGEX_PREPROCESSED = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc \\] " + + JdkRegEx.GC_EVENT_NUMBER + " Pause Remark " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + + "\\) " + JdkRegEx.DURATION_JDK9 + TimesData.REGEX_JDK9 + "[ ]*$"; /** * The log entry for the event. Can be used for debugging purposes. @@ -71,6 +86,16 @@ public class UnifiedRemarkEvent extends UnknownCollector implements UnifiedLoggi */ private long timestamp; + /** + * The time of all threads added together in centiseconds. + */ + private int timeUser; + + /** + * The wall (clock) time in centiseconds. + */ + private int timeReal; + /** * Create event from log entry. * @@ -79,11 +104,31 @@ public class UnifiedRemarkEvent extends UnknownCollector implements UnifiedLoggi */ public UnifiedRemarkEvent(String logEntry) { this.logEntry = logEntry; - Matcher matcher = pattern.matcher(logEntry); - if (matcher.find()) { - long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); - duration = JdkMath.roundMillis(matcher.group(11)).intValue(); - timestamp = endTimestamp - duration; + if (logEntry.matches(REGEX)) { + Pattern pattern = Pattern.compile(REGEX); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + duration = JdkMath.roundMillis(matcher.group(11)).intValue(); + timestamp = endTimestamp - duration; + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } else if (logEntry.matches(REGEX_PREPROCESSED)) { + Pattern pattern = Pattern.compile(REGEX_PREPROCESSED); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.find()) { + long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); + duration = JdkMath.roundMillis(matcher.group(11)).intValue(); + timestamp = endTimestamp - duration; + if (matcher.group(12) != null) { + timeUser = JdkMath.convertSecsToCentis(matcher.group(13)).intValue(); + timeReal = JdkMath.convertSecsToCentis(matcher.group(14)).intValue(); + } else { + timeUser = TimesData.NO_DATA; + timeReal = TimesData.NO_DATA; + } + } } } @@ -119,6 +164,18 @@ public String getName() { return JdkUtil.LogEventType.UNIFIED_REMARK.toString(); } + public int getTimeUser() { + return timeUser; + } + + public int getTimeReal() { + return timeReal; + } + + public int getParallelism() { + return JdkMath.calcParallelism(timeUser, timeReal); + } + /** * Determine if the logLine matches the logging pattern(s) for this event. * @@ -127,6 +184,6 @@ public String getName() { * @return true if the log line matches the event pattern, false otherwise. */ public static final boolean match(String logLine) { - return pattern.matcher(logLine).matches(); + return logLine.matches(REGEX) || logLine.matches(REGEX_PREPROCESSED); } } diff --git a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedYoungEvent.java b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedYoungEvent.java index f2e3b89a..46fae749 100644 --- a/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedYoungEvent.java +++ b/src/main/java/org/eclipselabs/garbagecat/domain/jdk/unified/UnifiedYoungEvent.java @@ -36,8 +36,7 @@ *

* Collector is one of the following: (1) {@link org.eclipselabs.garbagecat.domain.jdk.SerialNewEvent}, (2) * {@link org.eclipselabs.garbagecat.domain.jdk.ParallelScavengeEvent}, (3) - * {@link org.eclipselabs.garbagecat.domain.jdk.ParNewEvent}, - * {@link org.eclipselabs.garbagecat.domain.jdk.G1YoungPauseEvent}(4). + * {@link org.eclipselabs.garbagecat.domain.jdk.ParNewEvent}. *

* *

Example Logging

@@ -46,11 +45,6 @@ * [0.053s][info][gc] GC(0) Pause Young (Allocation Failure) 0M->0M(1M) 0.914ms * * - * 
- * [18.406s][info][gc] GC(1012) Pause Young (Normal) (G1 Evacuation Pause) 38M->19M(46M) 1.815ms
- *
- * - * * @author Mike Millson * */ @@ -96,14 +90,14 @@ public class UnifiedYoungEvent extends UnknownCollector * Trigger(s) regular expression(s). */ private static final String TRIGGER = "(" + JdkRegEx.TRIGGER_ALLOCATION_FAILURE + "|" + JdkRegEx.TRIGGER_SYSTEM_GC - + "|" + JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE + ")"; + + ")"; /** * Regular expression defining the logging. */ private static final String REGEX = "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc\\] " - + JdkRegEx.GC_EVENT_NUMBER + " Pause Young( \\((Normal|Concurrent Start)\\))? \\(" + TRIGGER + "\\) " - + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + "[ ]*$"; + + JdkRegEx.GC_EVENT_NUMBER + " Pause Young \\(" + TRIGGER + "\\) " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + "[ ]*$"; private static final Pattern pattern = Pattern.compile(REGEX); @@ -117,12 +111,12 @@ public UnifiedYoungEvent(String logEntry) { Matcher matcher = pattern.matcher(logEntry); if (matcher.find()) { long endTimestamp = JdkMath.convertSecsToMillis(matcher.group(1)).longValue(); - trigger = matcher.group(4); - combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(6)), matcher.group(8).charAt(0)); - combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(9)), matcher.group(11).charAt(0)); - combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(12)), - matcher.group(14).charAt(0)); - duration = JdkMath.roundMillis(matcher.group(15)).intValue(); + trigger = matcher.group(2); + combinedBegin = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(4)), matcher.group(6).charAt(0)); + combinedEnd = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(7)), matcher.group(9).charAt(0)); + combinedAllocation = JdkMath.calcKilobytes(Integer.parseInt(matcher.group(10)), + matcher.group(12).charAt(0)); + duration = JdkMath.roundMillis(matcher.group(13)).intValue(); timestamp = endTimestamp - duration; } } diff --git a/src/main/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/UnifiedG1PreprocessAction.java b/src/main/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/UnifiedG1PreprocessAction.java new file mode 100644 index 00000000..0a548902 --- /dev/null +++ b/src/main/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/UnifiedG1PreprocessAction.java @@ -0,0 +1,295 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.preprocess.jdk.unified; + +import java.util.Iterator; +import java.util.List; +import java.util.Set; +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.eclipselabs.garbagecat.domain.TimesData; +import org.eclipselabs.garbagecat.preprocess.PreprocessAction; +import org.eclipselabs.garbagecat.util.Constants; +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; + +/** + *

+ * G1 unified logging preprocessing. + *

+ * + *

Example Logging

+ * + *

+ * 1) {@link org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedG1YoungPauseEvent}: + *

+ * + * 
+ * [0.099s][info][gc,start     ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
+ * [0.100s][info][gc,task      ] GC(0) Using 2 workers of 4 for evacuation
+ * [0.101s][info][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms
+ * [0.101s][info][gc,phases    ] GC(0)   Evacuate Collection Set: 1.0ms
+ * [0.101s][info][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.2ms
+ * [0.101s][info][gc,phases    ] GC(0)   Other: 0.2ms
+ * [0.101s][info][gc,heap      ] GC(0) Eden regions: 1->0(1)
+ * [0.101s][info][gc,heap      ] GC(0) Survivor regions: 0->1(1)
+ * [0.101s][info][gc,heap      ] GC(0) Old regions: 0->0
+ * [0.101s][info][gc,heap      ] GC(0) Humongous regions: 0->0
+ * [0.101s][info][gc,metaspace ] GC(0) Metaspace: 4463K->4463K(1056768K)
+ * [0.101s][info][gc           ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 0M->0M(2M) 1.371ms
+ * [0.101s][info][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + *

+ * Preprocessed: + *

+ * + * 
+ * [0.101s][info][gc           ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 0M->0M(2M) 1.371ms User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + *

+ * 2) {@link org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedRemarkEvent}: + *

+ * + * 
+ * [16.051s][info][gc,start     ] GC(969) Pause Remark
+ * [16.053s][info][gc,stringtable] GC(969) Cleaned string and symbol table, strings: 5786 processed, 4 removed, symbols: 38663 processed, 11 removed
+ * [16.053s][info][gc            ] GC(969) Pause Remark 29M->29M(46M) 2.328ms
+ * [16.053s][info][gc,cpu        ] GC(969) User=0.01s Sys=0.00s Real=0.00s
+ *
+ * + *

+ * Preprocessed: + *

+ * + * 
+ * [16.053s][info][gc            ] GC(969) Pause Remark 29M->29M(46M) 2.328ms User=0.01s Sys=0.00s Real=0.00s
+ *
+ * + * * + *

+ * 3) {@link org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedG1CleanupEvent}: + *

+ * + * 
+ * [16.081s][info][gc,start      ] GC(969) Pause Cleanup
+ * [16.082s][info][gc            ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms
+ * [16.082s][info][gc,cpu        ] GC(969) User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + *

+ * Preprocessed: + *

+ * + * 
+ * [16.082s][info][gc            ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms User=0.00s Sys=0.00s Real=0.00s
+ *
+ * + * @author Mike Millson + * + */ +public class UnifiedG1PreprocessAction implements PreprocessAction { + + /** + * Regular expression for retained beginning UNIFIED_G1_YOUNG_PAUSE collection. + * + * [0.101s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 0M->0M(2M) 1.371ms + * + * [16.601s][info][gc ] GC(1032) Pause Young (Concurrent Start) (G1 Evacuation Pause) 38M->20M(46M) 0.772ms + */ + private static final String REGEX_RETAIN_PAUSE_YOUNG = "^(\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc \\] " + JdkRegEx.GC_EVENT_NUMBER + + " Pause Young \\((Normal|Concurrent Start)\\) \\(G1 Evacuation Pause\\) " + JdkRegEx.SIZE + "->" + + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + ")$"; + + /** + * Regular expression for retained beginning UNIFIED_G1_CLEANUP collection. + * + * [16.082s][info][gc ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms + */ + private static final String REGEX_RETAIN_CLEANUP = "^(\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc \\] " + JdkRegEx.GC_EVENT_NUMBER + " Pause Cleanup " + JdkRegEx.SIZE + + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + ")$"; + + /** + * Regular expression for retained beginning UNIFIED_REMARK collection. + * + * [16.053s][info][gc ] GC(969) Pause Remark 29M->29M(46M) 2.328ms + */ + private static final String REGEX_RETAIN_REMARK = "^(\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc \\] " + JdkRegEx.GC_EVENT_NUMBER + " Pause Remark " + JdkRegEx.SIZE + "->" + + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\) " + JdkRegEx.DURATION_JDK9 + ")$"; + + /** + * Regular expression for retained end times data. + * + * [16.601s][info][gc,cpu ] GC(1032) User=0.00s Sys=0.00s Real=0.00s + */ + private static final String REGEX_RETAIN_END_TIMES_DATA = "^\\[" + JdkRegEx.TIMESTAMP + + "s\\]\\[info\\]\\[gc,cpu[ ]{7,8}\\] " + JdkRegEx.GC_EVENT_NUMBER + TimesData.REGEX_JDK9 + "$"; + + /** + * Regular expressions for lines thrown away. + */ + private static final String[] REGEX_THROWAWAY = { + + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,start[ ]{5,6}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Pause Young \\((Normal|Concurrent Start)\\) \\(G1 Evacuation Pause\\)$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,task[ ]{6,7}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Using \\d workers of \\d for (evacuation|marking)$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,phases[ ]{4,5}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " ((Pre Evacuate|Evacuate|Post Evacuate|Other) Collection Set|Other): " + JdkRegEx.DURATION_JDK9 + + "$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,heap[ ]{6,7}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " (Eden|Survivor|Old|Humongous) regions: \\d{1,2}->\\d{1,2}(\\(\\d{1,2}\\))?$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,metaspace[ ]{1,2}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Metaspace: " + JdkRegEx.SIZE + "->" + JdkRegEx.SIZE + "\\(" + JdkRegEx.SIZE + "\\)$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,start[ ]{5,6}\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Pause Remark$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,stringtable\\] " + JdkRegEx.GC_EVENT_NUMBER + + " Cleaned string and symbol table, strings: \\d{1,4} processed, \\d removed, " + + "symbols: \\d{1,5} processed, \\d{1,2} removed$", + // + "^\\[" + JdkRegEx.TIMESTAMP + "s\\]\\[info\\]\\[gc,start \\] " + JdkRegEx.GC_EVENT_NUMBER + + " Pause Cleanup$" + // + }; + + /** + * The log entry for the event. Can be used for debugging purposes. + */ + private String logEntry; + + /** + * Log entry in the entangle log list used to indicate the current high level preprocessor (e.g. CMS, G1). This + * context is necessary to detangle multi-line events where logging patterns are shared among preprocessors. + * + * For example, it is used with the G1PreprocessAction to identify concurrent events intermingled with + * non-concurrent events to store them in the intermingled log lines list for output after the non-concurrent event. + */ + public static final String TOKEN = "UNIFIED_G1_PREPROCESS_ACTION_TOKEN"; + + /** + * Create event from log entry. + * + * @param priorLogEntry + * The prior log line. + * @param logEntry + * The log line. + * @param nextLogEntry + * The next log line. + * @param entangledLogLines + * Log lines to be output out of order. + * @param context + * Information to make preprocessing decisions. + */ + public UnifiedG1PreprocessAction(String priorLogEntry, String logEntry, String nextLogEntry, + List entangledLogLines, Set context) { + + // Beginning logging + if (logEntry.matches(REGEX_RETAIN_PAUSE_YOUNG)) { + Pattern pattern = Pattern.compile(REGEX_RETAIN_PAUSE_YOUNG); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.matches()) { + this.logEntry = matcher.group(1); + } + context.add(PreprocessAction.TOKEN_BEGINNING_OF_EVENT); + context.add(TOKEN); + } else if (logEntry.matches(REGEX_RETAIN_CLEANUP)) { + Pattern pattern = Pattern.compile(REGEX_RETAIN_CLEANUP); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.matches()) { + this.logEntry = matcher.group(1); + } + context.add(PreprocessAction.TOKEN_BEGINNING_OF_EVENT); + context.add(TOKEN); + } else if (logEntry.matches(REGEX_RETAIN_REMARK)) { + Pattern pattern = Pattern.compile(REGEX_RETAIN_REMARK); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.matches()) { + this.logEntry = matcher.group(1); + } + context.add(PreprocessAction.TOKEN_BEGINNING_OF_EVENT); + context.add(TOKEN); + } else if (logEntry.matches(REGEX_RETAIN_END_TIMES_DATA)) { + // End of logging event + Pattern pattern = Pattern.compile(REGEX_RETAIN_END_TIMES_DATA); + Matcher matcher = pattern.matcher(logEntry); + if (matcher.matches()) { + this.logEntry = matcher.group(2); + } + clearEntangledLines(entangledLogLines); + context.remove(PreprocessAction.TOKEN_BEGINNING_OF_EVENT); + context.remove(TOKEN); + } + } + + public String getLogEntry() { + return logEntry; + } + + public String getName() { + return JdkUtil.PreprocessActionType.G1.toString(); + } + + /** + * @param logLine + * The log line to test. + * @return true if the log line matches the event pattern, false otherwise. + */ + public static final boolean match(String logLine) { + boolean match = false; + if (logLine.matches(REGEX_RETAIN_PAUSE_YOUNG) + || logLine.matches(REGEX_RETAIN_PAUSE_YOUNG) | logLine.matches(REGEX_RETAIN_CLEANUP) + || logLine.matches(REGEX_RETAIN_END_TIMES_DATA)) { + match = true; + } else { + // TODO: Get rid of this and make them throwaway events? + for (int i = 0; i < REGEX_THROWAWAY.length; i++) { + if (logLine.matches(REGEX_THROWAWAY[i])) { + match = true; + break; + } + } + } + return match; + } + + /** + * Convenience method to write out any saved log lines. + * + * @param entangledLogLines + * Log lines to be output out of order. + * @return + */ + private final void clearEntangledLines(List entangledLogLines) { + if (entangledLogLines != null && entangledLogLines.size() > 0) { + // Output any entangled log lines + Iterator iterator = entangledLogLines.iterator(); + while (iterator.hasNext()) { + String logLine = iterator.next(); + this.logEntry = this.logEntry + Constants.LINE_SEPARATOR + logLine; + } + // Reset entangled log lines + entangledLogLines.clear(); + } + } +} \ No newline at end of file diff --git a/src/main/java/org/eclipselabs/garbagecat/service/GcManager.java b/src/main/java/org/eclipselabs/garbagecat/service/GcManager.java index 2497a6a8..d2f1f3f0 100644 --- a/src/main/java/org/eclipselabs/garbagecat/service/GcManager.java +++ b/src/main/java/org/eclipselabs/garbagecat/service/GcManager.java @@ -70,6 +70,7 @@ import org.eclipselabs.garbagecat.preprocess.jdk.G1PreprocessAction; import org.eclipselabs.garbagecat.preprocess.jdk.ParallelPreprocessAction; import org.eclipselabs.garbagecat.preprocess.jdk.SerialPreprocessAction; +import org.eclipselabs.garbagecat.preprocess.jdk.unified.UnifiedG1PreprocessAction; import org.eclipselabs.garbagecat.util.Constants; import org.eclipselabs.garbagecat.util.GcUtil; import org.eclipselabs.garbagecat.util.jdk.Analysis; @@ -320,7 +321,18 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) && !context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(CmsPreprocessAction.TOKEN) - && !context.contains(G1PreprocessAction.TOKEN) && ParallelPreprocessAction.match(currentLogLine)) { + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) + && UnifiedG1PreprocessAction.match(currentLogLine)) { + UnifiedG1PreprocessAction action = new UnifiedG1PreprocessAction(priorLogLine, currentLogLine, nextLogLine, + entangledLogLines, context); + if (action.getLogEntry() != null) { + preprocessedLogLine = action.getLogEntry(); + } + } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) + && !context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) + && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(CmsPreprocessAction.TOKEN) + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) + && ParallelPreprocessAction.match(currentLogLine)) { ParallelPreprocessAction action = new ParallelPreprocessAction(priorLogLine, currentLogLine, nextLogLine, entangledLogLines, context); if (action.getLogEntry() != null) { @@ -329,7 +341,7 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) && !context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) - && !context.contains(G1PreprocessAction.TOKEN) + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) && CmsPreprocessAction.match(currentLogLine, priorLogLine, nextLogLine)) { CmsPreprocessAction action = new CmsPreprocessAction(priorLogLine, currentLogLine, nextLogLine, entangledLogLines, context); @@ -337,8 +349,9 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin preprocessedLogLine = action.getLogEntry(); } } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) - && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(SerialPreprocessAction.TOKEN) - && !context.contains(ParallelPreprocessAction.TOKEN) && !context.contains(CmsPreprocessAction.TOKEN) + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) + && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) + && !context.contains(CmsPreprocessAction.TOKEN) && ApplicationConcurrentTimePreprocessAction.match(currentLogLine, priorLogLine)) { ApplicationConcurrentTimePreprocessAction action = new ApplicationConcurrentTimePreprocessAction( currentLogLine, context); @@ -346,8 +359,9 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin preprocessedLogLine = action.getLogEntry(); } } else if (!context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) - && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(SerialPreprocessAction.TOKEN) - && !context.contains(ParallelPreprocessAction.TOKEN) && !context.contains(CmsPreprocessAction.TOKEN) + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) + && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) + && !context.contains(CmsPreprocessAction.TOKEN) && ApplicationStoppedTimePreprocessAction.match(currentLogLine, priorLogLine)) { ApplicationStoppedTimePreprocessAction action = new ApplicationStoppedTimePreprocessAction(currentLogLine, context); @@ -357,7 +371,7 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) && !context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) && !context.contains(SerialPreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) - && !context.contains(CmsPreprocessAction.TOKEN) + && !context.contains(CmsPreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) && G1PreprocessAction.match(currentLogLine, priorLogLine, nextLogLine)) { G1PreprocessAction action = new G1PreprocessAction(priorLogLine, currentLogLine, nextLogLine, entangledLogLines, context); @@ -367,7 +381,8 @@ private String getPreprocessedLogEntry(String currentLogLine, String priorLogLin } else if (!context.contains(ApplicationStoppedTimePreprocessAction.TOKEN) && !context.contains(ApplicationConcurrentTimePreprocessAction.TOKEN) && !context.contains(ParallelPreprocessAction.TOKEN) && !context.contains(CmsPreprocessAction.TOKEN) - && !context.contains(G1PreprocessAction.TOKEN) && SerialPreprocessAction.match(currentLogLine)) { + && !context.contains(G1PreprocessAction.TOKEN) && !context.contains(UnifiedG1PreprocessAction.TOKEN) + && SerialPreprocessAction.match(currentLogLine)) { SerialPreprocessAction action = new SerialPreprocessAction(priorLogLine, currentLogLine, nextLogLine, entangledLogLines, context); if (action.getLogEntry() != null) { @@ -640,19 +655,22 @@ public void store(File logFile, boolean reorder) { } // 15) Inverted parallelism - if (event instanceof ParallelEvent) { - jvmDao.setParallelCount(jvmDao.getParallelCount() + 1); - if (event instanceof TimesData && ((TimesData) event).getTimeUser() > 0 - && JdkMath.isInvertedParallelism(((TimesData) event).getParallelism())) { - jvmDao.setInvertedParallelismCount(jvmDao.getInvertedParallelismCount() + 1); - if (jvmDao.getWorstInvertedParallelismEvent() == null) { - jvmDao.setWorstInvertedParallelismEvent(event); - } else { - if (((TimesData) event) - .getParallelism() < ((TimesData) jvmDao.getWorstInvertedParallelismEvent()) - .getParallelism()) { - // Update lowest "low" + if (event instanceof ParallelEvent && event instanceof TimesData) { + if (((TimesData) event).getTimeUser() != TimesData.NO_DATA + && ((TimesData) event).getTimeReal() != TimesData.NO_DATA) { + jvmDao.setParallelCount(jvmDao.getParallelCount() + 1); + if (event instanceof TimesData && ((TimesData) event).getTimeUser() > 0 + && JdkMath.isInvertedParallelism(((TimesData) event).getParallelism())) { + jvmDao.setInvertedParallelismCount(jvmDao.getInvertedParallelismCount() + 1); + if (jvmDao.getWorstInvertedParallelismEvent() == null) { jvmDao.setWorstInvertedParallelismEvent(event); + } else { + if (((TimesData) event) + .getParallelism() < ((TimesData) jvmDao.getWorstInvertedParallelismEvent()) + .getParallelism()) { + // Update lowest "low" + jvmDao.setWorstInvertedParallelismEvent(event); + } } } } diff --git a/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkRegEx.java b/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkRegEx.java index 1a60dacf..5fd303fd 100644 --- a/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkRegEx.java +++ b/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkRegEx.java @@ -113,9 +113,9 @@ public class JdkRegEx { /** * The duration of the event in milliseconds with 3 decimal places, introduced JDK9. * - * For example: 2.969ms + * For example: 2.969ms, 0.2ms */ - public static final String DURATION_JDK9 = "(\\d{1,7}[\\.\\,]\\d{3})ms"; + public static final String DURATION_JDK9 = "(\\d{1,7}[\\.\\,]\\d{1,3})ms"; /** * The garbage collection event number in JDK9+ unified logging. diff --git a/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkUtil.java b/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkUtil.java index 5a1125b5..567c7f9b 100644 --- a/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkUtil.java +++ b/src/main/java/org/eclipselabs/garbagecat/util/jdk/JdkUtil.java @@ -61,9 +61,14 @@ import org.eclipselabs.garbagecat.domain.jdk.ThreadDumpEvent; import org.eclipselabs.garbagecat.domain.jdk.VerboseGcOldEvent; import org.eclipselabs.garbagecat.domain.jdk.VerboseGcYoungEvent; +import org.eclipselabs.garbagecat.domain.jdk.unified.FooterHeapEvent; +import org.eclipselabs.garbagecat.domain.jdk.unified.HeapAddressEvent; +import org.eclipselabs.garbagecat.domain.jdk.unified.HeapRegionSizeEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedCmsConcurrentEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedCmsInitialMarkEvent; +import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedG1CleanupEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedG1ConcurrentEvent; +import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedG1YoungPauseEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedOldEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedRemarkEvent; import org.eclipselabs.garbagecat.domain.jdk.unified.UnifiedYoungEvent; @@ -88,34 +93,37 @@ public class JdkUtil { * Defined logging events. */ public enum LogEventType { - SERIAL_NEW, SERIAL_OLD, - // - PAR_NEW, PARALLEL_SCAVENGE, PARALLEL_SERIAL_OLD, PARALLEL_COMPACTING_OLD, - // + // unified UNIFIED_YOUNG, UNIFIED_OLD, // - UNIFIED_REMARK, UNIFIED_CMS_INITIAL_MARK, UNIFIED_CMS_CONCURRENT, UNIFIED_G1_CONCURRENT, + UNIFIED_REMARK, UNIFIED_CMS_INITIAL_MARK, UNIFIED_CMS_CONCURRENT, // - CMS_SERIAL_OLD, CMS_REMARK, CMS_INITIAL_MARK, CMS_CONCURRENT, + UNIFIED_G1_YOUNG_PAUSE, UNIFIED_G1_CLEANUP, UNIFIED_G1_CONCURRENT, // + USING_SERIAL, USING_PARALLEL, USING_CMS, USING_G1, FOOTER_HEAP, HEAP_REGION_SIZE, HEAP_ADDRESS, + // serial + SERIAL_NEW, SERIAL_OLD, + // parallel + PAR_NEW, PARALLEL_SCAVENGE, PARALLEL_SERIAL_OLD, PARALLEL_COMPACTING_OLD, + // cms + CMS_SERIAL_OLD, CMS_REMARK, CMS_INITIAL_MARK, CMS_CONCURRENT, + // g1 G1_YOUNG_PAUSE, G1_MIXED_PAUSE, G1_CONCURRENT, G1_YOUNG_INITIAL_MARK, G1_REMARK, G1_CLEANUP, G1_FULL_GC, - // + // other APPLICATION_CONCURRENT_TIME, APPLICATION_STOPPED_TIME, UNKNOWN, VERBOSE_GC_YOUNG, VERBOSE_GC_OLD, // HEADER_COMMAND_LINE_FLAGS, HEADER_MEMORY, HEADER_VERSION, REFERENCE_GC, CLASS_HISTOGRAM, HEAP_AT_GC, // CLASS_UNLOADING, APPLICATION_LOGGING, THREAD_DUMP, BLANK_LINE, GC_OVERHEAD_LIMIT, LOG_FILE, FLS_STATISTICS, // - GC_LOCKER, TENURING_DISTRIBUTION, - // - USING_SERIAL, USING_PARALLEL, USING_CMS, USING_G1 + GC_LOCKER, TENURING_DISTRIBUTION }; /** * Defined preprocessing actions. */ public enum PreprocessActionType { - APPLICATION_CONCURRENT_TIME, APPLICATION_STOPPED_TIME, DATE_STAMP, G1, CMS, PARALLEL, SERIAL + APPLICATION_CONCURRENT_TIME, APPLICATION_STOPPED_TIME, DATE_STAMP, G1, CMS, PARALLEL, SERIAL, UNIFIED_G1 }; /** @@ -155,12 +163,22 @@ private JdkUtil() { public static final LogEventType identifyEventType(String logLine) { // Unified (alphabetical) + if (FooterHeapEvent.match(logLine)) + return LogEventType.FOOTER_HEAP; + if (HeapAddressEvent.match(logLine)) + return LogEventType.HEAP_ADDRESS; + if (HeapRegionSizeEvent.match(logLine)) + return LogEventType.HEAP_REGION_SIZE; if (UnifiedCmsConcurrentEvent.match(logLine)) return LogEventType.UNIFIED_CMS_CONCURRENT; if (UnifiedCmsInitialMarkEvent.match(logLine)) return LogEventType.UNIFIED_CMS_INITIAL_MARK; + if (UnifiedG1CleanupEvent.match(logLine)) + return LogEventType.UNIFIED_G1_CLEANUP; if (UnifiedG1ConcurrentEvent.match(logLine)) return LogEventType.UNIFIED_G1_CONCURRENT; + if (UnifiedG1YoungPauseEvent.match(logLine)) + return LogEventType.UNIFIED_G1_YOUNG_PAUSE; if (UnifiedOldEvent.match(logLine)) return LogEventType.UNIFIED_OLD; if (UnifiedRemarkEvent.match(logLine)) @@ -286,14 +304,29 @@ public static final LogEvent parseLogLine(String logLine) { LogEvent event = null; switch (eventType) { // Unified (alphabetical) + case FOOTER_HEAP: + event = new FooterHeapEvent(logLine); + break; + case HEAP_ADDRESS: + event = new HeapAddressEvent(logLine); + break; + case HEAP_REGION_SIZE: + event = new HeapRegionSizeEvent(logLine); + break; case UNIFIED_CMS_CONCURRENT: event = new UnifiedCmsConcurrentEvent(); break; case UNIFIED_CMS_INITIAL_MARK: event = new UnifiedCmsInitialMarkEvent(logLine); break; + case UNIFIED_G1_CLEANUP: + event = new UnifiedG1CleanupEvent(logLine); + break; case UNIFIED_G1_CONCURRENT: - event = new UnifiedG1ConcurrentEvent(logLine); + event = new UnifiedG1ConcurrentEvent(); + break; + case UNIFIED_G1_YOUNG_PAUSE: + event = new UnifiedG1YoungPauseEvent(logLine); break; case UNIFIED_OLD: event = new UnifiedOldEvent(logLine); @@ -339,6 +372,7 @@ public static final LogEvent parseLogLine(String logLine) { case G1_YOUNG_PAUSE: event = new G1YoungPauseEvent(logLine); break; + // CMS case PAR_NEW: event = new ParNewEvent(logLine); @@ -355,6 +389,7 @@ public static final LogEvent parseLogLine(String logLine) { case CMS_SERIAL_OLD: event = new CmsSerialOldEvent(logLine); break; + // Parallel case PARALLEL_COMPACTING_OLD: event = new ParallelCompactingOldEvent(logLine); @@ -365,6 +400,7 @@ public static final LogEvent parseLogLine(String logLine) { case PARALLEL_SERIAL_OLD: event = new ParallelSerialOldEvent(logLine); break; + // Serial case SERIAL_NEW: event = new SerialNewEvent(logLine); @@ -372,6 +408,7 @@ public static final LogEvent parseLogLine(String logLine) { case SERIAL_OLD: event = new SerialOldEvent(logLine); break; + // Other case APPLICATION_CONCURRENT_TIME: event = new ApplicationConcurrentTimeEvent(); @@ -456,9 +493,13 @@ public static final BlockingEvent hydrateBlockingEvent(LogEventType eventType, S int duration) { BlockingEvent event = null; switch (eventType) { - // Unified - case UNIFIED_YOUNG: - event = new UnifiedYoungEvent(logEntry, timestamp, duration); + + // Unified (alphabetical) + case UNIFIED_CMS_INITIAL_MARK: + event = new UnifiedCmsInitialMarkEvent(logEntry, timestamp, duration); + break; + case UNIFIED_G1_CLEANUP: + event = new UnifiedG1CleanupEvent(logEntry, timestamp, duration); break; case UNIFIED_OLD: event = new UnifiedOldEvent(logEntry, timestamp, duration); @@ -466,8 +507,11 @@ public static final BlockingEvent hydrateBlockingEvent(LogEventType eventType, S case UNIFIED_REMARK: event = new UnifiedRemarkEvent(logEntry, timestamp, duration); break; - case UNIFIED_CMS_INITIAL_MARK: - event = new UnifiedCmsInitialMarkEvent(logEntry, timestamp, duration); + case UNIFIED_YOUNG: + event = new UnifiedYoungEvent(logEntry, timestamp, duration); + break; + case UNIFIED_G1_YOUNG_PAUSE: + event = new UnifiedG1YoungPauseEvent(logEntry, timestamp, duration); break; // G1 @@ -549,13 +593,16 @@ public static final boolean isBlocking(LogEventType eventType) { case CLASS_UNLOADING: case CMS_CONCURRENT: case FLS_STATISTICS: + case FOOTER_HEAP: case GC_LOCKER: case GC_OVERHEAD_LIMIT: case G1_CONCURRENT: case HEADER_COMMAND_LINE_FLAGS: case HEADER_MEMORY: case HEADER_VERSION: + case HEAP_ADDRESS: case HEAP_AT_GC: + case HEAP_REGION_SIZE: case LOG_FILE: case REFERENCE_GC: case THREAD_DUMP: @@ -843,14 +890,17 @@ public static final boolean isReportable(LogEventType eventType) { case CLASS_HISTOGRAM: case CLASS_UNLOADING: case FLS_STATISTICS: + case FOOTER_HEAP: case GC_LOCKER: case GC_OVERHEAD_LIMIT: case HEADER_COMMAND_LINE_FLAGS: case HEADER_MEMORY: case HEADER_VERSION: + case HEAP_ADDRESS: case HEAP_AT_GC: - case REFERENCE_GC: + case HEAP_REGION_SIZE: case LOG_FILE: + case REFERENCE_GC: case UNKNOWN: reportable = false; break; @@ -873,9 +923,14 @@ public static final boolean isUnifiedLogging(List eventTypes) { while (iterator.hasNext() && !isUnifiedLogging) { LogEventType eventType = iterator.next(); switch (eventType) { + case FOOTER_HEAP: + case HEAP_ADDRESS: + case HEAP_REGION_SIZE: case UNIFIED_CMS_CONCURRENT: case UNIFIED_CMS_INITIAL_MARK: + case UNIFIED_G1_CLEANUP: case UNIFIED_G1_CONCURRENT: + case UNIFIED_G1_YOUNG_PAUSE: case UNIFIED_OLD: case UNIFIED_REMARK: case UNIFIED_YOUNG: diff --git a/src/test/data/.gitignore b/src/test/data/.gitignore index f875cf96..1ccbe57f 100644 --- a/src/test/data/.gitignore +++ b/src/test/data/.gitignore @@ -151,3 +151,6 @@ /dataset152.txt.pp /dataset153.txt.pp /dataset154.txt.pp +/dataset155.txt.pp +/dataset156.txt.pp +/dataset157.txt.pp diff --git a/src/test/data/dataset155.txt b/src/test/data/dataset155.txt new file mode 100644 index 00000000..072649ab --- /dev/null +++ b/src/test/data/dataset155.txt @@ -0,0 +1,13 @@ +[0.369s][info][gc,start ] GC(6) Pause Young (Normal) (G1 Evacuation Pause) +[0.369s][info][gc,task ] GC(6) Using 2 workers of 4 for evacuation +[0.370s][info][gc,phases ] GC(6) Pre Evacuate Collection Set: 0.0ms +[0.370s][info][gc,phases ] GC(6) Evacuate Collection Set: 0.7ms +[0.370s][info][gc,phases ] GC(6) Post Evacuate Collection Set: 0.1ms +[0.370s][info][gc,phases ] GC(6) Other: 0.1ms +[0.370s][info][gc,heap ] GC(6) Eden regions: 1->0(1) +[0.370s][info][gc,heap ] GC(6) Survivor regions: 1->1(1) +[0.370s][info][gc,heap ] GC(6) Old regions: 3->3 +[0.370s][info][gc,heap ] GC(6) Humongous regions: 0->0 +[0.370s][info][gc,metaspace ] GC(6) Metaspace: 9085K->9085K(1058816K) +[0.370s][info][gc ] GC(6) Pause Young (Normal) (G1 Evacuation Pause) 3M->2M(7M) 0.929ms +[0.370s][info][gc,cpu ] GC(6) User=0.01s Sys=0.00s Real=0.01s \ No newline at end of file diff --git a/src/test/data/dataset156.txt b/src/test/data/dataset156.txt new file mode 100644 index 00000000..137cf92b --- /dev/null +++ b/src/test/data/dataset156.txt @@ -0,0 +1,4 @@ +[16.051s][info][gc,start ] GC(969) Pause Remark +[16.053s][info][gc,stringtable] GC(969) Cleaned string and symbol table, strings: 5786 processed, 4 removed, symbols: 38663 processed, 11 removed +[16.053s][info][gc ] GC(969) Pause Remark 29M->29M(46M) 2.328ms +[16.053s][info][gc,cpu ] GC(969) User=0.01s Sys=0.00s Real=0.00s \ No newline at end of file diff --git a/src/test/data/dataset157.txt b/src/test/data/dataset157.txt new file mode 100644 index 00000000..a6b97968 --- /dev/null +++ b/src/test/data/dataset157.txt @@ -0,0 +1,3 @@ +[16.081s][info][gc,start ] GC(969) Pause Cleanup +[16.082s][info][gc ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms +[16.082s][info][gc,cpu ] GC(969) User=0.00s Sys=0.00s Real=0.00s \ No newline at end of file diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestCmsInitialMarkEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestCmsInitialMarkEvent.java index e1fac4cf..e9d8a602 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestCmsInitialMarkEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestCmsInitialMarkEvent.java @@ -12,7 +12,11 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.domain.jdk.unified; +import java.util.ArrayList; +import java.util.List; + import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; import junit.framework.Assert; import junit.framework.TestCase; @@ -25,29 +29,48 @@ public class TestCmsInitialMarkEvent extends TestCase { public void testLogLine() { String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms"; - Assert.assertTrue("Log line not recognized as CMS Initial Mark event.", + Assert.assertTrue( + "Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + ".", UnifiedCmsInitialMarkEvent.match(logLine)); UnifiedCmsInitialMarkEvent event = new UnifiedCmsInitialMarkEvent(logLine); Assert.assertEquals("Time stamp not parsed correctly.", 178 - 0, event.getTimestamp()); Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); } - public void testLogLineWhitespaceAtEnd() { - String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms "; - Assert.assertTrue( - "Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + ".", - UnifiedCmsInitialMarkEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms"; Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK + "not identified.", JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK, JdkUtil.identifyEventType(logLine)); } - public void testIsBlocking() { + public void testParseLogLine() { + String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedCmsInitialMarkEvent); + } + + public void testBlocking() { String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms"; Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + " not indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_CMS_INITIAL_MARK); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[0.178s][info][gc] GC(5) Pause Initial Mark 1M->1M(2M) 0.157ms "; + Assert.assertTrue( + "Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_CMS_INITIAL_MARK.toString() + ".", + UnifiedCmsInitialMarkEvent.match(logLine)); + } } diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestFooterHeapEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestFooterHeapEvent.java new file mode 100644 index 00000000..3ba03f56 --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestFooterHeapEvent.java @@ -0,0 +1,92 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.ArrayList; +import java.util.List; + +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestFooterHeapEvent extends TestCase { + + public void testLineHeap() { + String logLine = "[25.016s][info][gc,heap,exit ] Heap"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.FOOTER_HEAP.toString() + ".", + FooterHeapEvent.match(logLine)); + } + + public void testIdentityEventType() { + String logLine = "[25.016s][info][gc,heap,exit ] Heap"; + Assert.assertEquals(JdkUtil.LogEventType.FOOTER_HEAP + "not identified.", JdkUtil.LogEventType.FOOTER_HEAP, + JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[25.016s][info][gc,heap,exit ] Heap"; + Assert.assertTrue(JdkUtil.LogEventType.FOOTER_HEAP.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof FooterHeapEvent); + } + + public void testNotBlocking() { + String logLine = "[25.016s][info][gc,heap,exit ] Heap"; + Assert.assertFalse(JdkUtil.LogEventType.FOOTER_HEAP.toString() + " incorrectly indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertFalse(JdkUtil.LogEventType.FOOTER_HEAP.toString() + " incorrectly indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.FOOTER_HEAP)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.FOOTER_HEAP); + Assert.assertTrue(JdkUtil.LogEventType.FOOTER_HEAP.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLineGarbageFirst() { + String logLine = "[25.016s][info][gc,heap,exit ] garbage-first heap total 59392K, used 38015K " + + "[0x00000000fc000000, 0x0000000100000000)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.FOOTER_HEAP.toString() + ".", + FooterHeapEvent.match(logLine)); + } + + public void testLineRegion() { + String logLine = "[25.016s][info][gc,heap,exit ] region size 1024K, 13 young (13312K), 1 survivors (1024K)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.FOOTER_HEAP.toString() + ".", + FooterHeapEvent.match(logLine)); + } + + public void testLineMetaspace() { + String logLine = "[25.016s][info][gc,heap,exit ] Metaspace used 11079K, capacity 11287K, " + + "committed 11520K, reserved 1060864K"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.FOOTER_HEAP.toString() + ".", + FooterHeapEvent.match(logLine)); + } + + public void testLineClass() { + String logLine = "[25.016s][info][gc,heap,exit ] class space used 909K, capacity 995K, committed 1024K, " + + "reserved 1048576K"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.FOOTER_HEAP.toString() + ".", + FooterHeapEvent.match(logLine)); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapAddressEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapAddressEvent.java new file mode 100644 index 00000000..95d6929b --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapAddressEvent.java @@ -0,0 +1,69 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.ArrayList; +import java.util.List; + +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestHeapAddressEvent extends TestCase { + + public void testLogLine() { + String logLine = "[0.004s][info][gc,heap,coops] Heap address: 0x00000000fc000000, size: 64 MB, " + + "Compressed Oops mode: 32-bit"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.HEAP_ADDRESS.toString() + ".", + HeapAddressEvent.match(logLine)); + } + + public void testIdentityEventType() { + String logLine = "[0.004s][info][gc,heap,coops] Heap address: 0x00000000fc000000, size: 64 MB, " + + "Compressed Oops mode: 32-bit"; + Assert.assertEquals(JdkUtil.LogEventType.HEAP_ADDRESS + "not identified.", JdkUtil.LogEventType.HEAP_ADDRESS, + JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[0.004s][info][gc,heap,coops] Heap address: 0x00000000fc000000, size: 64 MB, " + + "Compressed Oops mode: 32-bit"; + Assert.assertTrue(JdkUtil.LogEventType.HEAP_ADDRESS.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof HeapAddressEvent); + } + + public void testNotBlocking() { + String logLine = "[0.004s][info][gc,heap,coops] Heap address: 0x00000000fc000000, size: 64 MB, " + + "Compressed Oops mode: 32-bit"; + Assert.assertFalse(JdkUtil.LogEventType.HEAP_ADDRESS.toString() + " incorrectly indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertFalse(JdkUtil.LogEventType.HEAP_ADDRESS.toString() + " incorrectly indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.HEAP_ADDRESS)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.HEAP_ADDRESS); + Assert.assertTrue(JdkUtil.LogEventType.HEAP_ADDRESS.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapRegionSizeEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapRegionSizeEvent.java new file mode 100644 index 00000000..3f86c5aa --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestHeapRegionSizeEvent.java @@ -0,0 +1,65 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.ArrayList; +import java.util.List; + +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestHeapRegionSizeEvent extends TestCase { + + public void testLine() { + String logLine = "[0.003s][info][gc,heap] Heap region size: 1M"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.HEAP_REGION_SIZE.toString() + ".", + HeapRegionSizeEvent.match(logLine)); + } + + public void testIdentityEventType() { + String logLine = "[0.003s][info][gc,heap] Heap region size: 1M"; + Assert.assertEquals(JdkUtil.LogEventType.HEAP_REGION_SIZE + "not identified.", + JdkUtil.LogEventType.HEAP_REGION_SIZE, JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[0.003s][info][gc,heap] Heap region size: 1M"; + Assert.assertTrue(JdkUtil.LogEventType.HEAP_REGION_SIZE.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof HeapRegionSizeEvent); + } + + public void testNotBlocking() { + String logLine = "[25.016s][info][gc,heap,exit ] Heap"; + Assert.assertFalse(JdkUtil.LogEventType.HEAP_REGION_SIZE.toString() + " incorrectly indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertFalse(JdkUtil.LogEventType.HEAP_REGION_SIZE.toString() + " incorrectly indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.HEAP_REGION_SIZE)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.HEAP_REGION_SIZE); + Assert.assertTrue(JdkUtil.LogEventType.HEAP_REGION_SIZE.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedCmsConcurrentEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedCmsConcurrentEvent.java index e2947f2f..8dee738f 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedCmsConcurrentEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedCmsConcurrentEvent.java @@ -12,7 +12,11 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.domain.jdk.unified; +import java.util.ArrayList; +import java.util.List; + import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; import junit.framework.Assert; import junit.framework.TestCase; @@ -29,6 +33,37 @@ public void testConcurrentMark() { UnifiedCmsConcurrentEvent.match(logLine)); } + public void testIdentityEventType() { + String logLine = "[0.082s][info][gc] GC(1) Concurrent Mark"; + Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT + "not identified.", + JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT, JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[0.082s][info][gc] GC(1) Concurrent Mark"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedCmsConcurrentEvent); + } + + public void testNotBlocking() { + String logLine = "[0.082s][info][gc] GC(1) Concurrent Mark"; + Assert.assertFalse( + JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + " incorrectly indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_CMS_CONCURRENT); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + public void testConcurrentMarkWithDuration() { String logLine = "[0.083s][info][gc] GC(1) Concurrent Mark 1.428ms"; Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + ".", @@ -70,18 +105,4 @@ public void testConcurrentResetWithDuration() { Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + ".", UnifiedCmsConcurrentEvent.match(logLine)); } - - public void testIdentity() { - String logLine = "[0.082s][info][gc] GC(1) Concurrent Mark"; - Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT + "not identified.", - JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT, JdkUtil.identifyEventType(logLine)); - } - - public void testNotBlocking() { - String logLine = "[0.082s][info][gc] GC(1) Concurrent Mark"; - Assert.assertFalse( - JdkUtil.LogEventType.UNIFIED_CMS_CONCURRENT.toString() + " incorrectly indentified as blocking.", - JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); - } - } diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1CleanupEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1CleanupEvent.java new file mode 100644 index 00000000..fd565e58 --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1CleanupEvent.java @@ -0,0 +1,97 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.ArrayList; +import java.util.List; + +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestUnifiedG1CleanupEvent extends TestCase { + + public void testLogLine() { + String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + ".", + UnifiedG1CleanupEvent.match(logLine)); + UnifiedG1CleanupEvent event = new UnifiedG1CleanupEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 15101 - 0, event.getTimestamp()); + Assert.assertEquals("Combined begin size not parsed correctly.", 30 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 30 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 44 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); + } + + public void testIdentityEventType() { + String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms"; + Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP + "not identified.", + JdkUtil.LogEventType.UNIFIED_G1_CLEANUP, JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedG1CleanupEvent); + } + + public void testIsBlocking() { + String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + " not indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_G1_CLEANUP); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + ".", + UnifiedG1CleanupEvent.match(logLine)); + } + + public void testLogLinePreprocessed() { + String logLine = "[16.082s][info][gc ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms " + + "User=0.00s Sys=0.00s Real=0.00s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + ".", + UnifiedG1CleanupEvent.match(logLine)); + UnifiedG1CleanupEvent event = new UnifiedG1CleanupEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 16082 - 0, event.getTimestamp()); + Assert.assertEquals("Combined begin size not parsed correctly.", 28 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 28 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 46 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); + Assert.assertEquals("User time not parsed correctly.", 0, event.getTimeUser()); + Assert.assertEquals("Real time not parsed correctly.", 0, event.getTimeReal()); + Assert.assertEquals("Parallelism not calculated correctly.", 100, event.getParallelism()); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1ConcurrentEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1ConcurrentEvent.java index e2d0f9b1..e2e9b4d0 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1ConcurrentEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1ConcurrentEvent.java @@ -12,7 +12,11 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.domain.jdk.unified; +import java.util.ArrayList; +import java.util.List; + import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; import junit.framework.Assert; import junit.framework.TestCase; @@ -22,40 +26,142 @@ */ public class TestUnifiedG1ConcurrentEvent extends TestCase { - public void testLogLineConcurrentCycle() { + public void testLogLine() { String logLine = "[14.859s][info][gc] GC(1083) Concurrent Cycle"; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.G1_CONCURRENT.toString() + ".", - UnifiedG1ConcurrentEvent.match(logLine)); - UnifiedG1ConcurrentEvent event = new UnifiedG1ConcurrentEvent(logLine); - Assert.assertEquals("Time stamp not parsed correctly.", 14859, event.getTimestamp()); - } - - public void testLogLineConcurrentCycleWithDuration() { - String logLine = "[14.904s][info][gc] GC(1083) Concurrent Cycle 45.374ms"; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.G1_CONCURRENT.toString() + ".", + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", UnifiedG1ConcurrentEvent.match(logLine)); - UnifiedG1ConcurrentEvent event = new UnifiedG1ConcurrentEvent(logLine); - Assert.assertEquals("Time stamp not parsed correctly.", 14904 - 45, event.getTimestamp()); } - public void testLogLineConcurrentPauseCleanup() { - String logLine = "[15.101s][info][gc] GC(1099) Pause Cleanup 30M->30M(44M) 0.058ms"; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.G1_CONCURRENT.toString() + ".", - UnifiedG1ConcurrentEvent.match(logLine)); - UnifiedG1ConcurrentEvent event = new UnifiedG1ConcurrentEvent(logLine); - Assert.assertEquals("Time stamp not parsed correctly.", 15101 - 0, event.getTimestamp()); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[14.859s][info][gc] GC(1083) Concurrent Cycle"; Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT + "not identified.", JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[14.859s][info][gc] GC(1083) Concurrent Cycle"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedG1ConcurrentEvent); + } + public void testNotBlocking() { String logLine = "[14.859s][info][gc] GC(1083) Concurrent Cycle"; Assert.assertFalse( JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + " incorrectly indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_G1_CONCURRENT); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineCycleWithDuration() { + String logLine = "[14.904s][info][gc] GC(1083) Concurrent Cycle 45.374ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testCycleDetailed() { + String logLine = "[16.601s][info][gc ] GC(1033) Concurrent Cycle"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testCycleDetailed12Spaces() { + String logLine = "[16.121s][info][gc ] GC(974) Concurrent Cycle"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testCycleDetailedWithDuration() { + String logLine = "[16.082s][info][gc ] GC(969) Concurrent Cycle 65.746ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testClearClaimedMarks() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Clear Claimed Marks"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testClearClaimedMarksWithDuration() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Clear Claimed Marks 0.019ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testScanRootRegions() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Scan Root Regions"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testScanRootRegionsWithDuration() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Scan Root Regions 0.283ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testMarkTimestamp() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Mark (16.601s)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testMarkDoubleTimestampWithDuration() { + String logLine = "[16.050s][info][gc,marking ] GC(969) Concurrent Mark (16.017s, 16.050s) 33.614ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testUsingWorkersForMarking() { + String logLine = "[16.601s][info][gc,marking ] GC(1033) Concurrent Mark From Roots"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testMarkFromRoots() { + String logLine = "[16.601s][info][gc,task ] GC(1033) Using 1 workers of 1 for marking"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testPreclean() { + String logLine = "[16.601s][info][gc,task ] GC(1033) Using 1 workers of 1 for marking"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testPrecleanWithDuration() { + String logLine = "[16.050s][info][gc,marking ] GC(969) Concurrent Preclean 0.115ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testRebuildRememberedSets() { + String logLine = "[16.053s][info][gc,marking ] GC(969) Concurrent Rebuild Remembered Sets"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testCleanupForNextMark() { + String logLine = "[16.082s][info][gc,marking ] GC(969) Concurrent Cleanup for Next Mark"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } + + public void testCleanupForNextMarkWithDuration() { + String logLine = "[16.082s][info][gc,marking ] GC(969) Concurrent Cleanup for Next Mark 0.428ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_CONCURRENT.toString() + ".", + UnifiedG1ConcurrentEvent.match(logLine)); + } } diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1YoungPauseEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1YoungPauseEvent.java new file mode 100644 index 00000000..74a27d64 --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedG1YoungPauseEvent.java @@ -0,0 +1,144 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.domain.jdk.unified; + +import java.util.ArrayList; +import java.util.List; + +import org.eclipselabs.garbagecat.util.jdk.JdkRegEx; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestUnifiedG1YoungPauseEvent extends TestCase { + + public void testLogLine() { + String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " + + "43M->26M(52M) 0.941ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + ".", + UnifiedG1YoungPauseEvent.match(logLine)); + UnifiedG1YoungPauseEvent event = new UnifiedG1YoungPauseEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 27091 - 0, event.getTimestamp()); + Assert.assertTrue("Trigger not parsed correctly.", + event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); + Assert.assertEquals("Combined begin size not parsed correctly.", 43 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 26 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 52 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); + } + + public void testIdentityEventType() { + String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " + + "43M->26M(52M) 0.941ms"; + Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE + "not identified.", + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE, JdkUtil.identifyEventType(logLine)); + } + + public void testParseLogLine() { + String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " + + "43M->26M(52M) 0.941ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedG1YoungPauseEvent); + } + + public void testIsBlocking() { + String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " + + "43M->26M(52M) 0.941ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + " not indentified as blocking.", + JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); + } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_G1_YOUNG_PAUSE); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " + + "43M->26M(52M) 0.941ms "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + ".", + UnifiedG1YoungPauseEvent.match(logLine)); + } + + public void testConcurrentStartCollectionTriggerEvacuationPause() { + String logLine = "[22.879s][info][gc] GC(1277) Pause Young (Concurrent Start) (G1 Evacuation Pause)" + + " 43M->23M(52M) 1.100ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + ".", + UnifiedG1YoungPauseEvent.match(logLine)); + UnifiedG1YoungPauseEvent event = new UnifiedG1YoungPauseEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 22879 - 1, event.getTimestamp()); + Assert.assertTrue("Trigger not parsed correctly.", + event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); + Assert.assertEquals("Combined begin size not parsed correctly.", 43 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 23 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 52 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 1, event.getDuration()); + } + + public void testLogLinePreprocessed() { + String logLine = "[0.370s][info][gc ] GC(6) Pause Young (Normal) (G1 Evacuation Pause) 3M->2M(7M) " + + "0.929ms User=0.01s Sys=0.00s Real=0.01s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + ".", + UnifiedG1YoungPauseEvent.match(logLine)); + UnifiedG1YoungPauseEvent event = new UnifiedG1YoungPauseEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 370 - 0, event.getTimestamp()); + Assert.assertTrue("Trigger not parsed correctly.", + event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); + Assert.assertEquals("Combined begin size not parsed correctly.", 3 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 2 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 7 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); + Assert.assertEquals("User time not parsed correctly.", 1, event.getTimeUser()); + Assert.assertEquals("Real time not parsed correctly.", 1, event.getTimeReal()); + Assert.assertEquals("Parallelism not calculated correctly.", 100, event.getParallelism()); + } + + public void testLogLinePreprocessed12Spaces() { + String logLine = "[16.072s][info][gc ] GC(971) Pause Young (Normal) (G1 Evacuation Pause) " + + "38M->20M(46M) 2.040ms User=0.00s Sys=0.00s Real=0.01s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + ".", + UnifiedG1YoungPauseEvent.match(logLine)); + UnifiedG1YoungPauseEvent event = new UnifiedG1YoungPauseEvent(logLine); + Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString(), + event.getName()); + Assert.assertEquals("Time stamp not parsed correctly.", 16072 - 2, event.getTimestamp()); + Assert.assertTrue("Trigger not parsed correctly.", + event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); + Assert.assertEquals("Combined begin size not parsed correctly.", 38 * 1024, event.getCombinedOccupancyInit()); + Assert.assertEquals("Combined end size not parsed correctly.", 20 * 1024, event.getCombinedOccupancyEnd()); + Assert.assertEquals("Combined allocation size not parsed correctly.", 46 * 1024, event.getCombinedSpace()); + Assert.assertEquals("Duration not parsed correctly.", 2, event.getDuration()); + Assert.assertEquals("User time not parsed correctly.", 0, event.getTimeUser()); + Assert.assertEquals("Real time not parsed correctly.", 1, event.getTimeReal()); + Assert.assertEquals("Parallelism not calculated correctly.", 0, event.getParallelism()); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedOldEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedOldEvent.java index 9b18b5e4..5ec13e41 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedOldEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedOldEvent.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -46,24 +48,42 @@ public void testLogLine() { Assert.assertEquals("Duration not parsed correctly.", 2, event.getDuration()); } - public void testLogLineWhitespaceAtEnd() { - String logLine = "[0.231s][info][gc] GC(6) Pause Full (Ergonomics) 1M->1M(7M) 2.969ms "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_OLD.toString() + ".", - UnifiedOldEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.231s][info][gc] GC(6) Pause Full (Ergonomics) 1M->1M(7M) 2.969ms"; Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_OLD + "not identified.", JdkUtil.LogEventType.UNIFIED_OLD, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[0.231s][info][gc] GC(6) Pause Full (Ergonomics) 1M->1M(7M) 2.969ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_OLD.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedOldEvent); + } + public void testIsBlocking() { String logLine = "[0.231s][info][gc] GC(6) Pause Full (Ergonomics) 1M->1M(7M) 2.969ms"; Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_OLD.toString() + " not indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_OLD.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_OLD)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_OLD); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_OLD.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[0.231s][info][gc] GC(6) Pause Full (Ergonomics) 1M->1M(7M) 2.969ms "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_OLD.toString() + ".", + UnifiedOldEvent.match(logLine)); + } + public void testUnifiedOldStandardLogging() { // TODO: Create File in platform independent way. File testFile = new File("src/test/data/dataset148.txt"); diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedRemarkEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedRemarkEvent.java index d215fa63..65a0021d 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedRemarkEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedRemarkEvent.java @@ -12,7 +12,11 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.domain.jdk.unified; +import java.util.ArrayList; +import java.util.List; + import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; import junit.framework.Assert; import junit.framework.TestCase; @@ -32,21 +36,52 @@ public void testLogLine() { Assert.assertEquals("Duration not parsed correctly.", 1, event.getDuration()); } - public void testLogLineWhitespaceAtEnd() { - String logLine = "[7.944s][info][gc] GC(6432) Pause Remark 8M->8M(10M) 1.767ms "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_REMARK.toString() + ".", - UnifiedRemarkEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[7.944s][info][gc] GC(6432) Pause Remark 8M->8M(10M) 1.767ms"; Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_REMARK + "not identified.", JdkUtil.LogEventType.UNIFIED_REMARK, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[7.944s][info][gc] GC(6432) Pause Remark 8M->8M(10M) 1.767ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_REMARK.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedRemarkEvent); + } + public void testIsBlocking() { String logLine = "[7.944s][info][gc] GC(6432) Pause Remark 8M->8M(10M) 1.767ms"; Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_REMARK.toString() + " not indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_REMARK.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_REMARK)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_REMARK); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_REMARK.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[7.944s][info][gc] GC(6432) Pause Remark 8M->8M(10M) 1.767ms "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_REMARK.toString() + ".", + UnifiedRemarkEvent.match(logLine)); + } + + public void testLogLineDetailedPreprocessed() { + String logLine = "[16.053s][info][gc ] GC(969) Pause Remark 29M->29M(46M) 2.328ms " + + "User=0.01s Sys=0.00s Real=0.00s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_REMARK.toString() + ".", + UnifiedRemarkEvent.match(logLine)); + UnifiedRemarkEvent event = new UnifiedRemarkEvent(logLine); + Assert.assertEquals("Time stamp not parsed correctly.", 16053 - 2, event.getTimestamp()); + Assert.assertEquals("Duration not parsed correctly.", 2, event.getDuration()); + Assert.assertEquals("User time not parsed correctly.", 1, event.getTimeUser()); + Assert.assertEquals("Real time not parsed correctly.", 0, event.getTimeReal()); + Assert.assertEquals("Parallelism not calculated correctly.", Integer.MAX_VALUE, event.getParallelism()); + } } diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedYoungEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedYoungEvent.java index 2717ecdb..ccc38b7e 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedYoungEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUnifiedYoungEvent.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -47,24 +49,42 @@ public void testLogLine() { Assert.assertEquals("Duration not parsed correctly.", 1, event.getDuration()); } - public void testLogLineWhitespaceAtEnd() { - String logLine = "[1.102s][info][gc] GC(48) Pause Young (Allocation Failure) 23M->3M(25M) 0.409ms "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + ".", - UnifiedYoungEvent.match(logLine)); - } - - public void testIdentity() { - String logLine = "[1.102s][info][gc] GC(48) Pause Young (Allocation Failure) 23M->3M(25M) 0.409ms"; + public void testIdentityEventType() { + String logLine = "[9.602s][info][gc] GC(569) Pause Young (Allocation Failure) 32M->12M(38M) 1.812ms"; Assert.assertEquals(JdkUtil.LogEventType.UNIFIED_YOUNG + "not identified.", JdkUtil.LogEventType.UNIFIED_YOUNG, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[9.602s][info][gc] GC(569) Pause Young (Allocation Failure) 32M->12M(38M) 1.812ms"; + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UnifiedYoungEvent); + } + public void testIsBlocking() { - String logLine = "[1.102s][info][gc] GC(48) Pause Young (Allocation Failure) 23M->3M(25M) 0.409ms"; + String logLine = "[9.602s][info][gc] GC(569) Pause Young (Allocation Failure) 32M->12M(38M) 1.812ms"; Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + " not indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.UNIFIED_YOUNG)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.UNIFIED_YOUNG); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLogLineWhitespaceAtEnd() { + String logLine = "[1.102s][info][gc] GC(48) Pause Young (Allocation Failure) 23M->3M(25M) 0.409ms "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + ".", + UnifiedYoungEvent.match(logLine)); + } + public void testTriggerExplicitGc() { String logLine = "[7.487s][info][gc] GC(497) Pause Young (System.gc()) 16M->10M(36M) 0.940ms"; Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + ".", @@ -79,38 +99,6 @@ public void testTriggerExplicitGc() { Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); } - public void testG1NormalTriggerEvacuationPause() { - String logLine = "[27.091s][info][gc] GC(1515) Pause Young (Normal) (G1 Evacuation Pause) " - + "43M->26M(52M) 0.941ms"; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + ".", - UnifiedYoungEvent.match(logLine)); - UnifiedYoungEvent event = new UnifiedYoungEvent(logLine); - Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_YOUNG.toString(), event.getName()); - Assert.assertEquals("Time stamp not parsed correctly.", 27091 - 0, event.getTimestamp()); - Assert.assertTrue("Trigger not parsed correctly.", - event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); - Assert.assertEquals("Combined begin size not parsed correctly.", 43 * 1024, event.getCombinedOccupancyInit()); - Assert.assertEquals("Combined end size not parsed correctly.", 26 * 1024, event.getCombinedOccupancyEnd()); - Assert.assertEquals("Combined allocation size not parsed correctly.", 52 * 1024, event.getCombinedSpace()); - Assert.assertEquals("Duration not parsed correctly.", 0, event.getDuration()); - } - - public void testG1ConcurrentStartTriggerEvacuationPause() { - String logLine = "[22.879s][info][gc] GC(1277) Pause Young (Concurrent Start) (G1 Evacuation Pause)" - + " 43M->23M(52M) 1.100ms"; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.UNIFIED_YOUNG.toString() + ".", - UnifiedYoungEvent.match(logLine)); - UnifiedYoungEvent event = new UnifiedYoungEvent(logLine); - Assert.assertEquals("Event name incorrect.", JdkUtil.LogEventType.UNIFIED_YOUNG.toString(), event.getName()); - Assert.assertEquals("Time stamp not parsed correctly.", 22879 - 1, event.getTimestamp()); - Assert.assertTrue("Trigger not parsed correctly.", - event.getTrigger().matches(JdkRegEx.TRIGGER_G1_EVACUATION_PAUSE)); - Assert.assertEquals("Combined begin size not parsed correctly.", 43 * 1024, event.getCombinedOccupancyInit()); - Assert.assertEquals("Combined end size not parsed correctly.", 23 * 1024, event.getCombinedOccupancyEnd()); - Assert.assertEquals("Combined allocation size not parsed correctly.", 52 * 1024, event.getCombinedSpace()); - Assert.assertEquals("Duration not parsed correctly.", 1, event.getDuration()); - } - public void testUnifiedYoungStandardLogging() { // TODO: Create File in platform independent way. File testFile = new File("src/test/data/dataset149.txt"); @@ -129,7 +117,7 @@ public void testUnifiedYoungStandardLogging() { jvmRun.getAnalysis().contains(Analysis.WARN_APPLICATION_STOPPED_TIME_MISSING)); } - public void testUnifiedOldExplictGc() { + public void testUnifiedYoungExplictGc() { // TODO: Create File in platform independent way. File testFile = new File("src/test/data/dataset154.txt"); GcManager gcManager = new GcManager(); diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingCmsEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingCmsEvent.java index 5cd2a196..1c8943ce 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingCmsEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingCmsEvent.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -38,24 +40,42 @@ public void testLine() { Assert.assertEquals("Time stamp not parsed correctly.", 3, event.getTimestamp()); } - public void testLineWithSpaces() { - String logLine = "[0.003s][info][gc] Using Concurrent Mark Sweep "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_CMS.toString() + ".", - UsingCmsEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.003s][info][gc] Using Concurrent Mark Sweep"; Assert.assertEquals(JdkUtil.LogEventType.USING_CMS + "not identified.", JdkUtil.LogEventType.USING_CMS, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[0.003s][info][gc] Using Concurrent Mark Sweep"; + Assert.assertTrue(JdkUtil.LogEventType.USING_CMS.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UsingCmsEvent); + } + public void testNotBlocking() { String logLine = "[0.003s][info][gc] Using Concurrent Mark Sweep"; Assert.assertFalse(JdkUtil.LogEventType.USING_CMS.toString() + " incorrectly indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.USING_CMS.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.USING_CMS)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.USING_CMS); + Assert.assertTrue(JdkUtil.LogEventType.USING_CMS.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLineWithSpaces() { + String logLine = "[0.003s][info][gc] Using Concurrent Mark Sweep "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_CMS.toString() + ".", + UsingCmsEvent.match(logLine)); + } + /** * Test logging. */ diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingG1Event.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingG1Event.java index b70a3ade..eb8f15d4 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingG1Event.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingG1Event.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -38,24 +40,42 @@ public void testLine() { Assert.assertEquals("Time stamp not parsed correctly.", 5, event.getTimestamp()); } - public void testLineWithSpaces() { - String logLine = "[0.005s][info][gc] Using G1 "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_G1.toString() + ".", - UsingG1Event.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.005s][info][gc] Using G1"; Assert.assertEquals(JdkUtil.LogEventType.USING_G1 + "not identified.", JdkUtil.LogEventType.USING_G1, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[0.005s][info][gc] Using G1"; + Assert.assertTrue(JdkUtil.LogEventType.USING_G1.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UsingG1Event); + } + public void testNotBlocking() { String logLine = "[0.005s][info][gc] Using G1"; Assert.assertFalse(JdkUtil.LogEventType.USING_G1.toString() + " incorrectly indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.USING_G1.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.USING_G1)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.USING_G1); + Assert.assertTrue(JdkUtil.LogEventType.USING_G1.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLineWithSpaces() { + String logLine = "[0.005s][info][gc] Using G1 "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_G1.toString() + ".", + UsingG1Event.match(logLine)); + } + public void testLineDetailedLogging() { String logLine = "[0.003s][info][gc ] Using G1"; Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_G1.toString() + ".", diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingParallelEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingParallelEvent.java index cfc8306a..0436ff07 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingParallelEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingParallelEvent.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -38,24 +40,42 @@ public void testLine() { Assert.assertEquals("Time stamp not parsed correctly.", 2, event.getTimestamp()); } - public void testLineWithSpaces() { - String logLine = "[0.002s][info][gc] Using Parallel "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_PARALLEL.toString() + ".", - UsingParallelEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.002s][info][gc] Using Parallel"; Assert.assertEquals(JdkUtil.LogEventType.USING_PARALLEL + "not identified.", JdkUtil.LogEventType.USING_PARALLEL, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[0.002s][info][gc] Using Parallel"; + Assert.assertTrue(JdkUtil.LogEventType.USING_PARALLEL.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UsingParallelEvent); + } + public void testNotBlocking() { String logLine = "[0.002s][info][gc] Using Parallel"; Assert.assertFalse(JdkUtil.LogEventType.USING_PARALLEL.toString() + " incorrectly indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.USING_PARALLEL.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.USING_PARALLEL)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.USING_PARALLEL); + Assert.assertTrue(JdkUtil.LogEventType.USING_PARALLEL.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLineWithSpaces() { + String logLine = "[0.002s][info][gc] Using Parallel "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_PARALLEL.toString() + ".", + UsingParallelEvent.match(logLine)); + } + /** * Test logging. */ diff --git a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingSerialEvent.java b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingSerialEvent.java index 16fd1387..df08f2a0 100644 --- a/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingSerialEvent.java +++ b/src/test/java/org/eclipselabs/garbagecat/domain/jdk/unified/TestUsingSerialEvent.java @@ -13,6 +13,8 @@ package org.eclipselabs.garbagecat.domain.jdk.unified; import java.io.File; +import java.util.ArrayList; +import java.util.List; import org.eclipselabs.garbagecat.domain.JvmRun; import org.eclipselabs.garbagecat.service.GcManager; @@ -38,24 +40,42 @@ public void testLine() { Assert.assertEquals("Time stamp not parsed correctly.", 3, event.getTimestamp()); } - public void testLineWithSpaces() { - String logLine = "[0.003s][info][gc] Using Serial "; - Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_SERIAL.toString() + ".", - UsingSerialEvent.match(logLine)); - } - - public void testIdentity() { + public void testIdentityEventType() { String logLine = "[0.003s][info][gc] Using Serial"; Assert.assertEquals(JdkUtil.LogEventType.USING_SERIAL + "not identified.", JdkUtil.LogEventType.USING_SERIAL, JdkUtil.identifyEventType(logLine)); } + public void testParseLogLine() { + String logLine = "[0.003s][info][gc] Using Serial"; + Assert.assertTrue(JdkUtil.LogEventType.USING_SERIAL.toString() + " not parsed.", + JdkUtil.parseLogLine(logLine) instanceof UsingSerialEvent); + } + public void testNotBlocking() { String logLine = "[0.003s][info][gc] Using Serial"; Assert.assertFalse(JdkUtil.LogEventType.USING_SERIAL.toString() + " incorrectly indentified as blocking.", JdkUtil.isBlocking(JdkUtil.identifyEventType(logLine))); } + public void testReportable() { + Assert.assertTrue(JdkUtil.LogEventType.USING_SERIAL.toString() + " not indentified as reportable.", + JdkUtil.isReportable(JdkUtil.LogEventType.USING_SERIAL)); + } + + public void testUnified() { + List eventTypes = new ArrayList(); + eventTypes.add(LogEventType.USING_SERIAL); + Assert.assertTrue(JdkUtil.LogEventType.USING_SERIAL.toString() + " not indentified as unified.", + JdkUtil.isUnifiedLogging(eventTypes)); + } + + public void testLineWithSpaces() { + String logLine = "[0.003s][info][gc] Using Serial "; + Assert.assertTrue("Log line not recognized as " + JdkUtil.LogEventType.USING_SERIAL.toString() + ".", + UsingSerialEvent.match(logLine)); + } + /** * Test logging. */ diff --git a/src/test/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/TestUnifiedG1PreprocessAction.java b/src/test/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/TestUnifiedG1PreprocessAction.java new file mode 100644 index 00000000..3691ca0a --- /dev/null +++ b/src/test/java/org/eclipselabs/garbagecat/preprocess/jdk/unified/TestUnifiedG1PreprocessAction.java @@ -0,0 +1,263 @@ +/********************************************************************************************************************** + * garbagecat * + * * + * Copyright (c) 2008-2016 Red Hat, Inc. * + * * + * All rights reserved. This program and the accompanying materials are made available under the terms of the Eclipse * + * Public License v1.0 which accompanies this distribution, and is available at * + * http://www.eclipse.org/legal/epl-v10.html. * + * * + * Contributors: * + * Red Hat, Inc. - initial API and implementation * + *********************************************************************************************************************/ +package org.eclipselabs.garbagecat.preprocess.jdk.unified; + +import java.io.File; + +import org.eclipselabs.garbagecat.domain.JvmRun; +import org.eclipselabs.garbagecat.service.GcManager; +import org.eclipselabs.garbagecat.util.Constants; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil; +import org.eclipselabs.garbagecat.util.jdk.JdkUtil.LogEventType; +import org.eclipselabs.garbagecat.util.jdk.Jvm; + +import junit.framework.Assert; +import junit.framework.TestCase; + +/** + * @author Mike Millson + * + */ +public class TestUnifiedG1PreprocessAction extends TestCase { + + public void testLogLineStartPauseYoungNormal() { + String logLine = "[0.099s][info][gc,start ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineStartPauseYoungNormal6Spaces() { + String logLine = "[16.070s][info][gc,start ] GC(971) Pause Young (Normal) (G1 Evacuation Pause)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineStartPauseYoungConcurrentStart() { + String logLine = "[16.600s][info][gc,start ] GC(1032) Pause Young (Concurrent Start) (G1 Evacuation Pause)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineUsingWorkersForEvacuation() { + String logLine = "[0.100s][info][gc,task ] GC(0) Using 2 workers of 4 for evacuation"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineUsingWorkersForEvacuation7Spaces() { + String logLine = "[16.070s][info][gc,task ] GC(971) Using 2 workers of 4 for evacuation"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineUsingWorkersForMarking() { + String logLine = "[16.121s][info][gc,task ] GC(974) Using 1 workers of 1 for marking"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePreEvacuate() { + String logLine = "[0.101s][info][gc,phases ] GC(0) Pre Evacuate Collection Set: 0.0ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePreEvacuate5Spaces() { + String logLine = "[16.071s][info][gc,phases ] GC(971) Pre Evacuate Collection Set: 0.0ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineEvacuate() { + String logLine = "[0.101s][info][gc,phases ] GC(0) Evacuate Collection Set: 1.0ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePostEvacuate() { + String logLine = "[0.101s][info][gc,phases ] GC(0) Post Evacuate Collection Set: 0.2ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePostEvacuate5Spaces() { + String logLine = "[16.072s][info][gc,phases ] GC(971) Post Evacuate Collection Set: 0.1ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineOther() { + String logLine = "[0.101s][info][gc,phases ] GC(0) Other: 0.2ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineOther5Spaces() { + String logLine = "[16.072s][info][gc,phases ] GC(971) Other: 0.1ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineEden() { + String logLine = "[0.101s][info][gc,heap ] GC(0) Eden regions: 1->0(1)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineEden2Digits() { + String logLine = "[11.018s][info][gc,heap ] GC(686) Eden regions: 18->0(18)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineSurvivor() { + String logLine = "[0.101s][info][gc,heap ] GC(0) Survivor regions: 0->1(1)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineOld() { + String logLine = "[0.101s][info][gc,heap ] GC(0) Old regions: 0->0"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineOld2Digits() { + String logLine = "[10.989s][info][gc,heap ] GC(684) Old regions: 15->15"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineOld7Spaces() { + String logLine = "[17.728s][info][gc,heap ] GC(1098) Old regions: 21->21"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineHumongous() { + String logLine = "[0.101s][info][gc,heap ] GC(0) Humongous regions: 0->0"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineMetaspace() { + String logLine = "[0.101s][info][gc,metaspace ] GC(0) Metaspace: 4463K->4463K(1056768K)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineMetaspace2Spaces() { + String logLine = "[16.072s][info][gc,metaspace ] GC(971) Metaspace: 10793K->10793K(1058816K)"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineGcPauseYoungNormal() { + String logLine = "[0.101s][info][gc ] GC(0) Pause Young (Normal) " + + "(G1 Evacuation Pause) 0M->0M(2M) 1.371ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineGcPauseYoungConcurrentStart() { + String logLine = "[16.601s][info][gc ] GC(1032) Pause Young (Concurrent Start) " + + "(G1 Evacuation Pause) 38M->20M(46M) 0.772ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineTimesData() { + String logLine = "[16.601s][info][gc,cpu ] GC(1032) User=0.00s Sys=0.00s Real=0.00s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineTimesData8Spaces() { + String logLine = "[16.053s][info][gc,cpu ] GC(969) User=0.01s Sys=0.00s Real=0.00s"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineRemark() { + String logLine = "[16.051s][info][gc,start ] GC(969) Pause Remark"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineRemark6Spaces() { + String logLine = "[16.175s][info][gc,start ] GC(974) Pause Remark"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLineStringTable() { + String logLine = "[16.053s][info][gc,stringtable] GC(969) Cleaned string and symbol table, strings: " + + "5786 processed, 4 removed, symbols: 38663 processed, 11 removed"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePauseCleanup() { + String logLine = "[16.081s][info][gc,start ] GC(969) Pause Cleanup"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testLogLinePauseCleanupWithData() { + String logLine = "[16.082s][info][gc ] GC(969) Pause Cleanup 28M->28M(46M) 0.064ms"; + Assert.assertTrue("Log line not recognized as " + JdkUtil.PreprocessActionType.UNIFIED_G1.toString() + ".", + UnifiedG1PreprocessAction.match(logLine)); + } + + public void testPreprocessingYoungNormalCollection() { + // TODO: Create File in platform independent way. + File testFile = new File("src/test/data/dataset155.txt"); + GcManager gcManager = new GcManager(); + File preprocessedFile = gcManager.preprocess(testFile, null); + gcManager.store(preprocessedFile, false); + JvmRun jvmRun = gcManager.getJvmRun(new Jvm(null, null), Constants.DEFAULT_BOTTLENECK_THROUGHPUT_THRESHOLD); + Assert.assertEquals("Event type count not correct.", 1, jvmRun.getEventTypes().size()); + Assert.assertFalse(JdkUtil.LogEventType.UNKNOWN.toString() + " collector identified.", + jvmRun.getEventTypes().contains(LogEventType.UNKNOWN)); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_YOUNG_PAUSE.toString() + " collector not identified.", + jvmRun.getEventTypes().contains(LogEventType.UNIFIED_G1_YOUNG_PAUSE)); + } + + public void testPreprocessingRemark() { + // TODO: Create File in platform independent way. + File testFile = new File("src/test/data/dataset156.txt"); + GcManager gcManager = new GcManager(); + File preprocessedFile = gcManager.preprocess(testFile, null); + gcManager.store(preprocessedFile, false); + JvmRun jvmRun = gcManager.getJvmRun(new Jvm(null, null), Constants.DEFAULT_BOTTLENECK_THROUGHPUT_THRESHOLD); + Assert.assertEquals("Event type count not correct.", 1, jvmRun.getEventTypes().size()); + Assert.assertFalse(JdkUtil.LogEventType.UNKNOWN.toString() + " collector identified.", + jvmRun.getEventTypes().contains(LogEventType.UNKNOWN)); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_REMARK.toString() + " collector not identified.", + jvmRun.getEventTypes().contains(LogEventType.UNIFIED_REMARK)); + } + + public void testPreprocessingCleanup() { + // TODO: Create File in platform independent way. + File testFile = new File("src/test/data/dataset157.txt"); + GcManager gcManager = new GcManager(); + File preprocessedFile = gcManager.preprocess(testFile, null); + gcManager.store(preprocessedFile, false); + JvmRun jvmRun = gcManager.getJvmRun(new Jvm(null, null), Constants.DEFAULT_BOTTLENECK_THROUGHPUT_THRESHOLD); + Assert.assertEquals("Event type count not correct.", 1, jvmRun.getEventTypes().size()); + Assert.assertFalse(JdkUtil.LogEventType.UNKNOWN.toString() + " collector identified.", + jvmRun.getEventTypes().contains(LogEventType.UNKNOWN)); + Assert.assertTrue(JdkUtil.LogEventType.UNIFIED_G1_CLEANUP.toString() + " collector not identified.", + jvmRun.getEventTypes().contains(LogEventType.UNIFIED_G1_CLEANUP)); + } +} diff --git a/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkMath.java b/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkMath.java index d922857f..e2295bcb 100644 --- a/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkMath.java +++ b/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkMath.java @@ -12,6 +12,8 @@ *********************************************************************************************************************/ package org.eclipselabs.garbagecat.util.jdk; +import org.eclipselabs.garbagecat.domain.TimesData; + import junit.framework.Assert; import junit.framework.TestCase; @@ -185,6 +187,12 @@ public void testCalcParallelismUserZeroRealZero() { Assert.assertEquals("Parallelism not calculated correctly.", 100, JdkMath.calcParallelism(timeUser, timeReal)); } + public void testCalcParallelismNoData() { + int timeUser = TimesData.NO_DATA; + int timeReal = TimesData.NO_DATA; + Assert.assertEquals("Parallelism not calculated correctly.", 100, JdkMath.calcParallelism(timeUser, timeReal)); + } + public void testParallelism() { Assert.assertTrue("Parallism not calculated correctly.", JdkMath.isInvertedParallelism((int) 0)); Assert.assertTrue("Parallism not calculated correctly.", JdkMath.isInvertedParallelism((int) 99)); diff --git a/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkRegEx.java b/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkRegEx.java index 03ecf484..a6f622e1 100644 --- a/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkRegEx.java +++ b/src/test/java/org/eclipselabs/garbagecat/util/jdk/TestJdkRegEx.java @@ -201,47 +201,52 @@ public void testDurationFractionk5Digits() { durationFraction.matches(JdkRegEx.DURATION_FRACTION)); } - public void testSizeG1WholeBytes() { + public void testSizeWholeBytes() { String size = "0B"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1WholeKilobytes() { + public void testSizeWholeKilobytes() { String size = "8192K"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1WholeMegabytes() { + public void testSizeWholeMegabytes() { String size = "28M"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1WholeGigabytes() { + public void testSizeWholeGigabytes() { String size = "30G"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1DecimalBytes() { + public void testSizeDecimalBytes() { String size = "0.0B"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1DecimalKilobytes() { + public void testSizeDecimalKilobytes() { String size = "8192.0K"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1DecimalMegabytes() { + public void testSizeDecimalMegabytes() { String size = "28.0M"; Assert.assertTrue("'" + size + "' " + "is a valid size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1DecimalGigabytes() { + public void testMegabytesM() { + String unit = "M"; + Assert.assertTrue("'" + unit + "' " + "is a valid unit.", unit.matches(JdkRegEx.MEGABYTES)); + } + + public void testSizeDecimalGigabytes() { String size = "30.0G"; Assert.assertTrue("'" + size + "' " + "is a valid G1 details size.", size.matches(JdkRegEx.SIZE)); } - public void testSizeG1Comma() { + public void testSizeComma() { String size = "306,0M"; Assert.assertTrue("'" + size + "' " + "is a valid G1 details size.", size.matches(JdkRegEx.SIZE)); } diff --git a/src/test/scripts/garbage-maker-jdk11.sh b/src/test/scripts/garbage-maker-jdk11.sh index 5494784f..2250b5da 100644 --- a/src/test/scripts/garbage-maker-jdk11.sh +++ b/src/test/scripts/garbage-maker-jdk11.sh @@ -10,24 +10,24 @@ GARBAGECAT_VERSION=-3.0.1-SNAPSHOT ##### Create GC Logging ##### -java -Xms1m -Xmx64m -verbose:gc -Xlog:gc:file=$GARBAGECAT_HOME/jdk11-serial-new-serial-old.log -XX:+UseSerialGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xlog:gc*:file=$GARBAGECAT_HOME/jdk11-serial-new-serial-old.log -XX:+UseSerialGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -t 50 -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xlog:gc:file=$GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.log -XX:+UseParallelGC -XX:-UseParallelOldGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xlog:gc*:file=$GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.log -XX:+UseParallelGC -XX:-UseParallelOldGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -t 50 -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xlog:gc:file=$GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.log -XX:+UseParallelGC -XX:+UseParallelOldGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xlog:gc*:file=$GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.log -XX:+UseParallelGC -XX:+UseParallelOldGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -t 50 -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xlog:gc:file=$GARBAGECAT_HOME/jdk11-par-new-cms.log -XX:+UseConcMarkSweepGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xlog:gc*:file=$GARBAGECAT_HOME/jdk11-par-new-cms.log -XX:+UseConcMarkSweepGC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -t 50 -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xlog:gc:file=$GARBAGECAT_HOME/jdk11-g1.log -XX:+UseG1GC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xlog:gc*:file=$GARBAGECAT_HOME/jdk11-g1.log -XX:+UseG1GC -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -t 50 -o /dev/null ./gc.log ##### Analyze GC Logging ##### -java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o $GARBAGECAT_HOME/jdk11-serial-new-serial-old.txt $GARBAGECAT_HOME/jdk11-serial-new-serial-old.log +java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -p -t 50 -o $GARBAGECAT_HOME/jdk11-serial-new-serial-old.txt $GARBAGECAT_HOME/jdk11-serial-new-serial-old.log -java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.txt $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.log +java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -p -t 50 -o $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.txt $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-serial-old.log -java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.txt $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.log +java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -p -t 50 -o $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.txt $GARBAGECAT_HOME/jdk11-parallel-scavenge-parallel-old-compacting.log -java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o $GARBAGECAT_HOME/jdk11-par-new-cms.txt $GARBAGECAT_HOME/jdk11-par-new-cms.log +java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -p -t 50 -o $GARBAGECAT_HOME/jdk11-par-new-cms.txt $GARBAGECAT_HOME/jdk11-par-new-cms.log -java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o $GARBAGECAT_HOME/jdk11-g1.txt $GARBAGECAT_HOME/jdk11-g1.log +java -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -p -t 50 -o $GARBAGECAT_HOME/jdk11-g1.txt $GARBAGECAT_HOME/jdk11-g1.log diff --git a/src/test/scripts/garbage-maker-jdk8.sh b/src/test/scripts/garbage-maker-jdk8.sh index c5e52646..83a35abd 100644 --- a/src/test/scripts/garbage-maker-jdk8.sh +++ b/src/test/scripts/garbage-maker-jdk8.sh @@ -6,33 +6,33 @@ # GARBAGECAT_HOME=~/workspace/garbagecat/target -GARBAGECAT_VERSION=-3.0.0-SNAPSHOT +GARBAGECAT_VERSION=-3.0.1-SNAPSHOT ##### Create GC Logging ##### -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-serial-new-serial-old.log -XX:+UseSerialGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-serial-new-serial-old.log -XX:+UseSerialGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-serial-new-serial-old-details.log -XX:+UseSerialGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-serial-new-serial-old-details.log -XX:+UseSerialGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-serial-old.log -XX:+UseParallelGC -XX:-UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-serial-old.log -XX:+UseParallelGC -XX:-UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-serial-old-details.log -XX:+UseParallelGC -XX:-UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-serial-old-details.log -XX:+UseParallelGC -XX:-UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-old-compacting.log -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-old-compacting.log -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-old-compacting-details.log -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-parallel-scavenge-parallel-old-compacting-details.log -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-parallel-serial-old.log -XX:+UseParNewGC -XX:-UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-parallel-serial-old.log -XX:+UseParNewGC -XX:-UseParallelOldGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-parallel-serial-old-details.log -XX:+UseParNewGC -XX:-UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-parallel-serial-old-details.log -XX:+UseParNewGC -XX:-UseParallelOldGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-cms.log -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-cms.log -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-cms-details.log -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-par-new-cms-details.log -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-g1.log -XX:+UseG1GC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-g1.log -XX:+UseG1GC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log -java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-g1-details.log -XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar ./gc.log +java -Xms1m -Xmx64m -verbose:gc -Xloggc:$GARBAGECAT_HOME/jdk8-g1-details.log -XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -jar $GARBAGECAT_HOME/garbagecat$GARBAGECAT_VERSION.jar -o /dev/null ./gc.log ##### Analyze GC Logging #####