From 6cdfd36ac80ad889ddbcfc702115b750a32d9645 Mon Sep 17 00:00:00 2001 From: Erik Gahlin Date: Thu, 5 Jun 2025 11:42:31 +0000 Subject: [PATCH] 8358590: JFR: Include min and max in MethodTiming event Reviewed-by: mgronlun --- src/hotspot/share/jfr/metadata/metadata.xml | 4 ++- .../jdk/jfr/events/MethodTimingEvent.java | 10 ++++++- .../classes/jdk/jfr/internal/query/view.ini | 4 +-- .../jfr/internal/tracing/PlatformTracer.java | 2 ++ .../jdk/jfr/internal/tracing/TimedClass.java | 7 ++++- .../jdk/jfr/internal/tracing/TimedMethod.java | 29 +++++++++++++++++-- 6 files changed, 49 insertions(+), 7 deletions(-) diff --git a/src/hotspot/share/jfr/metadata/metadata.xml b/src/hotspot/share/jfr/metadata/metadata.xml index 03daca946f6..d7287adb1a6 100644 --- a/src/hotspot/share/jfr/metadata/metadata.xml +++ b/src/hotspot/share/jfr/metadata/metadata.xml @@ -1315,7 +1315,9 @@ - + + + diff --git a/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java b/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java index cc1d8f681c7..4998966939b 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java @@ -42,11 +42,19 @@ public final class MethodTimingEvent extends AbstractJDKEvent { @Label("Invocations") public long invocations; + @Label("Minimum Time") + @Timespan(Timespan.TICKS) + public long minimum; + @Label("Average Time") @Timespan(Timespan.TICKS) public long average; - public static void commit(long start, long method, long invocations, long average) { + @Label("Maximum Time") + @Timespan(Timespan.TICKS) + public long maximum; + + public static void commit(long start, long method, long invocations, long minimum, long average, long maximum) { // Generated by JFR } diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini b/src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini index a2ac74142f4..018f41bbf22 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini +++ b/src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini @@ -471,9 +471,9 @@ table = "COLUMN 'Alloc. Time', 'Application Method', 'Object Age', 'Heap Usage' [application.method-timing] label = "Method Timing" -table = "COLUMN 'Timed Method', 'Invocations', 'Average Time' +table = "COLUMN 'Timed Method', 'Invocations', 'Min. Tim', 'Max. Time', 'Average Time' FORMAT none, none, ms-precision:6 - SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(average) + SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(maximum), LAST_BATCH(average) FROM jdk.MethodTiming GROUP BY method ORDER BY average" [application.method-calls] diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java index 608fe865147..abc3b0f8cd0 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java @@ -146,6 +146,7 @@ public final class PlatformTracer { public static void addObjectTiming(long duration) { OBJECT.invocations().getAndIncrement(); OBJECT.time().addAndGet(duration); + OBJECT.updateMinMax(duration); } public static void addTiming(long id, long duration) { @@ -153,6 +154,7 @@ public final class PlatformTracer { if (entry != null) { entry.invocations().getAndIncrement(); entry.time().addAndGet(duration); + entry.updateMinMax(duration); } } diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java index 936a8cf835d..ed592fec645 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java @@ -61,7 +61,12 @@ public final class TimedClass { long invocations = tm.invocations().get(); long time = tm.time().get(); long average = invocations == 0 ? Long.MIN_VALUE : time / invocations; - MethodTimingEvent.commit(timestamp, methodId, invocations, average); + long min = tm.minimum().get(); + if (min == Long.MAX_VALUE) { + min = Long.MIN_VALUE; // Signals that the value is missing + } + long max = tm.maximum().get(); + MethodTimingEvent.commit(timestamp, methodId, invocations, min, average, max); tm.method().log("Emitted event"); } } diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java index 185fab62421..be7f0c8f084 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java @@ -33,8 +33,33 @@ import java.util.concurrent.atomic.AtomicLong; *

* Fields in record classes are truly final so might help to have a record here. */ -record TimedMethod(AtomicLong invocations, AtomicLong time, Method method, AtomicBoolean published) { +record TimedMethod(AtomicLong invocations, AtomicLong time, AtomicLong minimum, AtomicLong maximum, Method method, AtomicBoolean published) { TimedMethod(Method method) { - this(new AtomicLong(), new AtomicLong(), method, new AtomicBoolean()); + this(new AtomicLong(), new AtomicLong(), new AtomicLong(Long.MAX_VALUE), new AtomicLong(Long.MIN_VALUE), method, new AtomicBoolean()); + } + + public void updateMinMax(long duration) { + if (duration > maximum.getPlain()) { + while (true) { + long max = maximum.get(); + if (duration <= max) { + return; + } + if (maximum.weakCompareAndSetVolatile(max, duration)) { + return; + } + } + } + if (duration < minimum.getPlain()) { + while (true) { + long min = minimum.get(); + if (duration >= min) { + return; + } + if (minimum.weakCompareAndSetVolatile(min, duration)) { + return; + } + } + } } }