Skip to content

Commit

Permalink
#228 small refactoring of uptimeunit detection
Browse files Browse the repository at this point in the history
  • Loading branch information
@chewiebug
chewiebug committed Sep 17, 2019
1 parent 30f85bd commit 53dfe45
Show file tree
Hide file tree
Showing 2 changed files with 68 additions and 9 deletions.
17 changes: 8 additions & 9 deletions src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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";
Expand Down Expand Up @@ -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));
Expand Down Expand Up @@ -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);
}
}

Expand Down
60 changes: 60 additions & 0 deletions src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK12.java
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
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.IOException;
import java.io.InputStream;
import java.util.logging.Level;

import com.tagtraum.perf.gcviewer.UnittestHelper;
import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
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 {
private GCModel getGCModelFromLogFile(String fileName) throws IOException {
return UnittestHelper.getGCModelFromLogFile(fileName, FOLDER.OPENJDK_UJL, DataReaderUnifiedJvmLogging.class);
}

@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"));
}

}

0 comments on commit 53dfe45

Please sign in to comment.