Remark with date stamp

src/main/java/com/tagtraum/perf/gcviewer/imp/AbstractDataReaderSun.java

@@ -10,6 +10,8 @@
 import java.util.List;
 import java.util.logging.Level;
 import java.util.logging.Logger;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
 
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
@@ -46,6 +48,8 @@ public abstract class AbstractDataReaderSun implements DataReader {
     /** the log type allowing for small differences between different versions of the gc logs */
     protected GcLogType gcLogType;
 
+    private static Pattern parenthesesPattern = Pattern.compile("\\([^()]*\\) ?");
+
     /**
      * Create an instance of this class passing an inputStream an the type of the logfile.
      * @param in inputstream to the log file
@@ -213,7 +217,7 @@ protected void setMemory(GCEvent event, String line, ParsePosition pos) throws P
 
         while (isGeneration(line, pos)) {
             final GCEvent detailEvent = new GCEvent();
-            final AbstractGCEvent.Type type = parseType(line, pos);
+            final AbstractGCEvent.Type type = parseNestedType(line, pos);
             detailEvent.setType(type);
             start = pos.getIndex();
             end = line.indexOf("K", pos.getIndex());
@@ -323,7 +327,8 @@ protected boolean nextCharIsBracket(String line, ParsePosition pos) {
         return line.charAt(pos.getIndex()) == '[';
     }
 
-    protected GCEvent.Type parseType(String line, ParsePosition pos) throws ParseException {
+
+    protected String parseTypeString(String line, ParsePosition pos) throws ParseException {
         int i = pos.getIndex();
         try {
             // consume all leading spaces and [
@@ -334,7 +339,7 @@ protected GCEvent.Type parseType(String line, ParsePosition pos) throws ParseExc
                 if (c != ' ' && c != '[') break;
             }
             if (i>=lineLength) throw new ParseException("Unexpected end of line.", line);
-            StringBuffer sb = new StringBuffer(20);
+            StringBuilder sb = new StringBuilder(20);
             // check whether the type name starts with a number
             // e.g. 0.406: [GC [1 CMS-initial-mark: 7664K(12288K)] 7666K(16320K), 0.0006855 secs]
             //final int startNumbers = i;
@@ -365,18 +370,44 @@ protected GCEvent.Type parseType(String line, ParsePosition pos) throws ParseExc
             for (; i<lineLength; c = lineChars[++i]) {
                 if (c == '[' || c == ']' || Character.isDigit(c)) break;
             }
-            final String s = sb.toString();
-            GCEvent.Type gcType = AbstractGCEvent.Type.parse(s);
-            if (gcType == null) {
-                throw new UnknownGcTypeException(s, line, pos);
-            }
-            return gcType;
+            return sb.toString();
         }
         finally {
             pos.setIndex(i);
         }
     }
 
+
+    protected GCEvent.Type parseNestedType(String line, ParsePosition pos) throws ParseException {
+        String typeString = parseTypeString(line, pos);
+        GCEvent.Type gcType = AbstractGCEvent.Type.parse(typeString);
+        //GCEvent.Type gcType = extractTypeFromParsedString(s);
+        if (gcType == null) {
+            throw new UnknownGcTypeException(typeString, line, pos);
+        }
+        return gcType;
+    }
+
+    protected GCEvent.Type parseTopType(String line, ParsePosition pos) throws ParseException {
+        String typeString = parseTypeString(line, pos);
+        return extractTypeFromParsedString(typeString);
+    }
+
+
+    protected GCEvent.Type extractTypeFromParsedString(String s) throws UnknownGcTypeException {
+        GCEvent.Type gcType = AbstractGCEvent.Type.parse(s);
+        // the gcType may be null because there was a PrintGCCause flag enabled - if so, reparse it with the first paren set stripped
+        if (gcType == null) {
+            // try to parse it again with the parens removed
+            Matcher parenMatcher = parenthesesPattern.matcher(s);
+            if (parenMatcher.find()) {
+                gcType = AbstractGCEvent.Type.parse(parenMatcher.replaceFirst(""));
+                // TODO: retain the full string representation of the GC (including the cause)
+            }
+        }
+        return gcType;
+    }
+
     /**
      * Returns <code>true</code>, if next "token" is a timestamp.
      * 
@@ -537,7 +568,7 @@ protected Date parseDatestamp(String line, ParsePosition pos) throws ParseExcept
         Date date = null;
         if (nextIsDatestamp(line, pos)) {
             try {
-                date = dateParser.parse(line.substring(pos.getIndex(), LENGTH_OF_DATESTAMP-1));
+                date = dateParser.parse(line.substring(pos.getIndex(), pos.getIndex()+LENGTH_OF_DATESTAMP-1));
                 pos.setIndex(pos.getIndex() + LENGTH_OF_DATESTAMP);
             }
             catch (java.text.ParseException e) {
@@ -555,11 +586,11 @@ protected Date parseDatestamp(String line, ParsePosition pos) throws ParseExcept
      * @param pos current parse position
      * @return <code>true</code> if in current line at current parse position we have a datestamp
      */
-    private boolean nextIsDatestamp(String line, ParsePosition pos) {
+    protected boolean nextIsDatestamp(String line, ParsePosition pos) {
         if (line == null || line.length() < 10) {
             return false;
         }
 
-        return line.indexOf("-", pos.getIndex()) == 4 && line.indexOf("-", pos.getIndex() + 5) == 7;
+        return line.indexOf("-", pos.getIndex()) == pos.getIndex()+4 && line.indexOf("-", pos.getIndex() + 5) == pos.getIndex()+7;
     }
 }

src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderFactory.java

@@ -128,8 +128,10 @@ private DataReader getDataReaderBySample(String s, InputStream in) throws IOExce
             // this should be an IBM JDK < 1.3.0
             if (LOG.isLoggable(Level.INFO)) LOG.info("File format: IBM <1.3.0");
             return new DataReaderIBM1_3_0(in);
-        } else if (s.indexOf("pause (young)") > 0) {
+        } else if (s.indexOf("pause (young)") > 0 || s.indexOf("G1Ergonomics") > 0) {
             // G1 logger usually starts with "<timestamp>: [GC pause (young)...]"
+            // but can start with  <timestamp>: [G1Ergonomics (Heap Sizing) expand the heap...
+            // with certain logging flaggs.
             if (LOG.isLoggable(Level.INFO)) LOG.info("File format: Sun 1.6.x G1 collector");
             return new DataReaderSun1_6_0G1(in, GcLogType.SUN1_6G1);
         } else if (s.indexOf("[Times:") > 0) {

src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0.java

@@ -58,7 +58,7 @@
  */
 public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
 
-    private static Logger LOG = Logger.getLogger(DataReaderSun1_6_0.class.getName());
+    private static final Logger LOG = Logger.getLogger(DataReaderSun1_6_0.class.getName());
 
     private static final String UNLOADING_CLASS = "[Unloading class ";
     private static final String APPLICATION_TIME = "Application time:"; // -XX:+PrintGCApplicationConcurrentTime
@@ -140,19 +140,19 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
     // AdaptiveSizeStop: collection: 1 
     //  [PSYoungGen: 16420K->2657K(19136K)] 16420K->15919K(62848K), 0.0109211 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
     // -> to parse it, the first line must be split, and the following left out until the rest of the gc information follows
-    private static Pattern adaptiveSizePolicyPattern = Pattern.compile("(.*GC|.*\\(System\\))Adaptive.*");
+    private static final Pattern adaptiveSizePolicyPattern = Pattern.compile("(.*GC|.*\\(System\\))Adaptive.*");
     private static final String ADAPTIVE_PATTERN = "AdaptiveSize";
 
     // -XX:+PrintAdaptiveSizePolicy combined with -XX:-UseAdaptiveSizePolicy (not using the policy, just printing)
     // outputs the following line:
     // 0.222: [GCAdaptiveSizePolicy::compute_survivor_space_size_and_thresh:  survived: 2720992  promoted: 13613552  overflow: true [PSYoungGen: 16420K->2657K(19136K)] 16420K->15951K(62848K), 0.0132830 secs] [Times: user=0.00 sys=0.03, real=0.02 secs] 
-    private static Pattern printAdaptiveSizePolicyPattern = Pattern.compile("(.*GC)Adaptive.*(true|false)( \\[.*)");
+    private static final Pattern printAdaptiveSizePolicyPattern = Pattern.compile("(.*GC)Adaptive.*(true|false)( \\[.*)");
     private static final int PRINT_ADAPTIVE_SIZE_GROUP_BEFORE = 1;
     private static final int PRINT_ADAPTIVE_SIZE_GROUP_AFTER = 3;
 
     // -XX:PrintCmsStatistics=2
     private static final String PRINT_CMS_STATISTICS_ITERATIONS = "iterations";
-    private static Pattern printCmsStatisticsIterationsPattern = Pattern.compile("(.*)[ ][\\[][0-9]+[ ]iterations[, 0-9]+[ ]waits[, 0-9]+[ ]cards[)][\\]][ ](.*)");
+    private static final Pattern printCmsStatisticsIterationsPattern = Pattern.compile("(.*)[ ][\\[][0-9]+[ ]iterations[, 0-9]+[ ]waits[, 0-9]+[ ]cards[)][\\]][ ](.*)");
     private static final int PRINT_CMS_STATISTICS_ITERATIONS_GROUP_BEFORE = 1;
     private static final int PRINT_CMS_STATISTICS_ITERATIONS_GROUP_AFTER = 2;
     private static final String PRINT_CMS_STATISTICS_SURVIVOR = "  (Survivor:";
@@ -163,7 +163,7 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
     // in JDK1.4 / 1.5 it looked like this:
     // 5.0: [GC Desired survivor size 3342336 bytes, new threshold 1 (max 32) - age   1:  6684672 bytes,  6684672 total 52471K->22991K(75776K), 1.0754938 secs]
     private static final String PRINT_TENURING_DISTRIBUTION = "Desired survivor size"; 
-    private static Pattern printTenuringDistributionPattern = Pattern.compile("(.*GC)[ ]?Desired.*(?:[0-9]\\)|total)( \\[.*|[ ][0-9]*.*)");
+    private static final Pattern printTenuringDistributionPattern = Pattern.compile("(.*GC)[ ]?Desired.*(?:[0-9]\\)|total)( \\[.*|[ ][0-9]*.*)");
     private static final int PRINT_TENURING_DISTRIBUTION_PATTERN_GROUP_BEFORE = 1;
     private static final int PRINT_TENURING_DISTRIBUTION_PATTERN_GROUP_AFTER = 2;
 
@@ -402,7 +402,7 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
             }
 
             double timestamp = getTimeStamp(line, pos, datestamp);
-            final GCEvent.Type type = parseType(line, pos);
+            final GCEvent.Type type = parseTopType(line, pos);
             // special provision for CMS events
             if (type.getConcurrency() == Concurrency.CONCURRENT) {
                 final ConcurrentGCEvent event = new ConcurrentGCEvent();
@@ -467,7 +467,7 @@ private void parseDetailEventsIfExist(final String line, final ParsePosition pos
                 } else {
                     detailEvent.setTimestamp(parseTimestamp(line, pos));
                 }
-                detailEvent.setType(parseType(line, pos));
+                detailEvent.setType(parseNestedType(line, pos));
                 setMemoryAndPauses(detailEvent, line, pos);
                 event.add(detailEvent);
             } 

src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0G1.java

@@ -51,7 +51,7 @@ public class DataReaderSun1_6_0G1 extends AbstractDataReaderSun {
 
     private static final String INCOMPLETE_CONCURRENT_MARK_INDICATOR = "concurrent-mark";
 
-    private static Logger LOG = Logger.getLogger(DataReaderSun1_6_0G1.class .getName());
+    private static final Logger LOG = Logger.getLogger(DataReaderSun1_6_0G1.class .getName());
 
     private static final String TIMES = "[Times";
 
@@ -77,7 +77,7 @@ public class DataReaderSun1_6_0G1 extends AbstractDataReaderSun {
 
     // the following pattern is specific for G1 with -XX:+PrintGCDetails
     // "[<datestamp>: ]0.295: [GC pause (young), 0.00594747 secs]"
-    private static final Pattern PATTERN_GC_PAUSE = Pattern.compile("^([0-9-T:.+]{29})?[ ]?([0-9.]+)[: \\[]{3}([A-Za-z- ().]+)[, ]+([0-9.]+)[ sec\\]]+$");
+    private static final Pattern PATTERN_GC_PAUSE = Pattern.compile("^([0-9-T:.+]{29})?[ ]?([0-9.]+)[: \\[]{3}([A-Z0-9a-z- ().]+)[, ]+([0-9.]+)[ sec\\]]+$");
     private static final int GC_PAUSE_GROUP_DATESTAMP = 1;
     private static final int GC_PAUSE_GROUP_TIMESTAMP = 2;
     private static final int GC_PAUSE_GROUP_TYPE = 3;
@@ -94,9 +94,9 @@ public class DataReaderSun1_6_0G1 extends AbstractDataReaderSun {
     // or "...Full GC<timestamp>..."
     // or "...)<timestamp>:  (initial-mark)..." (where the timestamp including ":" belongs to a concurrent event and the rest not)
     // or "...)<timestamp> (initial-mark)..." (where only the timestamp belongs to a concurrent event)
-    private static Pattern PATTERN_LINES_MIXED = Pattern.compile("(.*\\)|.*Full GC)([0-9.]+.*)");
+    private static final Pattern PATTERN_LINES_MIXED = Pattern.compile("(.*\\)|.*Full GC)([0-9.]+.*)");
 
-    private static Pattern PATTERN_G1_ERGONOMICS = Pattern.compile("(.*)\\W\\d+\\.\\d{3}\\W{2}\\[G1Ergonomics .+\\].*");
+    private static final Pattern PATTERN_G1_ERGONOMICS = Pattern.compile("(.*)\\W\\d+\\.\\d{3}\\W{2}\\[G1Ergonomics .+\\].*");
 
     private static final String HEAP_SIZING_START = "Heap";
 
@@ -218,7 +218,8 @@ else if (isPrintTenuringDistribution(line)) {
                     // all other GC types are the same as in standard G1 mode.
                     gcPauseMatcher.reset(line);
                     if (gcPauseMatcher.matches()) {
-                        AbstractGCEvent.Type type = AbstractGCEvent.Type.parse(gcPauseMatcher.group(GC_PAUSE_GROUP_TYPE));
+                        AbstractGCEvent.Type type  = extractTypeFromParsedString(gcPauseMatcher.group(GC_PAUSE_GROUP_TYPE));
+
                         if (type != null && type.getPattern().compareTo(GcPattern.GC_MEMORY_PAUSE) == 0) {
                             // detailed G1 events start with GC_MEMORY pattern, but are of type GC_MEMORY_PAUSE
 
@@ -337,7 +338,7 @@ private int parseDetails(BufferedReader in,
                 GCEvent youngEvent = new GCEvent();
                 youngEvent.setDateStamp(event.getDatestamp());
                 youngEvent.setTimestamp(event.getTimestamp());
-                youngEvent.setType(parseType(line, pos));
+                youngEvent.setType(parseNestedType(line, pos));
                 setMemoryExtended(youngEvent, line, pos);
 
                 // add survivors
@@ -394,7 +395,7 @@ else if (line.indexOf(INCOMPLETE_CONCURRENT_MARK_INDICATOR) >= 0) {
     private void parseIncompleteConcurrentEvent(GCModel model, AbstractGCEvent<?> previousEvent, String line, ParsePosition pos) throws ParseException {
         // some concurrent event is mixed in -> extract it
         pos.setIndex(line.indexOf("GC conc"));
-        Type type = parseType(line, pos);
+        Type type = parseNestedType(line, pos);
         model.add(parseConcurrentEvent(line, pos, previousEvent.getDatestamp(), previousEvent.getTimestamp(), type));
     }
 
@@ -408,7 +409,7 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
             // pre-used->post-used, total, time
             final Date datestamp = parseDatestamp(line, pos);
             final double timestamp = parseTimestamp(line, pos);
-            final GCEvent.Type type = parseType(line, pos);
+            final GCEvent.Type type = parseTopType(line, pos);
             // special provision for concurrent events
             if (type.getConcurrency() == Concurrency.CONCURRENT) {
                 ae = parseConcurrentEvent(line, pos, datestamp, timestamp, type);
@@ -419,7 +420,9 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
                 event.setType(type);
                 // Java 7 can have detailed event at this position like this
                 // 0.197: [GC remark 0.197: [GC ref-proc, 0.0000070 secs], 0.0005297 secs]
-                if (nextIsTimestamp(line, pos)) {
+                // or when PrintDateTimeStamps is on like:
+                // 2013-09-09T06:45:45.825+0000: 83146.942: [GC remark 2013-09-09T06:45:45.825+0000: 83146.943: [GC ref-proc, 0.0069100 secs], 0.0290090 secs]
+                if (nextIsTimestamp(line, pos) || nextIsDatestamp(line,pos)) {
                     event.add((GCEvent) parseLine(line, pos));
                 }
 

src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java

@@ -239,7 +239,7 @@ public boolean isRemark() {
     }
 
     public static class Type implements Serializable {
-        private final String type;
+        private String type;
         private final String rep;
         private Generation generation;
         private Concurrency concurrency;

src/main/java/com/tagtraum/perf/gcviewer/model/GCModel.java

@@ -82,7 +82,7 @@ public boolean equals(Object other) {
 	    }
 	}
 
-	private static Logger LOG = Logger.getLogger(GCModel.class.getName());
+	private static final Logger LOG = Logger.getLogger(GCModel.class.getName());
 
     private List<AbstractGCEvent<?>> allEvents;
     private List<GCEvent> stopTheWorldEvents;