support parsing of logs without timestamp information present (but wi…

…th datestamp information)
chewiebug · Dec 21, 2013 · a87d4dc · a87d4dc
1 parent 62de636
commit a87d4dc
Show file tree

Hide file tree

Showing 12 changed files with 241 additions and 146 deletions.
diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/AbstractDataReaderSun.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/AbstractDataReaderSun.java
diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_3_1.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_3_1.java
@@ -12,7 +12,7 @@
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
 import com.tagtraum.perf.gcviewer.model.GCModel;
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 /**
  * Parses -verbose:gc output from Sun JDK 1.3.1.
@@ -69,7 +69,7 @@ public GCModel read() throws IOException {
         }
     }
 
-    protected AbstractGCEvent<GCEvent> parseLine(String line, ParsePosition pos) throws ParseException {
+    protected AbstractGCEvent<GCEvent> parseLine(String line, ParseInformation pos) throws ParseException {
         AbstractGCEvent<GCEvent> event = new GCEvent();
         try {
             event.setTimestamp(count);

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0.java
@@ -21,7 +21,7 @@
 import com.tagtraum.perf.gcviewer.model.ConcurrentGCEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
 import com.tagtraum.perf.gcviewer.model.GCModel;
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 /**
  * <p>Parses log output from Sun / Oracle Java 1.4 / 1.5 / 1.6. / 1.7
@@ -181,9 +181,6 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
     // -XX:+CMSScavengeBeforeRemark JDK 1.5
     private static final String SCAVENGE_BEFORE_REMARK = Type.SCAVENGE_BEFORE_REMARK.getName();
 
-
-    private Date firstDateStamp = null;
-
     public DataReaderSun1_6_0(InputStream in, GcLogType gcLogType) throws UnsupportedEncodingException {
         super(in, gcLogType);
     }
@@ -206,7 +203,7 @@ public GCModel read() throws IOException {
             boolean lastLineWasScavengeBeforeRemark = false;
             boolean lineSkippedForScavengeBeforeRemark = false;
             boolean printTenuringDistributionOn = false;
-            final ParsePosition parsePosition = new ParsePosition(0);
+            final ParseInformation parsePosition = new ParseInformation(0);
 
             while ((line = in.readLine()) != null) {
                 ++lineNumber;
@@ -435,7 +432,7 @@ private boolean isCmsScavengeBeforeRemark(String line) {
                 && (line.indexOf(EVENT_PARNEW) >= 0 || line.indexOf(EVENT_DEFNEW) >= 0);
     }
 
-    protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition pos) throws ParseException {
+    protected AbstractGCEvent<?> parseLine(final String line, final ParseInformation pos) throws ParseException {
         AbstractGCEvent<?> ae = null;
         try {
             // parse datestamp          "yyyy-MM-dd'T'hh:mm:ssZ:"
@@ -444,11 +441,7 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
             // either GC data or another collection type starting with timestamp
             // pre-used->post-used, total, time
             final Date datestamp = parseDatestamp(line, pos);
-            if (firstDateStamp == null) {
-                firstDateStamp = datestamp;
-            }
-
-            double timestamp = getTimeStamp(line, pos, datestamp);
+            double timestamp = getTimestamp(line, pos, datestamp);
             final ExtendedType type = parseType(line, pos);
             // special provision for CMS events
             if (type.getConcurrency() == Concurrency.CONCURRENT) {
@@ -492,28 +485,5 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
             throw new ParseException("Error parsing entry (" + rte.toString() + ")", line, pos);
         }
     }
-
-    /**
-     * If the next thing in <code>line</code> is a timestamp, it is parsed and returned.
-     * 
-     * @param line current line
-     * @param pos current parse positition
-     * @param datestamp datestamp that may have been parsed
-     * @return timestamp (either parsed or derived from datestamp)
-     * @throws ParseException it seemed to be a timestamp but still couldn't be parsed
-     */
-    private double getTimeStamp(final String line, final ParsePosition pos, final Date datestamp) 
-            throws ParseException {
-
-        double timestamp = 0;
-        if (nextIsTimestamp(line, pos)) {
-            timestamp = parseTimestamp(line, pos);
-        }
-        else if (datestamp != null && firstDateStamp != null) {
-            // if no timestamp was present, calculate difference between last and this date
-            timestamp = (datestamp.getTime() - firstDateStamp.getTime()) / (double)1000; 
-        }
-        return timestamp;
-    }
 
 }
diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0G1.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0G1.java
@@ -21,7 +21,7 @@
 import com.tagtraum.perf.gcviewer.model.G1GcEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
 import com.tagtraum.perf.gcviewer.model.GCModel;
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 /**
  * <p>Parses log output from Sun / Oracle Java 1.6. / 1.7
@@ -80,7 +80,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-Z0-9a-z- ().]+)[, ]+([0-9.]+)[ sec\\]]+$");
+    private static final Pattern PATTERN_GC_PAUSE = Pattern.compile("^([0-9-T:.+]{29})?[ ]?([0-9.]+)?[: \\[]{2,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;
@@ -128,7 +128,7 @@ public GCModel read() throws IOException {
             // TODO what is this for?
             model.setFormat(GCModel.Format.SUN_X_LOG_GC);
             String line;
-            final ParsePosition parsePosition = new ParsePosition(0);
+            final ParseInformation parsePosition = new ParseInformation(0);
             Matcher gcPauseMatcher = PATTERN_GC_PAUSE.matcher("");
             Matcher linesMixedMatcher = PATTERN_LINES_MIXED.matcher("");
             Matcher ergonomicsMatcher = PATTERN_G1_ERGONOMICS.matcher("");
@@ -234,8 +234,16 @@ else if (isPrintTenuringDistribution(line)) {
                             // detailed G1 events start with GC_MEMORY pattern, but are of type GC_MEMORY_PAUSE
 
                             gcEvent = new G1GcEvent();
-                            gcEvent.setDateStamp(parseDatestamp(gcPauseMatcher.group(GC_PAUSE_GROUP_DATESTAMP), parsePosition));
-                            gcEvent.setTimestamp(Double.parseDouble(gcPauseMatcher.group(GC_PAUSE_GROUP_TIMESTAMP)));
+                            Date datestamp = parseDatestamp(gcPauseMatcher.group(GC_PAUSE_GROUP_DATESTAMP), parsePosition);
+                            gcEvent.setDateStamp(datestamp);
+                            double timestamp = 0;
+                            if (gcPauseMatcher.group(GC_PAUSE_GROUP_TIMESTAMP) == null) {
+                                timestamp = getTimestamp(line, parsePosition, datestamp);
+                            }
+                            else {
+                                timestamp = Double.parseDouble(gcPauseMatcher.group(GC_PAUSE_GROUP_TIMESTAMP));
+                            }
+                            gcEvent.setTimestamp(timestamp);
                             gcEvent.setExtendedType(type);
                             gcEvent.setPause(Double.parseDouble(gcPauseMatcher.group(GC_PAUSE_GROUP_PAUSE)));
 
@@ -311,7 +319,7 @@ private boolean isPrintTenuringDistribution(String line) {
      */
     private int parseDetails(BufferedReader in, 
             GCModel model,
-            ParsePosition pos, 
+            ParseInformation pos, 
             int lineNumber, 
             GCEvent event, 
             String beginningOfLine)
@@ -401,28 +409,29 @@ else if (line.indexOf(INCOMPLETE_CONCURRENT_MARK_INDICATOR) >= 0) {
      * @param line line containing the incomplete concurrent event
      * @throws ParseException 
      */
-    private void parseIncompleteConcurrentEvent(GCModel model, AbstractGCEvent<?> previousEvent, String line, ParsePosition pos) throws ParseException {
+    private void parseIncompleteConcurrentEvent(GCModel model, AbstractGCEvent<?> previousEvent, String line, ParseInformation pos) throws ParseException {
         // some concurrent event is mixed in -> extract it
         pos.setIndex(line.indexOf("GC conc"));
         ExtendedType type = parseType(line, pos);
         model.add(parseConcurrentEvent(line, pos, previousEvent.getDatestamp(), previousEvent.getTimestamp(), type));
     }
 
     @Override
-    protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition pos) throws ParseException {
+    protected AbstractGCEvent<?> parseLine(final String line, final ParseInformation pos) throws ParseException {
         AbstractGCEvent<?> ae = null;
         try {
             // parse datestamp          "yyyy-MM-dd'T'hh:mm:ssZ:"
             // parse timestamp          "double:"
             // parse collection type    "[TYPE"
             // pre-used->post-used, total, time
             final Date datestamp = parseDatestamp(line, pos);
-            final double timestamp = parseTimestamp(line, pos);
+            final double timestamp = getTimestamp(line, pos, datestamp);
             final ExtendedType type = parseType(line, pos);
             // special provision for concurrent events
             if (type.getConcurrency() == Concurrency.CONCURRENT) {
                 ae = parseConcurrentEvent(line, pos, datestamp, timestamp, type);
-            } else {
+            } 
+            else {
                 final GCEvent event = new GCEvent();
                 event.setDateStamp(datestamp);
                 event.setTimestamp(timestamp);
@@ -444,7 +453,8 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
                 ae = event;
             }
             return ae;
-        } catch (RuntimeException rte) {
+        } 
+        catch (RuntimeException rte) {
             throw new ParseException(rte.toString(), line, pos);
         }
     }
@@ -460,7 +470,7 @@ protected AbstractGCEvent<?> parseLine(final String line, final ParsePosition po
      * @return complete concurrent event
      */
     private AbstractGCEvent<?> parseConcurrentEvent(final String line,
-            final ParsePosition pos, final Date datestamp,
+            final ParseInformation pos, final Date datestamp,
             final double timestamp, final ExtendedType type) {
 
         final ConcurrentGCEvent event = new ConcurrentGCEvent();

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/ParseException.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/ParseException.java
@@ -2,7 +2,7 @@
 
 import java.io.IOException;
 
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 /**
  * Is thrown whenever a ParseError occurs.
@@ -13,7 +13,7 @@
  */
 public class ParseException extends IOException {
     private String line;
-    private ParsePosition parsePosition;
+    private ParseInformation parsePosition;
 
     public ParseException(String s) {
         this(s, null);
@@ -24,7 +24,7 @@ public ParseException(String s, String line) {
         this.line = line;
     }
 
-    public ParseException(String s, String line, ParsePosition pos) {
+    public ParseException(String s, String line, ParseInformation pos) {
         super(s);
         this.line = line;
         this.parsePosition = pos;

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/UnknownGcTypeException.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/UnknownGcTypeException.java
@@ -1,6 +1,6 @@
 package com.tagtraum.perf.gcviewer.imp;
 
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 /**
  * GC Types are the text introducing specific information for (part of) a GC (e.g. "Full GC") 
@@ -10,7 +10,7 @@
  */
 public class UnknownGcTypeException extends ParseException {
 
-    public UnknownGcTypeException(String gcType, String line, ParsePosition pos) {
+    public UnknownGcTypeException(String gcType, String line, ParseInformation pos) {
         super("Unknown gc type: '" + gcType + "'", line, pos);
     }
 

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/util/ParseInformation.java b/src/main/java/com/tagtraum/perf/gcviewer/util/ParseInformation.java
@@ -0,0 +1,37 @@
+package com.tagtraum.perf.gcviewer.util;
+
+import java.text.ParsePosition;
+import java.util.Date;
+
+/**
+ * This class holds information about the current parsing process. 
+ * 
+ * @author <a href="mailto:hs@tagtraum.com">Hendrik Schreiber</a>
+ * @author <a href="mailto:gcviewer@gmx.ch">Joerg Wuethrich</a>
+ */
+public class ParseInformation extends ParsePosition {
+
+    private Date firstDateStamp;
+    private int lineNumber;
+
+    public ParseInformation(int index) {
+        super(index);
+    }
+
+    public Date getFirstDateStamp() {
+        return firstDateStamp;
+    }
+
+    public int getLineNumber() {
+        return lineNumber;
+    }
+
+    public void setFirstDateStamp(Date firstDateStamp) {
+        this.firstDateStamp = firstDateStamp;
+    }
+
+    public void setLineNumber(int lineNumber) {
+        this.lineNumber = lineNumber;
+    }
+
+}
diff --git a/src/main/java/com/tagtraum/perf/gcviewer/util/ParsePosition.java b/src/main/java/com/tagtraum/perf/gcviewer/util/ParsePosition.java
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestAbstractDataReaderSun.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestAbstractDataReaderSun.java
@@ -13,7 +13,7 @@
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
 import com.tagtraum.perf.gcviewer.model.GCModel;
-import com.tagtraum.perf.gcviewer.util.ParsePosition;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
 
 public class TestAbstractDataReaderSun {
 
@@ -31,7 +31,7 @@ public void setUp() throws UnsupportedEncodingException {
     public void setMemorySimplePreUsed_heap_postUsed_heap() throws ParseException {
         String line = "   [Eden: 1000K(2000K)->0B(3000K) Survivors: 1024B->4000K Heap: 5000K(16M)->6000K(16M)]";
 
-        ParsePosition pos = new ParsePosition(0);
+        ParseInformation pos = new ParseInformation(0);
         pos.setIndex(line.indexOf("Heap:") + "Heap:".length() + 1);
 
         GCEvent event = new GCEvent();
@@ -49,7 +49,7 @@ public void setMemorySimplePreUsed_heap_postUsed_heap() throws ParseException {
     public void setMemorySimplePreUsed_postUsed_heap() throws ParseException {
         String line = "   [ 8192K->8128K(64M)]";
 
-        ParsePosition pos = new ParsePosition(0);
+        ParseInformation pos = new ParseInformation(0);
         pos.setIndex(line.indexOf("[") + 1);
 
         GCEvent event = new GCEvent();
@@ -67,7 +67,7 @@ public void setMemorySimplePreUsed_postUsed_heap() throws ParseException {
     public void setMemorySimplePreHeap_postHeap() throws ParseException {
         String line = "   [Eden: 1000K(2000K)->0B(3000K) Survivors: 1024B->4000K Heap: 5000K(16M)->6000K(16M)]";
 
-        ParsePosition pos = new ParsePosition(0);
+        ParseInformation pos = new ParseInformation(0);
         pos.setIndex(line.indexOf("Survivors:") + "Survivors:".length() + 1);
 
         GCEvent event = new GCEvent();
@@ -84,7 +84,7 @@ public void setMemorySimplePreHeap_postHeap() throws ParseException {
     public void setExtendedMemoryFloatingPointPreEden_postEden() throws ParseException {
         String line = "   [Eden: 118.5M(118.0M)->128.4K(112.0M) Survivors: 10.0M->16.0M Heap: 548.6M(640.0M)->440.6M(640.0M)]";
 
-        ParsePosition pos = new ParsePosition(0);
+        ParseInformation pos = new ParseInformation(0);
         pos.setIndex(line.indexOf("Eden:") + "Eden:".length() + 1);
 
         GCEvent event = new GCEvent();
@@ -107,7 +107,7 @@ public AbstractDataReaderSunSub(InputStream in, GcLogType gcLogType) throws Unsu
         }
 
         @Override
-        public void setMemoryExtended(GCEvent event, String line, ParsePosition pos) throws ParseException {
+        public void setMemoryExtended(GCEvent event, String line, ParseInformation pos) throws ParseException {
             super.setMemoryExtended(event, line, pos);
         }
 
@@ -117,7 +117,7 @@ public GCModel read() throws IOException {
         }
 
         @Override
-        protected AbstractGCEvent<?> parseLine(String line, ParsePosition pos) throws ParseException {
+        protected AbstractGCEvent<?> parseLine(String line, ParseInformation pos) throws ParseException {
             return null;
         }
 

diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderSun1_7_0.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderSun1_7_0.java
@@ -111,6 +111,20 @@ public void CmsRemarkWithTimestamps() throws Exception {
         assertEquals("type name", "GC; CMS-remark", model.get(0).getTypeAsString());
         assertEquals("GC pause", 0.3410220, model.getPause().getMax(), 0.00000001);
     }    
+
+    @Test
+    public void CmsWithoutTimestamps() throws Exception {
+        ByteArrayInputStream in = new ByteArrayInputStream(
+                "2013-12-19T17:52:49.323+0100: [GC2013-12-19T17:52:49.323+0100: [ParNew: 4872K->480K(4928K), 0.0031563 secs] 102791K->102785K(140892K), 0.0032042 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]"
+                        .getBytes());
+
+        final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
+        GCModel model = reader.read();
+
+        assertEquals("GC count", 1, model.size());
+        assertEquals("type name", "GC; ParNew", model.get(0).getTypeAsString());
+        assertEquals("GC pause", 0.0032042, model.getPause().getMax(), 0.00000001);
+    }
 
     /**
      * Test output of -XX:+PrintAdaptiveSizePolicy -XX:+UseAdaptiveSizePolicy -XX:+PrintReferenceGC