Skip to content

Commit 6b09724

Browse files
shipilevshipilev
authored
7903450: JMH: Improve -prof perfnorm accuracy with robust estimations
1 parent d88f901 commit 6b09724

File tree

1 file changed

+118
-133
lines changed

1 file changed

+118
-133
lines changed

‎jmh-core/src/main/java/org/openjdk/jmh/profile/LinuxPerfNormProfiler.java

Lines changed: 118 additions & 133 deletions
Original file line numberDiff line numberDiff line change
@@ -60,9 +60,8 @@ public class LinuxPerfNormProfiler implements ExternalProfiler {
6060
private final int delayMs;
6161
private final int lengthMs;
6262
private final boolean useDefaultStats;
63-
private final long highPassFilter;
6463
private final int incrementInterval;
65-
private final boolean isIncrementable;
64+
private final boolean doFilter;
6665

6766
private final Collection<String> supportedEvents = new ArrayList<>();
6867

@@ -87,9 +86,9 @@ public LinuxPerfNormProfiler(String initLine) throws ProfilerException {
8786
"Lower values may improve accuracy, while increasing the profiling overhead.")
8887
.withRequiredArg().ofType(Integer.class).describedAs("ms").defaultsTo(100);
8988

90-
OptionSpec<Long> optHighPassFilter = parser.accepts("highPassFilter",
91-
"Ignore event increments larger that this.")
92-
.withRequiredArg().ofType(Long.class).describedAs("#").defaultsTo(100_000_000_000L);
89+
OptionSpec<Boolean> optFilter = parser.accepts("filter",
90+
"Filter problematic samples from infrastructure and perf itself.")
91+
.withRequiredArg().ofType(Boolean.class).describedAs("bool").defaultsTo(true);
9392

9493
OptionSpec<Boolean> optDefaultStat = parser.accepts("useDefaultStat",
9594
"Use \"perf stat -d -d -d\" instead of explicit counter list.")
@@ -103,7 +102,7 @@ public LinuxPerfNormProfiler(String initLine) throws ProfilerException {
103102
delayMs = set.valueOf(optDelay);
104103
lengthMs = set.valueOf(optLength);
105104
incrementInterval = set.valueOf(optIncrementInterval);
106-
highPassFilter = set.valueOf(optHighPassFilter);
105+
doFilter = set.valueOf(optFilter);
107106
useDefaultStats = set.valueOf(optDefaultStat);
108107
userEvents = set.valuesOf(optEvents);
109108
} catch (OptionException e) {
@@ -116,7 +115,9 @@ public LinuxPerfNormProfiler(String initLine) throws ProfilerException {
116115
}
117116

118117
Collection<String> incremental = Utils.tryWith(PerfSupport.PERF_EXEC, "stat", "--log-fd", "2", "--field-separator", ",", "--interval-print", String.valueOf(incrementInterval), "echo", "1");
119-
isIncrementable = incremental.isEmpty();
118+
if (!incremental.isEmpty()) {
119+
throw new ProfilerException("\\\"perf\\\" is too old, needs incremental mode (-I).");
120+
}
120121

121122
Collection<String> candidateEvents = new ArrayList<>();
122123
if (userEvents != null) {
@@ -126,7 +127,7 @@ public LinuxPerfNormProfiler(String initLine) throws ProfilerException {
126127
}
127128
}
128129

129-
if (supportedEvents.isEmpty()) {
130+
if (candidateEvents.isEmpty()) {
130131
candidateEvents.addAll(Arrays.asList(interestingEvents));
131132
}
132133

@@ -154,9 +155,7 @@ public Collection<String> addJVMInvokeOptions(BenchmarkParams params) {
154155
} else {
155156
cmd.addAll(Arrays.asList(PerfSupport.PERF_EXEC, "stat", "--log-fd", "2", "--field-separator", ",", "--event", Utils.join(supportedEvents, ",")));
156157
}
157-
if (isIncrementable) {
158-
cmd.addAll(Arrays.asList("-I", String.valueOf(incrementInterval)));
159-
}
158+
cmd.addAll(Arrays.asList("-I", String.valueOf(incrementInterval)));
160159
return cmd;
161160
}
162161

@@ -190,8 +189,17 @@ public String getDescription() {
190189
return "Linux perf statistics, normalized by operation count";
191190
}
192191

192+
private static class EventRecord {
193+
final double time;
194+
final double value;
195+
public EventRecord(double time, double value) {
196+
this.time = time;
197+
this.value = value;
198+
}
199+
}
200+
193201
private Collection<? extends Result> process(BenchmarkResult br, File stdOut, File stdErr) {
194-
Multiset<String> events = new HashMultiset<>();
202+
Multimap<String, EventRecord> eventRecords = new HashMultimap<>();
195203

196204
try (FileReader fr = new FileReader(stdErr);
197205
BufferedReader reader = new BufferedReader(fr)) {
@@ -211,161 +219,138 @@ private Collection<? extends Result> process(BenchmarkResult br, File stdOut, Fi
211219
}
212220

213221
double readFrom = skipMs / 1000D;
214-
double softTo = (skipMs + lenMs) / 1000D;
215222
double readTo = (skipMs + lenMs + incrementInterval) / 1000D;
216223

217224
NumberFormat nf = NumberFormat.getInstance();
218225

219226
String line;
220227

221-
nextline:
222228
while ((line = reader.readLine()) != null) {
223229
if (line.startsWith("#")) continue;
224230

225-
if (isIncrementable) {
226-
String[] split = line.split(",");
227-
228-
String time;
229-
String count;
230-
String event;
231-
232-
if (split.length == 3) {
233-
// perf 3.13: time,count,event
234-
time = split[0].trim();
235-
count = split[1].trim();
236-
event = split[2].trim();
237-
} else if (split.length >= 4) {
238-
// perf >3.13: time,count,<other>,event,<others>
239-
time = split[0].trim();
240-
count = split[1].trim();
241-
event = split[3].trim();
242-
} else {
243-
// Malformed line, ignore
244-
continue nextline;
245-
}
231+
String[] split = line.split(",");
232+
233+
String time;
234+
String count;
235+
String event;
236+
237+
if (split.length == 3) {
238+
// perf 3.13: time,count,event
239+
time = split[0].trim();
240+
count = split[1].trim();
241+
event = split[2].trim();
242+
} else if (split.length >= 4) {
243+
// perf >3.13: time,count,<other>,event,<others>
244+
time = split[0].trim();
245+
count = split[1].trim();
246+
event = split[3].trim();
247+
} else {
248+
// Malformed line, ignore
249+
continue;
250+
}
246251

247-
double multiplier = 1D;
248-
try {
249-
double timeSec = nf.parse(time).doubleValue();
250-
if (timeSec < readFrom) {
251-
// warmup, ignore
252-
continue nextline;
253-
}
254-
if (timeSec > readTo) {
255-
// post-run, ignore
256-
continue nextline;
257-
}
258-
259-
// Handle partial events:
260-
double intervalSec = incrementInterval / 1000D;
261-
if (timeSec - intervalSec < readFrom) {
262-
// Event _starts_ before the measurement window
263-
// .............[============|============
264-
// readFrom timeSec
265-
// [<----------------->| // event
266-
// incrementInterval
267-
//
268-
// Only count the tail after readFrom:
269-
270-
multiplier = (timeSec - readFrom) / intervalSec;
271-
}
272-
if (timeSec > softTo) {
273-
// Event is past the measurement window
274-
// =============].............|............
275-
// softTo timeSec
276-
// [<----------------->| // event
277-
// incrementInterval
278-
//
279-
// Only count the head before softTo:
280-
multiplier = 1 - (timeSec - softTo) / intervalSec;
281-
}
282-
283-
// Defensive, keep multiplier in bounds:
284-
multiplier = Math.max(1D, Math.min(0D, multiplier));
285-
} catch (ParseException e) {
286-
// don't care then, continue
287-
continue nextline;
288-
}
252+
double timeSec = 0D;
253+
try {
254+
timeSec = nf.parse(time).doubleValue();
255+
} catch (ParseException e) {
256+
continue;
257+
}
289258

290-
try {
291-
long lValue = nf.parse(count).longValue();
292-
if (lValue > highPassFilter) {
293-
// anomalous value, pretend we did not see it
294-
continue nextline;
295-
}
296-
events.add(event, (long) (lValue * multiplier));
297-
} catch (ParseException e) {
298-
// do nothing, continue
299-
continue nextline;
259+
if (timeSec < readFrom || timeSec > readTo) {
260+
// Outside measurement window, ignore
261+
continue;
262+
}
300263

301-
}
302-
} else {
303-
int idx = line.lastIndexOf(",");
264+
long lValue = 0L;
265+
try {
266+
lValue = nf.parse(count).longValue();
267+
} catch (ParseException e) {
268+
continue;
269+
}
304270

305-
// Malformed line, ignore
306-
if (idx == -1) continue nextline;
271+
eventRecords.put(event, new EventRecord(timeSec, lValue));
272+
}
307273

308-
String count = line.substring(0, idx).trim();
309-
String event = line.substring(idx + 1).trim();
274+
Map<String, Double> finalThroughputs = new HashMap<>();
275+
for (String key : eventRecords.keys()) {
276+
List<EventRecord> countedEvents = new ArrayList<>(eventRecords.get(key));
277+
278+
// If needed and possible, filter out a few head and tail iterations.
279+
// Head iteration potentially contains the infrastructure startup.
280+
// That iteration would only be handled for getting time, not the counter itself.
281+
// Trailing iterations come with both infrastructure rampdown, and the final
282+
// profiler output on shutdown. Sometimes these manifest as two separate iterations.
283+
final int filteredCount = countedEvents.size() - 2;
284+
if (doFilter && filteredCount > 0) {
285+
countedEvents = countedEvents.subList(0, filteredCount);
286+
}
287+
288+
double s = 0;
289+
double minTime = Double.MAX_VALUE;
290+
double maxTime = Double.MIN_VALUE;
310291

311-
try {
312-
long lValue = nf.parse(count).longValue();
313-
events.add(event, lValue);
314-
} catch (ParseException e) {
315-
// do nothing, continue
316-
continue nextline;
292+
for (int i = 0; i < countedEvents.size(); i++) {
293+
EventRecord v = countedEvents.get(i);
294+
if (i != 0) {
295+
// Do not count the first event in the series, since time interval
296+
// does not actually include it.
297+
s += v.value;
317298
}
299+
minTime = Math.min(minTime, v.time);
300+
maxTime = Math.max(maxTime, v.time);
318301
}
302+
double thr = s / (maxTime - minTime);
303+
finalThroughputs.put(key, thr);
304+
}
319305

306+
BenchmarkResultMetaData md = br.getMetadata();
307+
if (md == null) {
308+
return emptyResults();
320309
}
321310

322-
if (!isIncrementable) {
323-
System.out.println();
324-
System.out.println();
325-
System.out.println("WARNING: Your system uses old \"perf\", which cannot print data incrementally (-I).\n" +
326-
"Therefore, perf performance data includes benchmark warmup.");
311+
long timeMs = md.getStopTime() - md.getMeasurementTime();
312+
if (timeMs == 0) {
313+
return emptyResults();
314+
315+
}
316+
double opsThroughput = 1000D * md.getMeasurementOps() / timeMs;
317+
if (opsThroughput == 0) {
318+
return emptyResults();
327319
}
328320

329-
long totalOpts;
321+
Collection<Result> results = new ArrayList<>();
322+
for (String key : finalThroughputs.keySet()) {
323+
results.add(new PerfResult(key, "#/op", finalThroughputs.get(key) / opsThroughput));
324+
}
330325

331-
BenchmarkResultMetaData md = br.getMetadata();
332-
if (md != null) {
333-
if (isIncrementable) {
334-
totalOpts = md.getMeasurementOps();
335-
} else {
336-
totalOpts = md.getWarmupOps() + md.getMeasurementOps();
337-
}
338-
Collection<Result> results = new ArrayList<>();
339-
for (String key : events.keys()) {
340-
results.add(new PerfResult(key, "#/op", events.count(key) * 1.0 / totalOpts));
341-
}
326+
// Also figure out IPC/CPI, if enough counters available:
327+
{
328+
Double c1 = finalThroughputs.get("cycles");
329+
Double c2 = finalThroughputs.get("cycles:u");
342330

343-
// Also figure out IPC/CPI, if enough counters available:
344-
{
345-
long c1 = events.count("cycles");
346-
long c2 = events.count("cycles:u");
331+
Double i1 = finalThroughputs.get("instructions");
332+
Double i2 = finalThroughputs.get("instructions:u");
347333

348-
long i1 = events.count("instructions");
349-
long i2 = events.count("instructions:u");
334+
Double cycles = (c1 != null) ? c1 : c2;
335+
Double instructions = (i1 != null) ? i1 : i2;
350336

351-
long cycles = (c1 != 0) ? c1 : c2;
352-
long instructions = (i1 != 0) ? i1 : i2;
353-
if (cycles != 0 && instructions != 0) {
354-
results.add(new PerfResult("CPI", "clks/insn", 1.0 * cycles / instructions));
355-
results.add(new PerfResult("IPC", "insns/clk", 1.0 * instructions / cycles));
356-
}
337+
if (cycles != null && instructions != null &&
338+
cycles != 0 && instructions != 0) {
339+
results.add(new PerfResult("CPI", "clks/insn", cycles / instructions));
340+
results.add(new PerfResult("IPC", "insns/clk", instructions / cycles));
357341
}
358-
359-
return results;
360-
} else {
361-
return Collections.singleton(new PerfResult("N/A", "", Double.NaN));
362342
}
363343

344+
return results;
364345
} catch (IOException e) {
365346
throw new IllegalStateException(e);
366347
}
367348
}
368349

350+
private static Set<PerfResult> emptyResults() {
351+
return Collections.singleton(new PerfResult("N/A", "", Double.NaN));
352+
}
353+
369354
static class PerfResult extends ScalarResult {
370355
private static final long serialVersionUID = -1262685915873231436L;
371356

0 commit comments

Comments
 (0)