From bcf6584813a2a2f40d3f72ac9168da14ac4aa4cf Mon Sep 17 00:00:00 2001
From: chewiebug <jwu@gmx.ch>
Date: Tue, 17 Sep 2019 22:48:19 +0200
Subject: [PATCH] #228 small refactoring of uptimeunit detection

---
 .../imp/DataReaderUnifiedJvmLogging.java      | 17 +++---
 .../imp/TestDataReaderUJLG1JDK12.java         | 53 +++++++++++++++++++
 2 files changed, 61 insertions(+), 9 deletions(-)
 create mode 100644 src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK12.java

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
index 706efaf6..edc973d9 100644
--- a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
+++ b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
@@ -59,10 +59,11 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
     // Regex: ^(?:\[(?<time>[0-9-T:.+]*)])?(?:\[(?<uptime>[^s]*)s])?\[(?<level>[^]]+)]\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\((?<gcnumber>[0-9]+)\)[ ](?<type>([-.a-zA-Z ()]+|[a-zA-Z1 ()]+))(?:(?:[ ](?<tail>[0-9]{1}.*))|$)
     //   note for the <type> part: easiest would have been to use [^0-9]+, but the G1 events don't fit there, because of the number in their name
     private static final Pattern PATTERN_DECORATORS = Pattern.compile(
-            "^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^s]*)m?s])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>(?:Phase [0-9]{1}: [a-zA-Z ]+)|[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
+            "^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^ms]*)(?<uptimeunit>m?s)])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>(?:Phase [0-9]{1}: [a-zA-Z ]+)|[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
     );
     private static final String GROUP_DECORATORS_TIME = "time";
     private static final String GROUP_DECORATORS_UPTIME = "uptime";
+    private static final String GROUP_DECORATORS_UPTIME_UNIT = "uptimeunit";
     private static final String GROUP_DECORATORS_LEVEL = "level";
     private static final String GROUP_DECORATORS_TAGS = "tags";
     private static final String GROUP_DECORATORS_GC_NUMBER = "gcnumber";
@@ -451,7 +452,7 @@ private AbstractGCEvent<?> createGcEventWithStandardDecorators(Matcher decorator
             event.setExtendedType(type);
             event.setNumber(Integer.parseInt(decoratorsMatcher.group(GROUP_DECORATORS_GC_NUMBER)));
             setDateStampIfPresent(event, decoratorsMatcher.group(GROUP_DECORATORS_TIME));
-            setTimeStampIfPresent(event, decoratorsMatcher.group(GROUP_DECORATORS_UPTIME));
+            setTimeStampIfPresent(event, decoratorsMatcher.group(GROUP_DECORATORS_UPTIME), decoratorsMatcher.group(GROUP_DECORATORS_UPTIME_UNIT));
             return event;
         } else {
             getLogger().warning(String.format("Failed to parse line number %d (no match; line=\"%s\")", in.getLineNumber(), line));
@@ -503,15 +504,13 @@ private void setDateStampIfPresent(AbstractGCEvent<?> event, String dateStampAsS
         }
     }
 
-    private void setTimeStampIfPresent(AbstractGCEvent<?> event, String timeStampAsString) {
+    private void setTimeStampIfPresent(AbstractGCEvent<?> event, String timeStampAsString, String timeUnit) {
         if (timeStampAsString != null && timeStampAsString.length() > 0) {
-            double ts;
-            if (timeStampAsString.endsWith("m")) {
-                ts = NumberParser.parseDouble(timeStampAsString.substring(0, timeStampAsString.length()-1)) / 1000;
-            } else {
-                ts = NumberParser.parseDouble(timeStampAsString);
+            double timestamp = NumberParser.parseDouble(timeStampAsString);
+            if ("ms".equals(timeUnit)) {
+                timestamp = timestamp / 1000;
             }
-            event.setTimestamp(ts);
+            event.setTimestamp(timestamp);
         }
     }
 
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK12.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK12.java
new file mode 100644
index 00000000..b30d4d7e
--- /dev/null
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK12.java
@@ -0,0 +1,53 @@
+package com.tagtraum.perf.gcviewer.imp;
+
+import static org.hamcrest.Matchers.closeTo;
+import static org.hamcrest.Matchers.containsString;
+import static org.hamcrest.Matchers.is;
+import static org.junit.Assert.assertThat;
+
+import java.io.ByteArrayInputStream;
+import java.io.InputStream;
+import java.util.logging.Level;
+
+import com.tagtraum.perf.gcviewer.model.GCModel;
+import com.tagtraum.perf.gcviewer.model.GCResource;
+import com.tagtraum.perf.gcviewer.model.GcResourceFile;
+import org.junit.Test;
+
+/**
+ * Test unified java logging G1 algorithm in OpenJDK 12
+ */
+public class TestDataReaderUJLG1JDK12 {
+    @Test
+    public void testG1ArchiveRegions() throws Exception {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[2019-09-16T20:06:59.836+0000][0.153s][info][gc,start     ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)\n" +
+                        "[2019-09-16T20:06:59.836+0000][0.153s][info][gc,task      ] GC(0) Using 2 workers of 2 for evacuation\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,phases    ] GC(0)   Evacuate Collection Set: 3.1ms\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.7ms\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,phases    ] GC(0)   Other: 0.4ms\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,heap      ] GC(0) Eden regions: 7->0(4)\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,heap      ] GC(0) Survivor regions: 0->1(1)\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,heap      ] GC(0) Old regions: 0->6\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,heap      ] GC(0) Archive regions: 2->2\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,heap      ] GC(0) Humongous regions: 0->0\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,metaspace ] GC(0) Metaspace: 189K->189K(1056768K)\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc           ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 7M->7M(34M) 4.379ms\n" +
+                        "[2019-09-16T20:06:59.840+0000][0.157s][info][gc,cpu       ] GC(0) User=0.00s Sys=0.01s Real=0.01s\n")
+                        .getBytes());
+
+        DataReader reader = new DataReaderUnifiedJvmLogging(gcResource, in);
+        GCModel model = reader.read();
+
+        assertThat("number of warnings", handler.getCount(), is(0));
+        assertThat("number of events", model.size(), is(1));
+        assertThat("pause", model.get(0).getPause(), closeTo(0.004379, 0.0000001));
+        assertThat("name", model.get(0).getTypeAsString(), containsString("Archive regions"));
+    }
+
+}