Add support for Go GC logging

The Go programming language has a very dense GC logging format, which
is difficult to read for humans. It looks like this:

gc 1 @0.027s 35%: 15+3.3+0.41 ms clock, 46+0.66/2.3/3.0+1.2 ms cpu...
gc 2 @0.060s 28%: 3.6+7.6+0.37 ms clock, 10+0.33/0/6.5+1.1 ms cpu,...
gc 3 @0.079s 26%: 0.072+6.7+0.68 ms clock, 0.21+3.9/0.060/11+2.0 m...
gc 4 @0.104s 21%: 0.16+14+0.31 ms clock, 0.48+5.2/0.16/14+0.94 ms ...
gc 5 @0.140s 18%: 0.12+14+0.73 ms clock, 0.36+3.8/4.1/16+2.1 ms cp...
gc 6 @0.179s 17%: 0.20+15+0.48 ms clock, 0.62+5.1/10/19+1.4 ms cpu...
gc 7 @0.222s 16%: 0.12+19+0.21 ms clock, 0.37+11/0.064/19+0.64 ms ...
gc 8 @0.292s 15%: 0.10+13+0.34 ms clock, 0.32+10/11/13+1.0 ms cpu,...
gc 9 @0.936s 4%: 0.053+25+0.67 ms clock, 0.16+0.30/0.36/30+2.0 ms ...
gc 10 @1.123s 5%: 0.073+30+0.52 ms clock, 0.22+1.7/29/1.4+1.5 ms c...
gc 11 @1.369s 4%: 0.066+34+0.47 ms clock, 0.19+10/20/2.1+1.4 ms cp...

It fits well into the GCViewer model, although Go has nothing to do with
the JVM.

Author: rillig

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

@@ -207,6 +207,10 @@ else if (s.indexOf("starting collection, threshold allocation reached.") != -1)
             if (getLogger().isLoggable(Level.INFO)) getLogger().info("File format: IBM i5/OS 1.4.2");
             return new DataReaderIBMi5OS1_4_2(gcResource, in);
         }
+        else if (s.contains("\ngc ")) {
+            if (getLogger().isLoggable(Level.INFO)) getLogger().info("File format: Go");
+            return new DataReaderGo(gcResource, in);
+        }
         return null;
     }
 

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

@@ -0,0 +1,89 @@
+package com.tagtraum.perf.gcviewer.imp;
+
+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.model.GCResource;
+import com.tagtraum.perf.gcviewer.util.ParseInformation;
+import java.io.IOException;
+import java.io.InputStream;
+import java.io.LineNumberReader;
+import java.io.UnsupportedEncodingException;
+import java.util.logging.Level;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+
+/**
+ * Parses GC log output from Go 1.9.
+ *
+ * @author <a href="mailto:roland.illig@gmx.de">Roland Illig</a>
+ * @see <a href="https://golang.org/pkg/runtime/#hdr-Environment_Variables">Go documentation</a>
+ */
+public class DataReaderGo extends AbstractDataReader {
+
+    private static final Pattern GCLINE = Pattern.compile(""
+            + "gc "
+            + "(\\d+) "
+            + "@(\\d+\\.\\d+)s "
+            + "(\\d+)%: "
+            + "(\\d+(?:\\.\\d+)?)\\+"
+            + "(\\d+(?:\\.\\d+)?)\\+"
+            + "(\\d+(?:\\.\\d+)?) ms clock, "
+            + "(\\d+(?:\\.\\d+)?)\\+"
+            + "(\\d+(?:\\.\\d+)?)/"
+            + "(\\d+(?:\\.\\d+)?)/"
+            + "(\\d+(?:\\.\\d+)?)\\+"
+            + "(\\d+(?:\\.\\d+)?) ms cpu, "
+            + "(\\d+)->"
+            + "(\\d+)->"
+            + "(\\d+) MB, "
+            + "(\\d+) MB goal, "
+            + "(\\d+) P");
+
+    public DataReaderGo(GCResource gcResource, InputStream in) throws UnsupportedEncodingException {
+        super(gcResource, in);
+    }
+
+    public GCModel read() throws IOException {
+        if (getLogger().isLoggable(Level.INFO)) getLogger().info("Reading Go format...");
+
+        try (LineNumberReader in = this.in) {
+            GCModel model = new GCModel();
+            model.setFormat(GCModel.Format.GO);
+            ParseInformation parsePosition = new ParseInformation(0);
+
+            Matcher matcher = GCLINE.matcher("");
+            String line;
+            while ((line = in.readLine()) != null && shouldContinue()) {
+                parsePosition.setIndex(0);
+                parsePosition.setLineNumber(in.getLineNumber());
+                if (!matcher.reset(line).matches()) {
+                    continue;
+                }
+
+                try {
+                    AbstractGCEvent<?> gcEvent = parseMatch(matcher);
+                    model.add(gcEvent);
+                } catch (Exception pe) {
+                    if (getLogger().isLoggable(Level.WARNING)) getLogger().warning(pe.toString());
+                    if (getLogger().isLoggable(Level.FINE)) getLogger().log(Level.FINE, pe.getMessage(), pe);
+                }
+            }
+            return model;
+        } finally {
+            if (getLogger().isLoggable(Level.INFO)) getLogger().info("Done reading.");
+        }
+    }
+
+    private AbstractGCEvent<?> parseMatch(Matcher matcher) {
+        double relativeTime = Double.parseDouble(matcher.group(2));
+        double stopTheWorld1Time = Double.parseDouble(matcher.group(4)) / 1000.0;
+        double stopTheWorld2Time = Double.parseDouble(matcher.group(6)) / 1000.0;
+        int preUsed = Integer.parseInt(matcher.group(12)) * 1024;
+        int alive = Integer.parseInt(matcher.group(13)) * 1024;
+        int postUsed = Integer.parseInt(matcher.group(14)) * 1024;
+
+        double pause = stopTheWorld1Time + stopTheWorld2Time;
+        return new GCEvent(relativeTime, preUsed, postUsed, alive, pause, AbstractGCEvent.Type.GC);
+    }
+}

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

@@ -1065,5 +1065,6 @@ public String toString() {
         public static final Format IBM_VERBOSE_GC = new Format("IBM -verbose:gc");
         public static final Format SUN_1_2_2VERBOSE_GC = new Format("Sun 1.2.2 -verbose:gc");
         public static final Format UNIFIED_JVM_LOGGING = new Format("Unified jvm logging -Xlog:gc");
+        public static final Format GO = new Format("Go");
     }
 }

src/test/java/com/tagtraum/perf/gcviewer/UnittestHelper.java

@@ -31,6 +31,7 @@ public class UnittestHelper {
 
     private static final String FOLDER_OPENJDK = "openjdk";
     public enum FOLDER {
+        GO("go"),
         HP("hp"),
         IBM("ibm"),
         JROCKIT("jrockit"),

src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderGo.java

@@ -0,0 +1,39 @@
+package com.tagtraum.perf.gcviewer.imp;
+
+import static org.junit.Assert.assertEquals;
+
+import com.tagtraum.perf.gcviewer.UnittestHelper;
+import com.tagtraum.perf.gcviewer.model.GCModel;
+import com.tagtraum.perf.gcviewer.model.GcResourceFile;
+import java.io.ByteArrayInputStream;
+import java.io.IOException;
+import java.io.InputStream;
+import org.junit.Test;
+
+public class TestDataReaderGo {
+
+    @Test
+    public void test() throws IOException {
+        String gcLog = ""
+                + "gc starting...\n" // Such a line is not produced by the Go GC; it is just for testing
+                + "gc 1 @997.597s 3%: 68+0.36+0.51 ms clock, 205+0/16/89+1.5 ms cpu, 84->84->42 MB, 86 MB goal, 3 P\n"
+                + "a line unrelated to GC logging\n"
+                + "gc 2 @997.597s 3%: 68+0.36+0.51 ms clock, 205+0/16/89+1.5 ms cpu, 11111111111111111111111111111111111->84->42 MB, 86 MB goal, 3 P\n"
+                + "gc 3 @997.597s 3%: 68+0.36+0.51 ms clock, 205+0/16/89+1.5 ms cpu, 84->84->42 MB, 86 MB goal, 3 P\n";
+        ByteArrayInputStream in = new ByteArrayInputStream(gcLog.getBytes("US-ASCII"));
+        DataReader reader = new DataReaderGo(new GcResourceFile("byteArray"), in);
+        GCModel model = reader.read();
+
+        assertEquals(2, model.size());
+    }
+
+    @Test
+    public void exampleLog() throws IOException {
+        String fileName = "go1.9.txt";
+        InputStream in = UnittestHelper.getResourceAsStream(UnittestHelper.FOLDER.GO, fileName);
+        DataReader reader = new DataReaderGo(new GcResourceFile(fileName), in);
+        GCModel model = reader.read();
+
+        assertEquals(635, model.size());
+    }
+}