From 7b96f03533af075d69591bc5636f94dbb43f834b Mon Sep 17 00:00:00 2001 From: duke Date: Sun, 6 Jul 2025 19:13:27 +0000 Subject: [PATCH] Backport f3e0588d0b825a68a4ad61ddf806877f46da69dc --- .../jdk/jfr/events/MethodTimingEvent.java | 5 +++++ .../classes/jdk/jfr/internal/query/view.ini | 4 ++-- .../jdk/jfr/internal/tracing/TimedClass.java | 21 ++++++++++++++----- .../jdk/jfr/internal/tracing/TimedMethod.java | 3 +++ 4 files changed, 26 insertions(+), 7 deletions(-) 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 4998966939b7a..e927abf80248f 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java @@ -29,11 +29,13 @@ import jdk.jfr.Name; import jdk.jfr.Timespan; import jdk.jfr.internal.RemoveFields; +import jdk.jfr.Description; @Name("jdk.MethodTiming") @Label("Method Timing") @Category({ "Java Virtual Machine", "Method Tracing" }) @RemoveFields({ "duration", "eventThread", "stackTrace" }) +@Description("Measures the approximate time it takes for a method to execute, including all delays, not just CPU processing time") public final class MethodTimingEvent extends AbstractJDKEvent { @Label("Method") @@ -43,14 +45,17 @@ public final class MethodTimingEvent extends AbstractJDKEvent { public long invocations; @Label("Minimum Time") + @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish a minimum time") @Timespan(Timespan.TICKS) public long minimum; @Label("Average Time") + @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish an average time") @Timespan(Timespan.TICKS) public long average; @Label("Maximum Time") + @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish a maximum time") @Timespan(Timespan.TICKS) public long maximum; 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 fd9636f17ab71..94eed6067ea32 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', 'Min. Time', 'Max. Time', 'Average Time' +table = "COLUMN 'Timed Method', 'Invocations', 'Minimum Time', 'Average Time', 'Maximum Time' FORMAT none, none, ms-precision:6, ms-precision:6, ms-precision:6 - SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(maximum), LAST_BATCH(average) + SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(average), LAST_BATCH(maximum) FROM jdk.MethodTiming GROUP BY method ORDER BY average" [application.method-calls] 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 ed592fec645c0..2c3ee2cbb95a1 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 @@ -33,6 +33,7 @@ * Holds timed method for a class. Used when publishing method ids. */ public final class TimedClass { + private static final long MISSING = Long.MIN_VALUE; private final ConcurrentHashMap methods = new ConcurrentHashMap<>(); public TimedMethod add(Method method) { @@ -60,13 +61,23 @@ public void emit(long timestamp) { long methodId = tm.method().methodId(); long invocations = tm.invocations().get(); long time = tm.time().get(); - long average = invocations == 0 ? Long.MIN_VALUE : time / invocations; 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); + if (time == 0 || invocations == 0) { + // If time is zero, it's a low resolution clock and more invocations are needed. + MethodTimingEvent.commit(timestamp, methodId, invocations, MISSING, MISSING, MISSING); + } else { + long average = (time + invocations / 2) / invocations; + if (min == Long.MAX_VALUE) { + min = average; + } + if (max == Long.MIN_VALUE) { + max = average; + } + min = Math.min(min, average); + max = Math.max(max, average); + 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 be7f0c8f0847e..bd4f22624447a 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 @@ -39,6 +39,9 @@ record TimedMethod(AtomicLong invocations, AtomicLong time, AtomicLong minimum, } public void updateMinMax(long duration) { + if (duration == 0) { + return; // Ignore data due to low-resolution clock + } if (duration > maximum.getPlain()) { while (true) { long max = maximum.get();