Skip to content

Commit

Permalink
feat: gc log analyzer supports metric (#237)
Browse files Browse the repository at this point in the history
  • Loading branch information
weixlu authored Nov 2, 2023
1 parent e8ffb71 commit 3677aca
Show file tree
Hide file tree
Showing 41 changed files with 2,435 additions and 1,164 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -32,4 +32,12 @@ public String toString() {
return String.format("User=%.2fs Sys=%.2fs Real=%.2fs", user / 1000, sys / 1000, real / 1000);
}

public double getValue(String type) {
return switch (type) {
case "USER" -> user;
case "SYS" -> sys;
case "REAL" -> real;
default -> 0;
};
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,134 @@
/********************************************************************************
* Copyright (c) 2023 Contributors to the Eclipse Foundation
*
* See the NOTICE file(s) distributed with this work for additional
* information regarding copyright ownership.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0
*
* SPDX-License-Identifier: EPL-2.0
********************************************************************************/
package org.eclipse.jifa.gclog.fragment;

import com.google.common.collect.ImmutableSet;

import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.util.Comparator;
import java.util.List;
import java.util.Set;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

public class Context {
private List<String> context;
private final ContextComparator contextComparator = new ContextComparator();

/* to match the following timestamp pattern:
[2023-08-25T14:28:44.980+0800][0.076s] GC(374) Pause Mark Start 4.459ms
2022-11-28T14:57:05.341+0800: 6.340: [CMS-concurrent-mark-start]
[7.006s] GC(374) Pause Mark Start 4.459ms
675.461: [CMS-concurrent-mark-start]
*/
static Pattern[] timestampPatternToChoose = {
Pattern.compile("\\[[\\d-T:+.]+]\\[(\\d+\\.\\d+)s][\\s\\S]*"),
Pattern.compile("[\\d-T:+.]+ (\\d+\\.\\d+): \\[[\\s\\S]*"),
Pattern.compile("\\[(\\d+\\.\\d+)s][\\s\\S]*"),
Pattern.compile("(\\d+\\.\\d+): \\[[\\s\\S]*")
};
private Pattern timestampPattern;

public Context(List<String> context) throws RuntimeException{
this.context = context;
selectTimestampPattern();
sort();
}

public BufferedReader toBufferedReader() {
String joinedString = String.join("\n", context);
InputStream inputStream = new ByteArrayInputStream(joinedString.getBytes());
return new BufferedReader(new InputStreamReader(inputStream));
}

private void selectTimestampPattern() throws RuntimeException{
for (String str : context) {
for (Pattern pattern : timestampPatternToChoose) {
if (pattern.matcher(str).matches()) {
timestampPattern = pattern;
return;
}
}
}
throw new RuntimeException("fail to parse timestamp");
}

class ContextComparator implements Comparator<String> {

static Set<String> precedentPatternSet = new ImmutableSet.Builder<String>()
.add("Pause Young", "Pause Initial Mark", "CMS Initial Mark", "Concurrent Cycle", "Concurrent Mark").build();

boolean isPrecedent(String str) {
return precedentPatternSet.stream().anyMatch(str::contains);
}
/*
return value:
1: place string2 in prior to string1
-1: place string1 in prior to string2
*/
@Override
public int compare(String o1, String o2) {
Matcher matcher;
String timestampString1, timestampString2;
if ((matcher = timestampPattern.matcher(o1)).matches()) {
timestampString1 = matcher.group(1);
} else {
// string2 in prior to string1:
// string1 doesn't match, thus place it at the tail of the list.
return 1;
}
if ((matcher = timestampPattern.matcher(o2)).matches()) {
timestampString2 = matcher.group(1);
} else {
// place string1 in prior to string2:
// string2 doesn't match, thus place string1 before it.
return -1;
}
//return Double.parseDouble(timestampString1) > Double.parseDouble(timestampString2) ? 1 : -1;
if (timestampString1.equals(timestampString2)) {
if (isPrecedent(o1)) {
// place string1 in prior to string2:
return -1;
}
if (isPrecedent(o2)) {
// place string2 in prior to string1:
return 1;
}
return 0;
} else {
return Double.parseDouble(timestampString1) > Double.parseDouble(timestampString2) ? 1 : -1;
}
}
}

private void sort() {
context.sort(contextComparator);
}

// for debug
private void checkStartWithTimeStamp() {
for (String str : context) {
if (!timestampPattern.matcher(str).matches()) {
throw new RuntimeException("found invalid string which doesn't start with a required timestamp: " + str);
}
}
}

// for debug
private void filterInvalidFragment() {
context.removeIf(str -> !timestampPattern.matcher(str).matches());
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,79 @@
/********************************************************************************
* Copyright (c) 2023 Contributors to the Eclipse Foundation
*
* See the NOTICE file(s) distributed with this work for additional
* information regarding copyright ownership.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0
*
* SPDX-License-Identifier: EPL-2.0
********************************************************************************/
package org.eclipse.jifa.gclog.fragment;

import lombok.NoArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.eclipse.jifa.gclog.model.GCModel;
import org.eclipse.jifa.gclog.parser.GCLogParser;
import org.eclipse.jifa.gclog.parser.GCLogParserFactory;

import java.io.*;
import java.util.*;
import java.util.concurrent.ConcurrentHashMap;

@NoArgsConstructor
@Slf4j
public class GCLogAnalyzer {
private final Map<Map<String, String>, GCLogParser> parserMap = new ConcurrentHashMap<>();

public List<Metric> parseToMetrics(List<String> rawContext, Map<String, String> instanceId, long startTime, long endTime) throws Exception {
Context context = new Context(rawContext);
BufferedReader br = context.toBufferedReader();
GCLogParser parser = selectParser(instanceId, br);
GCModel model = parser.parse(br);
br.close();
if (!model.isEmpty()) {
model.calculateDerivedInfo(null);
return new GCModelConverter().toMetrics(model, instanceId, startTime, endTime);
}
return null;
}

public GCModel parseToGCModel(List<String> rawContext, Map<String, String> instanceId) {
Context context = new Context(rawContext);
BufferedReader br = context.toBufferedReader();
GCModel model = null;
try {
GCLogParser parser = selectParser(instanceId, br);
model = parser.parse(br);
br.close();
if (!model.isEmpty()) {
model.calculateDerivedInfo(null);
} else {
model = null;
}
} catch (Exception e) {
log.error("fail to parse context ");
log.error(e.getMessage());
model = null;
} finally {
return model;
}
}

private GCLogParser selectParser(Map<String, String> instanceId, BufferedReader br) throws IOException {
GCLogParser parser = parserMap.get(instanceId);
if (parser == null) {
GCLogParserFactory logParserFactory = new GCLogParserFactory();
// max length in hotspot
int MAX_SINGLE_LINE_LENGTH = 2048;
br.mark(GCLogParserFactory.MAX_ATTEMPT_LINE * MAX_SINGLE_LINE_LENGTH);
parser = logParserFactory.getParser(br);
br.reset();
parserMap.put(instanceId, parser);
}
return parser;
}
}

Original file line number Diff line number Diff line change
@@ -0,0 +1,132 @@
/********************************************************************************
* Copyright (c) 2023 Contributors to the Eclipse Foundation
*
* See the NOTICE file(s) distributed with this work for additional
* information regarding copyright ownership.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0
*
* SPDX-License-Identifier: EPL-2.0
********************************************************************************/
package org.eclipse.jifa.gclog.fragment;

import com.google.common.collect.ImmutableMap;
import com.google.common.collect.ImmutableSet;
import lombok.extern.slf4j.Slf4j;
import org.eclipse.jifa.gclog.event.GCEvent;
import org.eclipse.jifa.gclog.event.evnetInfo.MemoryArea;
import org.eclipse.jifa.gclog.model.GCModel;

import org.eclipse.jifa.gclog.util.Constant;

import java.util.*;

@Slf4j
public class GCModelConverter {
public List<Metric> toMetrics(GCModel gcModel, Map<String, String> instanceId, long startTime, long endTime) {
List<Metric> result = new ArrayList<>();
Map<String, String> sharedLabels = new HashMap<>(instanceId);
sharedLabels.put("gc_type", gcModel.getCollectorType().getName());
for (GCEvent gcEvent : gcModel.getGcEvents()) {
long timestamp = (long)(gcModel.getReferenceTimestamp() + gcEvent.getStartTime());
if (timestamp >= startTime && timestamp < endTime) {
result.addAll(new GCEventConverter().toMetrics(gcEvent, timestamp, sharedLabels));
}
}
return result;
}

private class GCEventConverter {
private GCEvent gcEvent;
private long timestamp;
private Map<String, String> sharedLabels;
private List<Metric> result = new ArrayList<>();

public List<Metric> toMetrics(GCEvent gcEvent, long timestamp, Map<String, String> sharedLabels) {
this.gcEvent = gcEvent;
this.timestamp = timestamp;
this.sharedLabels = sharedLabels;
addMetricCpuTime();
addMetricDuration();
addMetricMemoryUsage();
addMetricPause();
addMetricPromotion();
addMetricSubphase();
return result;
}

private Map<String, String> buildLabel() {
return sharedLabels;
}
private Map<String, String> buildLabel(String key, String value) {
Map<String, String> label = new HashMap<>(sharedLabels);
label.put(key, value);
return label;
}
private Map<String, String> buildLabel(String key1, String value1, String key2, String value2) {
Map<String, String> label = new HashMap<>(sharedLabels);
label.put(key1, value1);
label.put(key2, value2);
return label;
}

private void addMetricDuration() {
if (gcEvent.getDuration() == Constant.UNKNOWN_DOUBLE) {
return;
}
result.add(new Metric(timestamp, buildLabel(), "GC_COST_TIME", gcEvent.getDuration()));
}

private void addMetricPause() {
if (gcEvent.getPause() == Constant.UNKNOWN_DOUBLE) {
return;
}
result.add(new Metric(timestamp, buildLabel("type", gcEvent.getEventType().getName()), "GC_PAUSE_TIME", gcEvent.getPause()));
}

private void addMetricPromotion() {
if (gcEvent.getPromotion() == Constant.UNKNOWN_INT) {
return;
}
result.add(new Metric(timestamp, buildLabel(), "GC_PROMOTION", gcEvent.getPromotion()));
}

private void addMetricCpuTime() {
if (gcEvent.getCpuTime() == null) {
return;
}
final Set<String> typeSet = new ImmutableSet.Builder<String>().add("USER", "SYS", "REAL").build();
typeSet.forEach(type ->
result.add(new Metric(timestamp, buildLabel("type", type), "GC_CPU_USED", gcEvent.getCpuTime().getValue(type)))
);
}

private void addMetricMemoryUsage() {
final Map<String, MemoryArea> memoryAreaMap = new ImmutableMap.Builder<String, MemoryArea>()
.put("Young", MemoryArea.YOUNG)
.put("Old", MemoryArea.OLD)
.put("Humongous", MemoryArea.HUMONGOUS)
.put("Heap", MemoryArea.HEAP)
.put("Metaspace", MemoryArea.METASPACE)
.build();
memoryAreaMap.forEach((key, value) -> {
if (gcEvent.getMemoryItem(value) != null) {
result.add(new Metric(timestamp, buildLabel("type", key), "BEFORE_GC_REGION_SIZE", gcEvent.getMemoryItem(value).getPreUsed()));
result.add(new Metric(timestamp, buildLabel("type", key), "AFTER_GC_REGION_SIZE", gcEvent.getMemoryItem(value).getPostUsed()));
}
});
}

private void addMetricSubphase() {
if (gcEvent.getPhases() == null) {
return;
}
gcEvent.getPhases().forEach(subphase ->
result.add(new Metric(timestamp,
buildLabel("subphase", subphase.getEventType().getName(), "type", gcEvent.getEventType().getName()),
"GC_SUBPHASE_TIME", subphase.getDuration())));
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
/********************************************************************************
* Copyright (c) 2023 Contributors to the Eclipse Foundation
*
* See the NOTICE file(s) distributed with this work for additional
* information regarding copyright ownership.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0
*
* SPDX-License-Identifier: EPL-2.0
********************************************************************************/
package org.eclipse.jifa.gclog.fragment;

import lombok.AllArgsConstructor;
import lombok.Getter;

import java.util.Map;

@AllArgsConstructor
@Getter
public class Metric {
long timestamp;
Map<String, String> label;
String name;
double value;
}
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@
public class GCLogParserFactory {
// When -Xlog:gc*=trace is used, a single gc produces at most about 5000 lines of log.
// 20000 lines should be enough to cover at least one gc.
static final int MAX_ATTEMPT_LINE = 20000;
public static final int MAX_ATTEMPT_LINE = 20000;

private static final ParserMetadataRule[] rules = {
// style
Expand Down
Loading

0 comments on commit 3677aca

Please sign in to comment.