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.

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

feat: gc log analyzer supports metric #237

Merged
merged 2 commits into from
Nov 2, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
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());
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Based on current design, getReferenceTimestamp may be UNKOWN (i.e -1) if datesteamp is not printed in the log. I think this situation may require some additional handling.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As explained before, this feature requires datestamp to be printed. If not, an exception will be raised at the very beginning(i.e. before reaching here)

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)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And there is Humongous for g1

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I will add it.

.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