Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added application stopped events to JDK unified logging parser #208

Open
wants to merge 7 commits into
base: develop
Choose a base branch
from
+215 −26
Open

Added application stopped events to JDK unified logging parser #208

Changes from 1 commit
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
3560b3e
initial refactoring, using to stage pass, first we extract log event …
kcrimson Oct 26, 2018
2eab1e8
minor refactoring, code should be more readable now
kcrimson Oct 29, 2018
772c33a
fixed code style issues
kcrimson Oct 29, 2018
0e2834b
initial refactoring, using to stage pass, first we extract log event …
kcrimson Oct 26, 2018
facaa58
minor refactoring, code should be more readable now
kcrimson Oct 29, 2018
38db187
fixed code style issues
kcrimson Oct 29, 2018
e06b5e6
Merge branch 'application_stopped_unified_logging' of github.com:kcri…
kcrimson Feb 18, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
initial refactoring, using to stage pass, first we extract log event … 
…decorators and then we parse message
@kcrimson
kcrimson committed Feb 18, 2019
commit 0e2834b6485d8f9ef42d3e48f5f4aae4b1446bdf
106 changes: 86 additions & 20 deletions src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
View file
Original file line number Diff line number Diff line change
@@ -21,6 +21,7 @@
import com.tagtraum.perf.gcviewer.model.GCEventUJL;
import com.tagtraum.perf.gcviewer.model.GCModel;
import com.tagtraum.perf.gcviewer.model.GCResource;
import com.tagtraum.perf.gcviewer.model.VmOperationEvent;
import com.tagtraum.perf.gcviewer.util.DateHelper;
import com.tagtraum.perf.gcviewer.util.NumberParser;

@@ -47,6 +48,24 @@
*/
public class DataReaderUnifiedJvmLogging extends AbstractDataReader {

class LogEvent {

final String time;
final String uptime;
final String level;
final String tags;
final String message;

LogEvent(String time, String uptime, String level, String tags, String message) {
this.time = time;
this.uptime = uptime;
this.level = level;
this.tags = tags;
this.message = message;
}

}

// matches the whole line and extracts decorators from it (decorators always appear between [] and are independent of the gc algorithm being logged)
// Input: [0.693s][info][gc ] GC(0) Pause Init Mark 1.070ms
// Group 1 / time: <empty> (optional group, no full timestamp present)
@@ -57,13 +76,18 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
// Group 6 / tail: Pause Init Mark 1.070ms
// 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]*)s])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
);

private static final Pattern PATTERN_DECORATORS = Pattern.compile("^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^s]*)s])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ](?<message>.*)");

private static final Pattern PATTERN_GC_MESSAGE = Pattern.compile("^GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)");

private static final Pattern PATTERN_APPLICATION_STOPPED = Pattern.compile("^Total time for which application threads were stopped: (?<applicationstopped>[0-9]+,[0-9]+) seconds, Stopping threads took: (?<threadsstopping>[0-9]+,[0-9]+) seconds$");

private static final String GROUP_DECORATORS_TIME = "time";
private static final String GROUP_DECORATORS_UPTIME = "uptime";
private static final String GROUP_DECORATORS_LEVEL = "level";
private static final String GROUP_DECORATORS_TAGS = "tags";
private static final String GROUP_DECORATORS_MESSAGE = "message";
private static final String GROUP_DECORATORS_GC_NUMBER = "gcnumber";
private static final String GROUP_DECORATORS_GC_TYPE = "type";
private static final String GROUP_DECORATORS_TAIL = "tail";
@@ -124,13 +148,14 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
private static final String TAG_GC_METASPACE = "gc,metaspace";

/** list of strings, that must be part of the gc log line to be considered for parsing */
private static final List<String> INCLUDE_STRINGS = Arrays.asList("[gc ", "[gc]", "[" + TAG_GC_START, "[" + TAG_GC_HEAP, "[" + TAG_GC_METASPACE);
private static final List<String> INCLUDE_STRINGS = Arrays.asList("[gc ", "[gc]", "[safepoint]","[" + TAG_GC_START, "[" + TAG_GC_HEAP, "[" + TAG_GC_METASPACE);
/** list of strings, that target gc log lines, that - although part of INCLUDE_STRINGS - are not considered a gc event */
private static final List<String> EXCLUDE_STRINGS = Arrays.asList("Cancelling concurrent GC", "[debug", "[trace", "gc,heap,coops", "gc,heap,exit");
/** list of strings, that are gc log lines, but not a gc event -&gt; should be logged only */
private static final List<String> LOG_ONLY_STRINGS = Arrays.asList("Using", "Heap region size");



protected DataReaderUnifiedJvmLogging(GCResource gcResource, InputStream in) throws UnsupportedEncodingException {
super(gcResource, in);
}
@@ -162,25 +187,65 @@ public GCModel read() throws IOException {

private ParseContext parseEvent(ParseContext context) {
AbstractGCEvent<?> event = null;

Matcher decoratorsMatcher = PATTERN_DECORATORS.matcher(context.getLine());
try {
event = createGcEventWithStandardDecorators(decoratorsMatcher, context.getLine());
if (event != null) {
String tags = decoratorsMatcher.group(GROUP_DECORATORS_TAGS);
String tail = decoratorsMatcher.group(GROUP_DECORATORS_TAIL);
event = handleTail(context, event, tags, tail);
String line = context.getLine();

// extract log decorators (like time stamp, up time, level, tags and message)
Matcher eventDecoratorsMatcher = PATTERN_DECORATORS.matcher(line );
LogEvent logEvent = createLogEvent(eventDecoratorsMatcher);

if (logEvent==null) {
getLogger().warning(String.format("Failed to parse line number %d (no match; line=\"%s\")", in.getLineNumber(), line));
} else {
String message = logEvent.message;
Matcher decoratorsMatcher = PATTERN_GC_MESSAGE.matcher(message);
try {
event = createGcEventWithStandardDecorators(logEvent, decoratorsMatcher, context.getLine());
if (event != null) {
String tags = logEvent.tags;
String tail = decoratorsMatcher.group(GROUP_DECORATORS_TAIL);
event = handleTail(context, event, tags, tail);
} else {
Matcher applicationStoppedMAtcher = PATTERN_APPLICATION_STOPPED.matcher(logEvent.message);
event = parseSafepointEvent(logEvent,applicationStoppedMAtcher,line);
}
} catch (UnknownGcTypeException | NumberFormatException e) {
// prevent incomplete event from being added to the GCModel
event = null;
getLogger().warning(String.format("Failed to parse gc event (%s) on line number %d (line=\"%s\")", e.toString(), in.getLineNumber(), context.getLine()));
}
} catch (UnknownGcTypeException | NumberFormatException e) {
// prevent incomplete event from being added to the GCModel
event = null;
getLogger().warning(String.format("Failed to parse gc event (%s) on line number %d (line=\"%s\")", e.toString(), in.getLineNumber(), context.getLine()));
}


context.setCurrentEvent(event);
return context;
}

private AbstractGCEvent<?> parseSafepointEvent(LogEvent logEvent, Matcher applicationStoppedMatcher, String line) {
if (applicationStoppedMatcher.matches()) {
AbstractGCEvent<?> event = new VmOperationEvent();
event.setType(Type.APPLICATION_STOPPED_TIME);
setPause(event, applicationStoppedMatcher.group("applicationstopped"));
setDateStampIfPresent(event, logEvent.time);
setTimeStampIfPresent(event, logEvent.uptime);
return event;
} else {
getLogger().warning(String.format("Failed to parse line number %d (no match; line=\"%s\")", in.getLineNumber(), line));
return null;
}
}

private LogEvent createLogEvent(Matcher eventDecoratorsMatcher) {
if(eventDecoratorsMatcher.matches()) {
String time = eventDecoratorsMatcher.group( GROUP_DECORATORS_TIME );
String uptime = eventDecoratorsMatcher.group( GROUP_DECORATORS_UPTIME );
String level = eventDecoratorsMatcher.group( GROUP_DECORATORS_LEVEL );
String tags = eventDecoratorsMatcher.group( GROUP_DECORATORS_TAGS );
String message = eventDecoratorsMatcher.group( GROUP_DECORATORS_MESSAGE );
return new LogEvent(time,uptime,level,tags,message);
}
return null;
}

private AbstractGCEvent<?> handleTail(ParseContext context, AbstractGCEvent<?> event, String tags, String tail) {
AbstractGCEvent<?> returnEvent = event;
switch (tags) {
@@ -321,19 +386,20 @@ private void parseGcRegionTail(ParseContext context, AbstractGCEvent<?> event, S
/**
* Returns an instance of AbstractGcEvent (GCEvent or ConcurrentGcEvent) with all decorators present filled in
* or <code>null</code> if the line could not be matched.
* @param logEvent
* @param decoratorsMatcher matcher for decorators to be used for GcEvent creation
* @param line current line to be parsed
* @return Instance of <code>AbstractGcEvent</code> or <code>null</code> if the line could not be matched.
*/
private AbstractGCEvent<?> createGcEventWithStandardDecorators(Matcher decoratorsMatcher, String line) throws UnknownGcTypeException {
if (decoratorsMatcher.find()) {
private AbstractGCEvent<?> createGcEventWithStandardDecorators(LogEvent logEvent, Matcher decoratorsMatcher, String line) throws UnknownGcTypeException {
if (decoratorsMatcher.matches()) {
AbstractGCEvent.ExtendedType type = getDataReaderTools().parseType(decoratorsMatcher.group(GROUP_DECORATORS_GC_TYPE));

AbstractGCEvent<?> event = type.getConcurrency().equals(Concurrency.CONCURRENT) ? new ConcurrentGCEvent() : new GCEventUJL();
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));
setDateStampIfPresent(event, logEvent.time);
setTimeStampIfPresent(event, logEvent.uptime);
return event;
} else {
getLogger().warning(String.format("Failed to parse line number %d (no match; line=\"%s\")", in.getLineNumber(), line));
95 changes: 95 additions & 0 deletions src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLSafepoint.java
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
package com.tagtraum.perf.gcviewer.imp;

import com.tagtraum.perf.gcviewer.UnittestHelper;
import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
import com.tagtraum.perf.gcviewer.model.AbstractGCEvent;
import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Generation;
import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Type;
import com.tagtraum.perf.gcviewer.model.GCModel;
import org.junit.Ignore;
import org.junit.Test;

import java.io.IOException;

import static org.hamcrest.Matchers.is;
import static org.junit.Assert.assertThat;

/**
* Tests unified jvm logging parser for safepoint events.
*/
public class TestDataReaderUJLSafepoint {
private GCModel getGCModelFromLogFile(String fileName) throws IOException {
return UnittestHelper.getGCModelFromLogFile(fileName, FOLDER.OPENJDK_UJL, DataReaderUnifiedJvmLogging.class);
}

@Test
public void parseGcDefaults() throws Exception {
GCModel model = getGCModelFromLogFile("sample-ujl-safepoint-defaults.txt");
assertThat("size", model.size(), is(16));
assertThat("amount of gc event types", model.getGcEventPauses().size(), is(3));
assertThat("amount of gc events", model.getGCPause().getN(), is(5));
assertThat("amount of full gc event types", model.getFullGcEventPauses().size(), is(1));
assertThat("amount of full gc events", model.getFullGCPause().getN(), is(1));
assertThat("amount of concurrent pause types", model.getConcurrentEventPauses().size(), is(5));


UnittestHelper.testMemoryPauseEvent(model.get(0),
"young",
Type.UJL_PAUSE_YOUNG,
0.008822,
1024 * 41, 1024 * 38,1024 * 150,
Generation.YOUNG,
false);

UnittestHelper.testMemoryPauseEvent(model.get(0),
"young",
Type.UJL_PAUSE_YOUNG,
0.008822,
1024 * 41, 1024 * 38,1024 * 150,
Generation.YOUNG,
false);

AbstractGCEvent<?> event2 = model.get(1);
UnittestHelper.testMemoryPauseEvent(event2,
"initialMarkEvent",
Type.UJL_PAUSE_INITIAL_MARK,
0.000136,
1024 * 61, 1024 * 61,1024 * 150,
Generation.TENURED,
false);
assertThat("isInitialMark", event2.isInitialMark(), is(true));

AbstractGCEvent<?> event3 = model.get(10);
UnittestHelper.testMemoryPauseEvent(event3,
"RemarkEvent",
Type.UJL_PAUSE_REMARK,
0.000859,
1024 * 110, 1024 * 110,1024 * 150,
Generation.TENURED,
false);
assertThat("isRemark", event3.isRemark(), is(true));

AbstractGCEvent<?> event4 = model.get(15);
UnittestHelper.testMemoryPauseEvent(event4,
"full",
Type.UJL_PAUSE_FULL,
0.009775,
1024 * 125, 1024 * 31, 1024 * 150,
Generation.ALL,
true);

AbstractGCEvent<?> concurrentMarkBeginEvent = model.get(2);
assertThat("event is not start of concurrent collection", concurrentMarkBeginEvent.isConcurrentCollectionStart(), is(false));

AbstractGCEvent<?> concurrentMarkWithPauseEvent = model.get(3);
assertThat("event is start of concurrent collection", concurrentMarkWithPauseEvent.isConcurrentCollectionStart(), is(true));

AbstractGCEvent<?> concurrentResetBeginEvent = model.get(13);
assertThat("event is not end of concurrent collection", concurrentResetBeginEvent.isConcurrentCollectionEnd(), is(false));

AbstractGCEvent<?> concurrentResetEvent = model.get(14);
assertThat("event is end of concurrent collection", concurrentResetEvent.isConcurrentCollectionEnd(), is(true));

}

}
73 changes: 73 additions & 0 deletions src/test/resources/openjdk/unified-jvm-logging/sample-ujl-safepoint-defaults.txt
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,73 @@
[2018-10-10T17:09:33.823+0200][0.022s][info][gc] Using G1
[2018-10-10T17:09:33.877+0200][0,077s][info][safepoint] Total time for which application threads were stopped: 0,0000235 seconds, Stopping threads took: 0,0000015 seconds
[2018-10-10T17:09:33.889+0200][0,089s][info][safepoint] Application time: 0,0118190 seconds
[2018-10-10T17:09:33.889+0200][0,089s][info][safepoint] Total time for which application threads were stopped: 0,0000495 seconds, Stopping threads took: 0,0000022 seconds
[2018-10-10T17:09:33.891+0200][0,091s][info][safepoint] Application time: 0,0020922 seconds
[2018-10-10T17:09:33.891+0200][0,091s][info][safepoint] Total time for which application threads were stopped: 0,0000211 seconds, Stopping threads took: 0,0000022 seconds
[2018-10-10T17:09:33.892+0200][0,092s][info][safepoint] Application time: 0,0008629 seconds
[2018-10-10T17:09:33.892+0200][0,092s][info][safepoint] Total time for which application threads were stopped: 0,0001209 seconds, Stopping threads took: 0,0001051 seconds
[2018-10-10T17:09:33.948+0200][0,147s][info][safepoint] Application time: 0,0550227 seconds
[2018-10-10T17:09:33.952+0200][0,151s][info][gc ] GC(0) Pause Young (G1 Evacuation Pause) 24M->4M(250M) 3,496ms
[2018-10-10T17:09:33.952+0200][0,151s][info][safepoint] Total time for which application threads were stopped: 0,0036337 seconds, Stopping threads took: 0,0000452 seconds
[2018-10-10T17:09:33.958+0200][0,157s][info][safepoint] Application time: 0,0062028 seconds
[2018-10-10T17:09:33.958+0200][0,157s][info][safepoint] Total time for which application threads were stopped: 0,0001133 seconds, Stopping threads took: 0,0000901 seconds
[2018-10-10T17:09:33.958+0200][0,157s][info][safepoint] Application time: 0,0000222 seconds
[2018-10-10T17:09:33.958+0200][0,158s][info][safepoint] Total time for which application threads were stopped: 0,0000353 seconds, Stopping threads took: 0,0000221 seconds
[2018-10-10T17:09:33.966+0200][0,165s][info][safepoint] Application time: 0,0076620 seconds
[2018-10-10T17:09:33.976+0200][0,176s][info][gc ] GC(1) Pause Young (G1 Evacuation Pause) 151M->27M(250M) 10,363ms
[2018-10-10T17:09:33.976+0200][0,176s][info][safepoint] Total time for which application threads were stopped: 0,0104689 seconds, Stopping threads took: 0,0000132 seconds
[2018-10-10T17:09:33.978+0200][0,178s][info][safepoint] Application time: 0,0019993 seconds
[2018-10-10T17:09:33.986+0200][0,185s][info][gc ] GC(2) Pause Young (G1 Evacuation Pause) 74M->35M(250M) 7,049ms
[2018-10-10T17:09:33.986+0200][0,185s][info][safepoint] Total time for which application threads were stopped: 0,0072140 seconds, Stopping threads took: 0,0000628 seconds
[2018-10-10T17:09:33.991+0200][0,190s][info][safepoint] Application time: 0,0055349 seconds
[2018-10-10T17:09:33.998+0200][0,197s][info][gc ] GC(3) Pause Young (G1 Evacuation Pause) 149M->62M(250M) 6,491ms
[2018-10-10T17:09:33.998+0200][0,197s][info][safepoint] Total time for which application threads were stopped: 0,0065900 seconds, Stopping threads took: 0,0000232 seconds
[2018-10-10T17:09:34.001+0200][0,201s][info][safepoint] Application time: 0,0036755 seconds
[2018-10-10T17:09:34.010+0200][0,209s][info][gc ] GC(4) Pause Young (G1 Evacuation Pause) 152M->78M(528M) 8,153ms
[2018-10-10T17:09:34.010+0200][0,209s][info][safepoint] Total time for which application threads were stopped: 0,0082641 seconds, Stopping threads took: 0,0000321 seconds
[2018-10-10T17:09:34.050+0200][0,250s][info][safepoint] Application time: 0,0404274 seconds
[2018-10-10T17:09:34.056+0200][0,255s][info][gc ] GC(5) Pause Young (G1 Evacuation Pause) 364M->105M(528M) 5,773ms
[2018-10-10T17:09:34.056+0200][0,255s][info][safepoint] Total time for which application threads were stopped: 0,0058898 seconds, Stopping threads took: 0,0000181 seconds
[2018-10-10T17:09:34.067+0200][0,267s][info][safepoint] Application time: 0,0113116 seconds
[2018-10-10T17:09:34.077+0200][0,277s][info][gc ] GC(6) Pause Young (G1 Evacuation Pause) 378M->134M(528M) 9,668ms
[2018-10-10T17:09:34.077+0200][0,277s][info][safepoint] Total time for which application threads were stopped: 0,0098035 seconds, Stopping threads took: 0,0000481 seconds
[2018-10-10T17:09:34.087+0200][0,286s][info][safepoint] Application time: 0,0098326 seconds
[2018-10-10T17:09:34.095+0200][0,294s][info][gc ] GC(7) Pause Young (G1 Evacuation Pause) 355M->160M(528M) 7,487ms
[2018-10-10T17:09:34.095+0200][0,294s][info][safepoint] Total time for which application threads were stopped: 0,0076406 seconds, Stopping threads took: 0,0000551 seconds
[2018-10-10T17:09:34.108+0200][0,307s][info][safepoint] Application time: 0,0128880 seconds
[2018-10-10T17:09:34.125+0200][0,324s][info][gc ] GC(8) Pause Young (G1 Evacuation Pause) 346M->188M(1391M) 16,934ms
[2018-10-10T17:09:34.125+0200][0,324s][info][safepoint] Total time for which application threads were stopped: 0,0170773 seconds, Stopping threads took: 0,0000110 seconds
[2018-10-10T17:09:34.199+0200][0,398s][info][safepoint] Application time: 0,0740680 seconds
[2018-10-10T17:09:34.211+0200][0,410s][info][gc ] GC(9) Pause Young (G1 Evacuation Pause) 820M->260M(1391M) 11,688ms
[2018-10-10T17:09:34.211+0200][0,410s][info][safepoint] Total time for which application threads were stopped: 0,0118661 seconds, Stopping threads took: 0,0000682 seconds
[2018-10-10T17:09:34.247+0200][0,446s][info][safepoint] Application time: 0,0357840 seconds
[2018-10-10T17:09:34.265+0200][0,465s][info][gc ] GC(10) Pause Young (G1 Evacuation Pause) 976M->270M(1391M) 18,726ms
[2018-10-10T17:09:34.265+0200][0,465s][info][safepoint] Total time for which application threads were stopped: 0,0188810 seconds, Stopping threads took: 0,0000239 seconds
[2018-10-10T17:09:34.297+0200][0,496s][info][safepoint] Application time: 0,0310386 seconds
[2018-10-10T17:09:34.311+0200][0,511s][info][gc ] GC(11) Pause Young (G1 Evacuation Pause) 990M->314M(1391M) 14,837ms
[2018-10-10T17:09:34.312+0200][0,511s][info][safepoint] Total time for which application threads were stopped: 0,0149630 seconds, Stopping threads took: 0,0000093 seconds
[2018-10-10T17:09:34.340+0200][0,539s][info][safepoint] Application time: 0,0282094 seconds
[2018-10-10T17:09:34.372+0200][0,571s][info][gc ] GC(12) Pause Young (G1 Evacuation Pause) 984M->419M(2428M) 31,622ms
[2018-10-10T17:09:34.372+0200][0,571s][info][safepoint] Total time for which application threads were stopped: 0,0317558 seconds, Stopping threads took: 0,0000101 seconds
[2018-10-10T17:09:34.528+0200][0,727s][info][safepoint] Application time: 0,1560104 seconds
[2018-10-10T17:09:34.548+0200][0,748s][info][gc ] GC(13) Pause Young (G1 Evacuation Pause) 1778M->473M(2428M) 20,424ms
[2018-10-10T17:09:34.548+0200][0,748s][info][safepoint] Total time for which application threads were stopped: 0,0206292 seconds, Stopping threads took: 0,0000112 seconds
[2018-10-10T17:09:34.604+0200][0,804s][info][safepoint] Application time: 0,0559395 seconds
[2018-10-10T17:09:34.637+0200][0,837s][info][gc ] GC(14) Pause Young (G1 Evacuation Pause) 1769M->537M(2428M) 32,996ms
[2018-10-10T17:09:34.637+0200][0,837s][info][safepoint] Total time for which application threads were stopped: 0,0331996 seconds, Stopping threads took: 0,0000114 seconds
[2018-10-10T17:09:34.695+0200][0,895s][info][safepoint] Application time: 0,0580040 seconds
[2018-10-10T17:09:34.729+0200][0,928s][info][gc ] GC(15) Pause Young (G1 Evacuation Pause) 1746M->590M(2428M) 33,492ms
[2018-10-10T17:09:34.729+0200][0,929s][info][safepoint] Total time for which application threads were stopped: 0,0336745 seconds, Stopping threads took: 0,0000104 seconds
[2018-10-10T17:09:34.781+0200][0,981s][info][safepoint] Application time: 0,0519908 seconds
[2018-10-10T17:09:34.817+0200][1,017s][info][gc ] GC(16) Pause Young (G1 Evacuation Pause) 1749M->626M(3050M) 35,972ms
[2018-10-10T17:09:34.817+0200][1,017s][info][safepoint] Total time for which application threads were stopped: 0,0362033 seconds, Stopping threads took: 0,0000112 seconds
[2018-10-10T17:09:34.933+0200][1,132s][info][safepoint] Application time: 0,1150617 seconds
[2018-10-10T17:09:34.961+0200][1,161s][info][gc ] GC(17) Pause Young (G1 Evacuation Pause) 2066M->675M(3050M) 28,515ms
[2018-10-10T17:09:34.961+0200][1,161s][info][safepoint] Total time for which application threads were stopped: 0,0287366 seconds, Stopping threads took: 0,0000249 seconds
[2018-10-10T17:09:35.030+0200][1,229s][info][safepoint] Application time: 0,0688478 seconds
[2018-10-10T17:09:35.068+0200][1,267s][info][gc ] GC(18) Pause Young (G1 Evacuation Pause) 2124M->730M(3050M) 37,778ms
[2018-10-10T17:09:35.068+0200][1,267s][info][safepoint] Total time for which application threads were stopped: 0,0379313 seconds, Stopping threads took: 0,0000207 seconds
[2018-10-10T17:09:35.126+0200][1,326s][info][safepoint] Application time: 0,0583244 seconds
[2018-10-10T17:09:35.158+0200][1,357s][info][gc ] GC(19) Pause Young (G1 Evacuation Pause) 2103M->778M(3050M) 31,486ms
[2018-10-10T17:09:35.158+0200][1,357s][info][safepoint] Total time for which application threads were stopped: 0,0316063 seconds, Stopping threads took: 0,0000080 seconds
[2018-10-10T17:09:35.191+0200][1,390s][info][safepoint] Application time: 0,0326633 seconds