Skip to content

Commit 6cdfd36

Browse files
committed
8358590: JFR: Include min and max in MethodTiming event
Reviewed-by: mgronlun
1 parent eb770a0 commit 6cdfd36

File tree

6 files changed

+49
-7
lines changed

6 files changed

+49
-7
lines changed

src/hotspot/share/jfr/metadata/metadata.xml

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1315,7 +1315,9 @@
13151315
<Event name="MethodTiming" category="Java Application" label="Method Timing" thread="false" stackTrace="false" startTime="false" period="everyChunk">
13161316
<Field type="Method" name="method" label="Method" />
13171317
<Field type="long" name="invocations" label="Invocations" description="The number of times the method was invoked" />
1318-
<Field type="Tickspan" name="average" label="Average" description="An approximation of the wall-clock time it took for the method to execute" />
1318+
<Field type="Tickspan" name="minimum" label="Minimum" description="An approximation of the minimum wall-clock time it took for the method to execute" />
1319+
<Field type="Tickspan" name="average" label="Average" description="An approximation of the average wall-clock time it took for the method to execute" />
1320+
<Field type="Tickspan" name="maximum" label="Maximum" description="An approximation of the maximum wall-clock time it took for the method to execute" />
13191321
</Event>
13201322

13211323
<Type name="DeoptimizationReason" label="Deoptimization Reason">

src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -42,11 +42,19 @@ public final class MethodTimingEvent extends AbstractJDKEvent {
4242
@Label("Invocations")
4343
public long invocations;
4444

45+
@Label("Minimum Time")
46+
@Timespan(Timespan.TICKS)
47+
public long minimum;
48+
4549
@Label("Average Time")
4650
@Timespan(Timespan.TICKS)
4751
public long average;
4852

49-
public static void commit(long start, long method, long invocations, long average) {
53+
@Label("Maximum Time")
54+
@Timespan(Timespan.TICKS)
55+
public long maximum;
56+
57+
public static void commit(long start, long method, long invocations, long minimum, long average, long maximum) {
5058
// Generated by JFR
5159
}
5260

src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -471,9 +471,9 @@ table = "COLUMN 'Alloc. Time', 'Application Method', 'Object Age', 'Heap Usage'
471471

472472
[application.method-timing]
473473
label = "Method Timing"
474-
table = "COLUMN 'Timed Method', 'Invocations', 'Average Time'
474+
table = "COLUMN 'Timed Method', 'Invocations', 'Min. Tim', 'Max. Time', 'Average Time'
475475
FORMAT none, none, ms-precision:6
476-
SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(average)
476+
SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(maximum), LAST_BATCH(average)
477477
FROM jdk.MethodTiming GROUP BY method ORDER BY average"
478478

479479
[application.method-calls]

src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -146,13 +146,15 @@ public static void emitTiming() {
146146
public static void addObjectTiming(long duration) {
147147
OBJECT.invocations().getAndIncrement();
148148
OBJECT.time().addAndGet(duration);
149+
OBJECT.updateMinMax(duration);
149150
}
150151

151152
public static void addTiming(long id, long duration) {
152153
TimedMethod entry = timedMethods.get(id);
153154
if (entry != null) {
154155
entry.invocations().getAndIncrement();
155156
entry.time().addAndGet(duration);
157+
entry.updateMinMax(duration);
156158
}
157159
}
158160

src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -61,7 +61,12 @@ public void emit(long timestamp) {
6161
long invocations = tm.invocations().get();
6262
long time = tm.time().get();
6363
long average = invocations == 0 ? Long.MIN_VALUE : time / invocations;
64-
MethodTimingEvent.commit(timestamp, methodId, invocations, average);
64+
long min = tm.minimum().get();
65+
if (min == Long.MAX_VALUE) {
66+
min = Long.MIN_VALUE; // Signals that the value is missing
67+
}
68+
long max = tm.maximum().get();
69+
MethodTimingEvent.commit(timestamp, methodId, invocations, min, average, max);
6570
tm.method().log("Emitted event");
6671
}
6772
}

src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java

Lines changed: 27 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,8 +33,33 @@
3333
* <p>
3434
* Fields in record classes are truly final so might help to have a record here.
3535
*/
36-
record TimedMethod(AtomicLong invocations, AtomicLong time, Method method, AtomicBoolean published) {
36+
record TimedMethod(AtomicLong invocations, AtomicLong time, AtomicLong minimum, AtomicLong maximum, Method method, AtomicBoolean published) {
3737
TimedMethod(Method method) {
38-
this(new AtomicLong(), new AtomicLong(), method, new AtomicBoolean());
38+
this(new AtomicLong(), new AtomicLong(), new AtomicLong(Long.MAX_VALUE), new AtomicLong(Long.MIN_VALUE), method, new AtomicBoolean());
39+
}
40+
41+
public void updateMinMax(long duration) {
42+
if (duration > maximum.getPlain()) {
43+
while (true) {
44+
long max = maximum.get();
45+
if (duration <= max) {
46+
return;
47+
}
48+
if (maximum.weakCompareAndSetVolatile(max, duration)) {
49+
return;
50+
}
51+
}
52+
}
53+
if (duration < minimum.getPlain()) {
54+
while (true) {
55+
long min = minimum.get();
56+
if (duration >= min) {
57+
return;
58+
}
59+
if (minimum.weakCompareAndSetVolatile(min, duration)) {
60+
return;
61+
}
62+
}
63+
}
3964
}
4065
}

0 commit comments

Comments
 (0)